diff --git a/src/sync/core-sync-state.js b/src/sync/core-sync-state.js index 0c58b7c5..3fe46b4a 100644 --- a/src/sync/core-sync-state.js +++ b/src/sync/core-sync-state.js @@ -43,6 +43,15 @@ import { InvalidBitfieldIndexError } from '../errors.js' // This is a 32-bit number with all bits set const WANT_FULL = 2 ** 32 - 1 +/** + * How long after `peer-add` to wait for the peer's first Synchronize message + * before treating the peer as started with its channel-level state unknown + * (see `#onPeerAdd`). Normally the Synchronize arrives in the same batch as + * the channel open, so this is only hit when a channel close/open crossing + * swallowed the handshake. + */ +const FIRST_SYNC_FALLBACK_MS = 5_000 + /** * Track sync state for a core identified by `discoveryId`. Can start tracking * state before the core instance exists locally, via the "preHave" messages @@ -279,12 +288,6 @@ export class CoreSyncState { const peerState = this.#getOrCreatePeerState(peerId) peerState.status = 'starting' - this.#core?.update({ wait: true }).then(() => { - peerState.status = 'started' - peerState.contiguousLength = peer.remoteContiguousLength - this.#update() - }) - // A peer can have a pre-emptive "have" bitfield received via an extension // message, but when the peer actually connects then we switch to the actual // bitfield from the peer object @@ -294,7 +297,9 @@ export class CoreSyncState { this.#update() // We want to emit state when a peer's bitfield changes, which can happen as - // a result of these two internal calls. + // a result of these two internal calls. Hypercore dispatches wire messages + // by property lookup on this peer object (its channel's userData), so + // shadowing the methods on the instance is the interception point. const originalOnBitfield = peer.onbitfield const originalOnRange = peer.onrange peer.onbitfield = (...args) => { @@ -307,6 +312,79 @@ export class CoreSyncState { peerState.contiguousLength = peer.remoteContiguousLength this.#update() } + + // The peer is "started" once its first Synchronize message has been + // processed (hypercore sets `peer.remoteSynced`): only then do we know + // the peer's length and fork, so only then can counts about this peer be + // trusted. Every channel sends a Synchronize immediately on open, so this + // always arrives. Do NOT use `core.update({ wait: true })` as a proxy for + // this: it answers a core-global question ("am I up to date with the + // swarm?") which (a) resolves immediately for writable cores, (b) + // resolves for all waiters when *any* peer supplies an upgrade, and (c) + // samples at most 3 peers (hypercore's MAX_PEERS_UPGRADE) — so it can + // report a peer as started before we have heard anything from it. + const markStarted = () => { + peerState.status = 'started' + peerState.contiguousLength = peer.remoteContiguousLength + this.#update() + } + if (peer.remoteSynced) { + // Defensive only — not reachable in production wiring: cores are + // attached synchronously on the core manager's 'add-core' event (or at + // construction), before a channel handshake could possibly complete, + // so peers replayed by `attachCore` have never synced yet. But nothing + // in this class enforces that callers attach before handshakes + // complete, so handle an already-synced peer correctly rather than + // waiting for a Synchronize that already happened. + markStarted() + } else { + const originalOnSync = peer.onsync + peer.onsync = (...args) => { + const result = originalOnSync.apply(peer, args) + // `remoteSynced` is set synchronously at the top of `onsync` + if (peer.remoteSynced) { + if (peerState.status === 'starting') { + clearTimeout(firstSyncFallback) + markStarted() + } else { + // A Synchronize arriving after the fallback below fired still + // carries state (the peer's length and fork), so re-derive + peerState.contiguousLength = peer.remoteContiguousLength + this.#update() + } + } + return result + } + // The remote sends its first Synchronize as soon as the channel + // opens, so normally this timer never fires. The exception is a + // renegotiation bug in hypercore/protomux (their `Peer#onclose` has a + // TODO about it): when both sides close and re-open a channel at the + // same time — e.g. a namespace toggling off and on around a role + // change — the messages cross and the remote keeps its old session, + // never re-sending its state, so we would wait forever. This is not + // repairable from here (no message forces a re-send, and + // closing/re-opening the channel from this layer destabilizes the + // replication layers that own it), only upstream. So stop waiting and + // mark the peer started. The cost is the same as any reconnect, and + // the same as the previous `core.update()`-based code: until this + // peer reconnects we only know about this core what its pre-haves + // told us (what it had at connect, plus its own writer-core appends), + // not blocks it downloaded from third devices mid-session, so its + // `have`/`wanted` counts can run low. + const firstSyncFallback = setTimeout(() => { + if (peer.remoteSynced || peer.removed) return + if (peerState.status !== 'starting') return + this.#l.log( + 'Peer %S sent no Synchronize %dms after channel open, marking started', + peerId, + FIRST_SYNC_FALLBACK_MS + ) + markStarted() + }, FIRST_SYNC_FALLBACK_MS) + // Don't keep the process alive for this; it matters only while the + // connection (which itself holds the process open) is live + firstSyncFallback.unref?.() + } } /** diff --git a/src/types.ts b/src/types.ts index 01618ecf..98f71aec 100644 --- a/src/types.ts +++ b/src/types.ts @@ -166,8 +166,25 @@ export type HypercorePeer = { remotePublicKey: Buffer remoteBitfield: HypercoreRemoteBitfield remoteContiguousLength: number + /** + * Set (synchronously) when the peer's first Synchronize wire message is + * processed, i.e. once we know the peer's length and fork. + */ + remoteSynced: boolean + /** Set when the peer's channel has closed and it was removed from the replicator. */ + removed: boolean onbitfield: (options: { start: number; bitfield: Buffer }) => void onrange: (options: { drop: boolean; start: number; length: number }) => void + onsync: (options: { + fork: number + length: number + remoteLength: number + canUpgrade: boolean + uploading: boolean + downloading: boolean + hasManifest: boolean + allowPush: boolean + }) => Promise } type ProtocolStream = Omit & { diff --git a/test/sync/core-sync-state.js b/test/sync/core-sync-state.js index 7f04994b..9c4392b7 100644 --- a/test/sync/core-sync-state.js +++ b/test/sync/core-sync-state.js @@ -463,6 +463,340 @@ test('CoreReplicationState', async (t) => { } }) +test('peer status stays "starting" until that peer\'s first Synchronize (writable core)', async (t) => { + // `core.update({ wait: true })` resolves immediately for writable cores + // (hypercore short-circuits: a writer is always "up to date"), so it can + // never be a signal that a *peer* has completed its length handshake. + const localCore = await createCore(t) + await localCore.append(['a', 'b', 'c']) + + const emitter = new EventEmitter() + const crs = new CoreSyncState({ + onUpdate: () => emitter.emit('update'), + peerSyncControllers: new Map(), + namespace: 'auth', + deviceId: '', + hasDownloadFilter: () => false, + }) + crs.attachCore(localCore) + + const hold = holdSynchronize(localCore) + const remoteCore = await createCore(t, localCore.key) + const kp2 = NoiseSecretStream.keyPair(Buffer.allocUnsafe(32).fill(1)) + const peerId = kp2.publicKey.toString('hex') + const destroy = replicate(localCore, remoteCore, { kp2 }) + t.after(destroy) + + await once(localCore, 'peer-add') + // Allow any (incorrect) async continuations to settle + await new Promise((res) => setTimeout(res, 200)) + + assert.equal( + localCore.peers[0].remoteSynced, + false, + 'sanity: the peer has not sent its first Synchronize yet' + ) + assert.equal( + crs.getState().remoteStates[peerId].status, + 'starting', + 'peer is still "starting" before its first Synchronize' + ) + + hold.release() + await waitForStatus(crs, emitter, peerId, 'started') + assert.equal( + localCore.peers[0].remoteSynced, + true, + 'sanity: Synchronize has now been processed' + ) +}) + +test('peer status stays "starting" while another peer supplies an upgrade', async (t) => { + // `core.update({ wait: true })` resolves for *all* waiters as soon as any + // peer advances the core's length, so on an actively-transferring core a + // newly-connected peer would be marked "started" before it has said + // anything at all. + const writerCore = await createCore(t) + await writerCore.append(['a', 'b', 'c']) + const localCore = await createCore(t, writerCore.key) + + const emitter = new EventEmitter() + const crs = new CoreSyncState({ + onUpdate: () => emitter.emit('update'), + peerSyncControllers: new Map(), + namespace: 'auth', + deviceId: '', + hasDownloadFilter: () => false, + }) + crs.attachCore(localCore) + + // Sync fully with the writer first + const kpWriter = NoiseSecretStream.keyPair(Buffer.allocUnsafe(32).fill(1)) + const destroyWriterConn = replicate(localCore, writerCore, { + kp2: kpWriter, + }) + t.after(destroyWriterConn) + localCore.download({ start: 0, end: -1 }) + await once(localCore, 'peer-add') + await waitFor(() => localCore.contiguousLength === 3) + + // Now a new peer connects, but its first Synchronize is withheld + const hold = holdSynchronize(localCore) + const newPeerCore = await createCore(t, writerCore.key) + const kpNew = NoiseSecretStream.keyPair(Buffer.allocUnsafe(32).fill(2)) + const newPeerId = kpNew.publicKey.toString('hex') + const destroyNewConn = replicate(localCore, newPeerCore, { kp2: kpNew }) + t.after(destroyNewConn) + await once(localCore, 'peer-add') + + // The writer appends and we download it: the core's length advances, which + // resolves every pending `core.update()` — but tells us nothing about the + // new peer + await writerCore.append('d') + await waitFor(() => localCore.contiguousLength === 4) + await new Promise((res) => setTimeout(res, 200)) + + const newPeer = localCore.peers.find((p) => + p.remotePublicKey.equals(kpNew.publicKey) + ) + assert(newPeer, 'sanity: new peer is connected') + assert.equal( + newPeer.remoteSynced, + false, + 'sanity: the new peer has not sent its first Synchronize yet' + ) + assert.equal( + crs.getState().remoteStates[newPeerId].status, + 'starting', + 'new peer is still "starting" before its first Synchronize' + ) + + hold.release() + await waitForStatus(crs, emitter, newPeerId, 'started') +}) + +test('peer status stays "starting" for a 4th concurrent peer (hypercore upgrade quorum cap)', async (t) => { + // `core.update({ wait: true })` samples at most MAX_PEERS_UPGRADE (3) + // peers, so with 4+ connected peers it can resolve without ever + // consulting the 4th peer's handshake — it must not be treated as a + // per-peer "handshake complete" signal. + const keySource = await createCore(t) // never replicated; provides a key + const localCore = await createCore(t, keySource.key) + + const emitter = new EventEmitter() + const crs = new CoreSyncState({ + onUpdate: () => emitter.emit('update'), + peerSyncControllers: new Map(), + namespace: 'auth', + deviceId: '', + hasDownloadFilter: () => false, + }) + crs.attachCore(localCore) + + // Three peers, fully synced + for (let i = 1; i <= 3; i++) { + const remoteCore = await createCore(t, keySource.key) + const kp2 = NoiseSecretStream.keyPair(Buffer.allocUnsafe(32).fill(i)) + const destroy = replicate(localCore, remoteCore, { kp2 }) + t.after(destroy) + } + await waitFor( + () => + localCore.peers.length === 3 && + localCore.peers.every((p) => p.remoteSynced) + ) + + // A 4th peer connects, but its first Synchronize is withheld + const hold = holdSynchronize(localCore, { maxPeers: 1 }) + const fourthCore = await createCore(t, keySource.key) + const kp4 = NoiseSecretStream.keyPair(Buffer.allocUnsafe(32).fill(4)) + const fourthPeerId = kp4.publicKey.toString('hex') + const destroy = replicate(localCore, fourthCore, { kp2: kp4 }) + t.after(destroy) + await once(localCore, 'peer-add') + + // A 5th peer connects and syncs normally: its handshake re-evaluates + // hypercore's shared upgrade request, which samples only the first + // MAX_PEERS_UPGRADE peers — never the still-silent 4th + const fifthCore = await createCore(t, keySource.key) + const kp5 = NoiseSecretStream.keyPair(Buffer.allocUnsafe(32).fill(5)) + const destroy5 = replicate(localCore, fifthCore, { kp2: kp5 }) + t.after(destroy5) + await waitFor(() => + localCore.peers.some( + (p) => p.remotePublicKey.equals(kp5.publicKey) && p.remoteSynced + ) + ) + // Allow any (incorrect) async continuations to settle + await new Promise((res) => setTimeout(res, 300)) + + assert.equal( + crs.getState().remoteStates[fourthPeerId].status, + 'starting', + '4th peer is still "starting" before its first Synchronize' + ) + + hold.release() + await waitForStatus(crs, emitter, fourthPeerId, 'started') +}) + +test('peer status falls back to "started" if the first Synchronize never arrives', async (t) => { + // A channel close/open crossing can leave the remote never re-sending its + // Synchronize (it believes its old session is still live) — see the + // comment in CoreSyncState's #onPeerAdd. A live channel in that state + // must not block sync state forever: after a fallback timeout the peer is + // treated as started, with its blocks still counted via pre-haves. + const localCore = await createCore(t) + await localCore.append(['a', 'b', 'c']) + + const emitter = new EventEmitter() + const crs = new CoreSyncState({ + onUpdate: () => emitter.emit('update'), + peerSyncControllers: new Map(), + namespace: 'auth', + deviceId: '', + hasDownloadFilter: () => false, + }) + crs.attachCore(localCore) + + // Never released: the Synchronize never arrives + holdSynchronize(localCore) + const remoteCore = await createCore(t, localCore.key) + const kp2 = NoiseSecretStream.keyPair(Buffer.allocUnsafe(32).fill(1)) + const peerId = kp2.publicKey.toString('hex') + const destroy = replicate(localCore, remoteCore, { kp2 }) + t.after(destroy) + + await once(localCore, 'peer-add') + assert.equal( + crs.getState().remoteStates[peerId].status, + 'starting', + 'peer is "starting" while the Synchronize is missing' + ) + + // 5000ms fallback (FIRST_SYNC_FALLBACK_MS) plus margin + await waitForStatus(crs, emitter, peerId, 'started', 8_000) + const livePeer = localCore.peers.find((p) => + p.remotePublicKey.equals(kp2.publicKey) + ) + assert.equal( + livePeer?.remoteSynced, + false, + 'sanity: "started" came from the fallback, not a Synchronize' + ) +}) + +test('peer status becomes "started" for a peer that synced before the core was attached', async (t) => { + // Defensive invariant: production wiring attaches cores before their + // channel handshakes can complete, but nothing in CoreSyncState enforces + // that. A peer whose Synchronize was already processed when the core is + // attached must become "started" without waiting for another message. + const localCore = await createCore(t) + await localCore.append(['a', 'b', 'c']) + const remoteCore = await createCore(t, localCore.key) + const kp2 = NoiseSecretStream.keyPair(Buffer.allocUnsafe(32).fill(1)) + const peerId = kp2.publicKey.toString('hex') + const destroy = replicate(localCore, remoteCore, { kp2 }) + t.after(destroy) + + await once(localCore, 'peer-add') + await waitFor(() => localCore.peers[0].remoteSynced === true) + + const emitter = new EventEmitter() + const crs = new CoreSyncState({ + onUpdate: () => emitter.emit('update'), + peerSyncControllers: new Map(), + namespace: 'auth', + deviceId: '', + hasDownloadFilter: () => false, + }) + crs.attachCore(localCore) + + await waitForStatus(crs, emitter, peerId, 'started') +}) + +/** + * Intercept and queue the first Synchronize message(s) from peers that are + * added to `core` after this is called, so tests can hold a peer in the + * "channel open, length handshake not yet processed" state. Uses the same + * interception point as production code: hypercore dispatches wire messages + * by property lookup on the peer object, so shadowing `onsync` on the + * instance sees every message. + * + * @param {import('hypercore')} core + * @param {object} [opts] + * @param {number} [opts.maxPeers] only hold the first `maxPeers` peers added + * after this call (later peers' messages flow normally) + */ +function holdSynchronize(core, { maxPeers = Infinity } = {}) { + /** @type {Array<() => unknown>} */ + const queued = [] + /** @type {Array<() => void>} */ + const restores = [] + let held = true + let heldPeerCount = 0 + /** @param {import('../../src/types.js').HypercorePeer} peer */ + const onPeerAdd = (peer) => { + if (heldPeerCount >= maxPeers) return + heldPeerCount++ + const originalOnSync = peer.onsync + peer.onsync = (...args) => { + if (!held) return originalOnSync.apply(peer, args) + queued.push(() => originalOnSync.apply(peer, args)) + return Promise.resolve() + } + restores.push(() => { + peer.onsync = originalOnSync + }) + } + core.on('peer-add', onPeerAdd) + return { + release() { + held = false + core.off('peer-add', onPeerAdd) + for (const apply of queued) apply() + for (const restore of restores) restore() + }, + } +} + +/** + * @param {() => boolean} condition + * @param {number} [timeoutMs] + */ +async function waitFor(condition, timeoutMs = 1000) { + const start = Date.now() + while (!condition()) { + if (Date.now() - start > timeoutMs) { + throw new Error('Timed out waiting for condition') + } + await new Promise((res) => setTimeout(res, 10)) + } +} + +/** + * Wait until the peer's status matches, driven by state update events. + * + * @param {CoreSyncState} crs + * @param {EventEmitter} emitter + * @param {string} peerId + * @param {import('../../src/sync/core-sync-state.js').PeerNamespaceState['status']} status + * @param {number} [timeoutMs] + */ +async function waitForStatus(crs, emitter, peerId, status, timeoutMs = 1000) { + await pTimeout( + (async () => { + while (crs.getState().remoteStates[peerId]?.status !== status) { + await once(emitter, 'update') + } + })(), + { + milliseconds: timeoutMs, + message: `Timed out waiting for status ${status}`, + } + ) +} + test('bitCount32', () => { const testCases = new Set([0, 2 ** 32 - 1]) for (let i = 0; i < 32; i++) {