OverviewFilesCommitsIssuesDocsReleasesPeers

atproto-room / test / phase2-admission-durability.repro.mjs

97 lines · javascript ref:
// Phase-2 admission-durability OFFLINE repro (hyper-social #6).
//
// Reproduces the tabertron symptom: a plain writer (B) that was admitted once boots writable=false
// on RESTART, and base.update() HANGS — so the sign/read/admission path (which awaits base.update())
// never re-rings the doorbell and B never re-admits. A (creator/sole N=1 indexer) stays ONLINE the
// whole time, mirroring stortron being healthy.
//
// This is a PROBE, not a pass/fail test — it prints exactly what happens at each step so we
// characterize the bug before fixing (never guess-fix the live wj62 StateBase). Run:
//   cd atproto-room && bare test/phase2-admission-durability.repro.mjs
import '../lib/bare-globals.js'
import crypto from 'hypercore-crypto'
import fs from 'bare-fs'
import b4a from 'b4a'
import createTestnet from '@hyperswarm/testnet'
import { StateBaseV3 } from '../lib/state-base.js'
import { makeAttest, makeVerifyAttest, attestDeviceChain, deviceKeetKeyPair, rootIdentityPublicKey } from '../lib/membership.js'

const ROOT = 'abandon abandon abandon abandon abandon abandon abandon abandon abandon abandon abandon about'
const DEVA = 'legal winner thank year wave sausage worth useful legal winner thank yellow'
const DEVB = 'zoo zoo zoo zoo zoo zoo zoo zoo zoo zoo zoo wrong'
const sleep = (ms) => new Promise(r => setTimeout(r, ms))
const RUN = '/tmp/hpp-phase2-' + Math.floor(Math.random() * 1e9)

// Race any promise against a timeout so a HANG is observable instead of hanging the whole script.
async function timed (label, p, ms = 4000) {
  const t0 = Date.now()
  const HUNG = Symbol('hung')
  const r = await Promise.race([p.then(v => ({ v })).catch(e => ({ err: e })), sleep(ms).then(() => HUNG)])
  const dt = Date.now() - t0
  if (r === HUNG) { console.log(`  [${label}] HUNG (>${ms}ms) <-- did not resolve`); return { hung: true } }
  if (r.err) { console.log(`  [${label}] threw after ${dt}ms: ${r.err.message}`); return { err: r.err } }
  console.log(`  [${label}] ok in ${dt}ms`)
  return { v: r.v }
}

async function main () {
  fs.mkdirSync(RUN, { recursive: true })
  const testnet = await createTestnet(3)
  const rootPub = await rootIdentityPublicKey(ROOT)
  let da = await deviceKeetKeyPair(DEVA); let pa = await attestDeviceChain({ rootMnemonic: ROOT, devicePublicKey: da.publicKey })
  let db = await deviceKeetKeyPair(DEVB); let pb = await attestDeviceChain({ rootMnemonic: ROOT, devicePublicKey: db.publicKey })
  let A = { dev: da, proof: pa }, B = { dev: db, proof: pb }
  if (b4a.compare(A.dev.publicKey, B.dev.publicKey) > 0) { const t = A; A = B; B = t } // creator = lowest key
  const members = [
    { key: b4a.toString(A.dev.publicKey, 'hex'), role: 1 },
    { key: b4a.toString(B.dev.publicKey, 'hex'), role: 1 }
  ]
  const roomSeed = crypto.randomBytes(32); const roomKey = crypto.randomBytes(32); const encryptionKey = crypto.randomBytes(32)
  const dirA = RUN + '/A'; const dirB = RUN + '/B'
  const mk = (dir, dev, proof) => new StateBaseV3(dir, roomKey, {
    roomSeed, encryptionKey, swarmOpts: { bootstrap: testnet.bootstrap },
    selfKey: dev.publicKey, attest: makeAttest(dev, proof), verifyAttest: makeVerifyAttest(rootPub),
    getMembers: async () => members
  })

  console.log('\n=== STEP 1: bring up A (creator/sole N=1 indexer) + admit B ===')
  const sbA = mk(dirA, A.dev, A.proof); await sbA.ready(); await sbA.projectMembers(members)
  let sbB = mk(dirB, B.dev, B.proof); await sbB.ready()
  console.log('A.writable=%s  A.isIndexer=%s', sbA.base.writable, sbA.base.isIndexer)
  await sbB.set('post/1', { text: 'first-post' })          // doorbell → admit → RUNTIME writable
  console.log('B.writable after first set()=%s  B.local.length=%s', sbB.base.writable, sbB.base.local.length)

  console.log('\n=== STEP 2: DO NOT converge — simulate a power cut right after admission ===')
  // B is writable at RUNTIME (linearized system) but A (ackInterval 1000ms) may not yet have SIGNED
  // an indexed checkpoint covering B's admission that B persisted. That is the power-cut window.
  const persignHasB = sbB.base.system ? await sbB.base.system.has(sbB.base.local.key) : null
  console.log('B.system.has(B.local) [durably signed?]=%s   (false => reboot will be writable=false)', persignHasB)

  console.log('\n=== STEP 3: CLOSE B abruptly (power cut), A STAYS ONLINE ===')
  await sbB.close()
  await sleep(500)

  console.log('\n=== STEP 4: REOPEN B on the SAME storage, A still online — the restart under test ===')
  sbB = mk(dirB, B.dev, B.proof)
  await sbB.ready()
  console.log('B.writable at boot (from persisted signed checkpoint)=%s', sbB.base.writable)
  console.log('B.local.length=%s  B.local.key=%s', sbB.base.local.length, sbB.base.local.key.toString('hex').slice(0, 12))

  console.log('\n=== STEP 5: probe the sign/read path (each raced against a 4s timeout) ===')
  await timed('B.base.update()', sbB.base.update())
  await timed('B.get(post/1) [blocking, via base.update]', sbB.get('post/1'))
  await timed('B.getNow(post/1) [non-blocking snapshot]', sbB.getNow('post/1'))
  await timed('B.lease.current() [sign-loop first read]', (async () => { const { Lease } = await import('../lib/lease.js'); return new Lease(sbB, { self: b4a.toString(B.dev.publicKey, 'hex') }).current() })())
  await timed('B.set(post/2) [_ensureWritable→requestWriter doorbell]', sbB.set('post/2', { text: 'second-post' }), 25000)
  console.log('B.writable after set(post/2)=%s', sbB.base.writable)

  console.log('\n=== STEP 6: give convergence more time, re-check ===')
  for (let i = 0; i < 20; i++) { await sbA.base.update().catch(() => {}); await sbB.base.update().catch(() => {}); await sleep(300) }
  console.log('B.writable=%s  B.effectiveWritable=%s', sbB.base.writable, await sbB.effectiveWritable())

  await sbA.close().catch(() => {}); await sbB.close().catch(() => {}); await testnet.destroy()
  console.log('\n=== done ===')
  process.exit(0)
}
main().catch(e => { console.error('REPRO ERROR', e); process.exit(1) })