OverviewFilesCommitsIssuesDocsReleasesPeers

atproto-did-peer / test / rpc-timeout.test.mjs

129 lines · javascript ref:
// A HUNG PEER MUST NOT HANG THE CALLER (hyper-social #47).
//
// `DidPeer._call` awaited `rpc.request(method, params)` with no options. protomux-rpc defaults
// `timeout = -1` and arms its timer only when `timeout > 0` (index.js:214, :230), so NO request
// ever timed out. Every membrane->hpp call — get-blob, apply-write(s), create-session,
// upload-blob, get-service-auth, get/put-preferences, list-blobs, get-repo-car — is made from
// inside an HTTP request handler in atproto-bridge. An hpp that is alive but wedged never answers,
// so the HTTP request hung forever: no 504, no log, no recovery. A hang is worse than a crash
// because nothing restarts it.
//
// It also made `_call`'s own failover dead code: `nextOn` adds TIMEOUT_EXCEEDED for read-only
// calls (did-peer.js:104) but nothing on this side could ever produce that code.
//
// The fix delegates the deadline to protomux-rpc rather than racing a local timer, because
// `_ontimeout` also DELETES the pending entry from `_requests` (index.js:161-168). A
// Promise.race wrapper would settle the caller and leak the request map entry forever.
//
// Real RPC pair over localhost TCP — a fake `request()` would only test the fake.
// Run: node test/rpc-timeout.test.mjs
import net from 'node:net'
import c from 'compact-encoding'
import ProtomuxRPC from 'protomux-rpc'
import { DidPeer } from '../index.js'

const PROTO = 'rpc-timeout-test'
const assert = (cond, m) => { if (!cond) { console.error('FAIL:', m); process.exit(1) } console.log('  ok -', m) }
const never = () => new Promise(() => {})

// A connected ProtomuxRPC pair. `mode` decides what the responder does with 'probe'.
async function pair (mode) {
  const server = net.createServer()
  await new Promise((r) => server.listen(0, '127.0.0.1', r))
  const port = server.address().port
  const accepted = new Promise((r) => server.once('connection', r))
  const clientSock = net.connect(port, '127.0.0.1')
  await new Promise((r) => clientSock.once('connect', r))
  const serverSock = await accepted

  const srv = new ProtomuxRPC(serverSock, { protocol: PROTO, valueEncoding: c.json })
  srv.on('error', () => {})
  if (mode === 'hang') srv.respond('probe', () => never())
  if (mode === 'answer') srv.respond('probe', () => ({ ok: true, from: 'answerer' }))

  const cli = new ProtomuxRPC(clientSock, { protocol: PROTO, valueEncoding: c.json })
  cli.on('error', () => {})
  return { cli, close: () => { try { clientSock.destroy() } catch {} try { serverSock.destroy() } catch {} server.close() } }
}

const newPeer = () => new DidPeer({}, { did: 'did:plc:timeouttest', verifyKey: new Uint8Array(32) })

const closers = []
const t0 = Date.now()

// ---------------------------------------------------------------------------
// 1. A single hung peer rejects instead of hanging.
// ---------------------------------------------------------------------------
{
  const a = await pair('hang'); closers.push(a.close)
  const peer = newPeer()
  peer.addRpc(a.cli)

  const started = Date.now()
  let code = null
  try {
    await peer._call('probe', {}, { readOnly: true, timeoutMs: 500 })
    console.error('FAIL: expected a rejection, got a resolution'); process.exit(1)
  } catch (e) { code = e && e.code }
  const took = Date.now() - started

  assert(code === 'TIMEOUT_EXCEEDED', `hung peer rejects with TIMEOUT_EXCEEDED (got ${code})`)
  assert(took < 3000, `rejected promptly, not hung (took ${took}ms)`)
}

// ---------------------------------------------------------------------------
// 2. READ failover: the timeout makes the previously-dead TIMEOUT_EXCEEDED branch live, so a
//    read moves past a wedged peer to one that answers.
// ---------------------------------------------------------------------------
{
  const hung = await pair('hang'); closers.push(hung.close)
  const good = await pair('answer'); closers.push(good.close)
  const peer = newPeer()
  peer.addRpc(hung.cli)
  peer.addRpc(good.cli)

  const res = await peer._call('probe', {}, { readOnly: true, timeoutMs: 500 })
  assert(res && res.from === 'answerer', 'read-only call fails over from the wedged peer and gets an answer')
  assert(peer._liveRpcs()[0] === good.cli, 'the peer that answered is promoted to the front (sticky)')
}

// ---------------------------------------------------------------------------
// 3. WRITE safety: a write that timed out must NOT be replayed against another peer. It may
//    already have been applied. This is the property the readOnly flag exists to protect.
// ---------------------------------------------------------------------------
{
  const hung = await pair('hang'); closers.push(hung.close)
  const good = await pair('answer'); closers.push(good.close)
  const peer = newPeer()
  peer.addRpc(hung.cli)

  let tried = 0
  const spy = { closed: false, request: async () => { tried++; return { ok: true } } }
  peer.addRpc(spy)

  let code = null
  try {
    await peer._call('probe', {}, { timeoutMs: 500 }) // no readOnly => a write
    console.error('FAIL: expected the write to reject'); process.exit(1)
  } catch (e) { code = e && e.code }

  assert(code === 'TIMEOUT_EXCEEDED', `write rejects with TIMEOUT_EXCEEDED (got ${code})`)
  assert(tried === 0, `a timed-out WRITE is never replayed against another peer (next tried ${tried} times)`)
}

// ---------------------------------------------------------------------------
// 4. The default applies with no explicit timeoutMs — the fix must not depend on every call site
//    remembering to pass one. Uses a tiny override of the default via the module constant.
// ---------------------------------------------------------------------------
{
  const a = await pair('hang'); closers.push(a.close)
  const peer = newPeer()
  peer.addRpc(a.cli)
  assert(typeof DidPeer.DEFAULT_RPC_TIMEOUT_MS === 'number' && DidPeer.DEFAULT_RPC_TIMEOUT_MS > 0,
    `a positive default timeout is defined (${DidPeer.DEFAULT_RPC_TIMEOUT_MS}ms)`)
}

for (const close of closers) { try { close() } catch {} }
console.log(`\nrpc-timeout: all assertions passed in ${Date.now() - t0}ms`)
process.exit(0)