| … | … | @@ -0,0 +1,128 @@ |
| 1 | // A HUNG PEER MUST NOT HANG THE CALLER (hyper-social #47). |
| 2 | // |
| 3 | // `DidPeer._call` awaited `rpc.request(method, params)` with no options. protomux-rpc defaults |
| 4 | // `timeout = -1` and arms its timer only when `timeout > 0` (index.js:214, :230), so NO request |
| 5 | // ever timed out. Every membrane->hpp call — get-blob, apply-write(s), create-session, |
| 6 | // upload-blob, get-service-auth, get/put-preferences, list-blobs, get-repo-car — is made from |
| 7 | // inside an HTTP request handler in atproto-bridge. An hpp that is alive but wedged never answers, |
| 8 | // so the HTTP request hung forever: no 504, no log, no recovery. A hang is worse than a crash |
| 9 | // because nothing restarts it. |
| 10 | // |
| 11 | // It also made `_call`'s own failover dead code: `nextOn` adds TIMEOUT_EXCEEDED for read-only |
| 12 | // calls (did-peer.js:104) but nothing on this side could ever produce that code. |
| 13 | // |
| 14 | // The fix delegates the deadline to protomux-rpc rather than racing a local timer, because |
| 15 | // `_ontimeout` also DELETES the pending entry from `_requests` (index.js:161-168). A |
| 16 | // Promise.race wrapper would settle the caller and leak the request map entry forever. |
| 17 | // |
| 18 | // Real RPC pair over localhost TCP — a fake `request()` would only test the fake. |
| 19 | // Run: node test/rpc-timeout.test.mjs |
| 20 | import net from 'node:net' |
| 21 | import c from 'compact-encoding' |
| 22 | import ProtomuxRPC from 'protomux-rpc' |
| 23 | import { DidPeer } from '../index.js' |
| 24 | |
| 25 | const PROTO = 'rpc-timeout-test' |
| 26 | const assert = (cond, m) => { if (!cond) { console.error('FAIL:', m); process.exit(1) } console.log(' ok -', m) } |
| 27 | const never = () => new Promise(() => {}) |
| 28 | |
| 29 | // A connected ProtomuxRPC pair. `mode` decides what the responder does with 'probe'. |
| 30 | async function pair (mode) { |
| 31 | const server = net.createServer() |
| 32 | await new Promise((r) => server.listen(0, '127.0.0.1', r)) |
| 33 | const port = server.address().port |
| 34 | const accepted = new Promise((r) => server.once('connection', r)) |
| 35 | const clientSock = net.connect(port, '127.0.0.1') |
| 36 | await new Promise((r) => clientSock.once('connect', r)) |
| 37 | const serverSock = await accepted |
| 38 | |
| 39 | const srv = new ProtomuxRPC(serverSock, { protocol: PROTO, valueEncoding: c.json }) |
| 40 | srv.on('error', () => {}) |
| 41 | if (mode === 'hang') srv.respond('probe', () => never()) |
| 42 | if (mode === 'answer') srv.respond('probe', () => ({ ok: true, from: 'answerer' })) |
| 43 | |
| 44 | const cli = new ProtomuxRPC(clientSock, { protocol: PROTO, valueEncoding: c.json }) |
| 45 | cli.on('error', () => {}) |
| 46 | return { cli, close: () => { try { clientSock.destroy() } catch {} try { serverSock.destroy() } catch {} server.close() } } |
| 47 | } |
| 48 | |
| 49 | const newPeer = () => new DidPeer({}, { did: 'did:plc:timeouttest', verifyKey: new Uint8Array(32) }) |
| 50 | |
| 51 | const closers = [] |
| 52 | const t0 = Date.now() |
| 53 | |
| 54 | // --------------------------------------------------------------------------- |
| 55 | // 1. A single hung peer rejects instead of hanging. |
| 56 | // --------------------------------------------------------------------------- |
| 57 | { |
| 58 | const a = await pair('hang'); closers.push(a.close) |
| 59 | const peer = newPeer() |
| 60 | peer.addRpc(a.cli) |
| 61 | |
| 62 | const started = Date.now() |
| 63 | let code = null |
| 64 | try { |
| 65 | await peer._call('probe', {}, { readOnly: true, timeoutMs: 500 }) |
| 66 | console.error('FAIL: expected a rejection, got a resolution'); process.exit(1) |
| 67 | } catch (e) { code = e && e.code } |
| 68 | const took = Date.now() - started |
| 69 | |
| 70 | assert(code === 'TIMEOUT_EXCEEDED', `hung peer rejects with TIMEOUT_EXCEEDED (got ${code})`) |
| 71 | assert(took < 3000, `rejected promptly, not hung (took ${took}ms)`) |
| 72 | } |
| 73 | |
| 74 | // --------------------------------------------------------------------------- |
| 75 | // 2. READ failover: the timeout makes the previously-dead TIMEOUT_EXCEEDED branch live, so a |
| 76 | // read moves past a wedged peer to one that answers. |
| 77 | // --------------------------------------------------------------------------- |
| 78 | { |
| 79 | const hung = await pair('hang'); closers.push(hung.close) |
| 80 | const good = await pair('answer'); closers.push(good.close) |
| 81 | const peer = newPeer() |
| 82 | peer.addRpc(hung.cli) |
| 83 | peer.addRpc(good.cli) |
| 84 | |
| 85 | const res = await peer._call('probe', {}, { readOnly: true, timeoutMs: 500 }) |
| 86 | assert(res && res.from === 'answerer', 'read-only call fails over from the wedged peer and gets an answer') |
| 87 | assert(peer._liveRpcs()[0] === good.cli, 'the peer that answered is promoted to the front (sticky)') |
| 88 | } |
| 89 | |
| 90 | // --------------------------------------------------------------------------- |
| 91 | // 3. WRITE safety: a write that timed out must NOT be replayed against another peer. It may |
| 92 | // already have been applied. This is the property the readOnly flag exists to protect. |
| 93 | // --------------------------------------------------------------------------- |
| 94 | { |
| 95 | const hung = await pair('hang'); closers.push(hung.close) |
| 96 | const good = await pair('answer'); closers.push(good.close) |
| 97 | const peer = newPeer() |
| 98 | peer.addRpc(hung.cli) |
| 99 | |
| 100 | let tried = 0 |
| 101 | const spy = { closed: false, request: async () => { tried++; return { ok: true } } } |
| 102 | peer.addRpc(spy) |
| 103 | |
| 104 | let code = null |
| 105 | try { |
| 106 | await peer._call('probe', {}, { timeoutMs: 500 }) // no readOnly => a write |
| 107 | console.error('FAIL: expected the write to reject'); process.exit(1) |
| 108 | } catch (e) { code = e && e.code } |
| 109 | |
| 110 | assert(code === 'TIMEOUT_EXCEEDED', `write rejects with TIMEOUT_EXCEEDED (got ${code})`) |
| 111 | assert(tried === 0, `a timed-out WRITE is never replayed against another peer (next tried ${tried} times)`) |
| 112 | } |
| 113 | |
| 114 | // --------------------------------------------------------------------------- |
| 115 | // 4. The default applies with no explicit timeoutMs — the fix must not depend on every call site |
| 116 | // remembering to pass one. Uses a tiny override of the default via the module constant. |
| 117 | // --------------------------------------------------------------------------- |
| 118 | { |
| 119 | const a = await pair('hang'); closers.push(a.close) |
| 120 | const peer = newPeer() |
| 121 | peer.addRpc(a.cli) |
| 122 | assert(typeof DidPeer.DEFAULT_RPC_TIMEOUT_MS === 'number' && DidPeer.DEFAULT_RPC_TIMEOUT_MS > 0, |
| 123 | `a positive default timeout is defined (${DidPeer.DEFAULT_RPC_TIMEOUT_MS}ms)`) |
| 124 | } |
| 125 | |
| 126 | for (const close of closers) { try { close() } catch {} } |
| 127 | console.log(`\nrpc-timeout: all assertions passed in ${Date.now() - t0}ms`) |
| 128 | process.exit(0) |