From 10314c5dea2c91b5c0a36f8ef5884df6d766d556 Mon Sep 17 00:00:00 2001 From: Meg-2646 Date: Fri, 16 Oct 2026 16:22:35 -0400 Subject: [PATCH 1/2] test(mcpl): vector 34c bounds its store syncs, not its time Vector 34c sends 300 coalesced channel messages one at a time and failed when they took 30 s or more. Each acceptance waits for its durable commit, a store sync, so the time follows the disk and the host's load more than the code. In six runs on a Linux host at load averages of 57 to 78, three of them beside six busy node loops, main's version took from 10.8 s to 34.1 s and failed once. With each store sync slowed by 120 ms, it failed both runs on time alone, at 44.2 s and 46.7 s, since 300 syncs at 120 ms take 36 s by themselves. The bound guarded the cost #196's review measured, 85 ms a message, from a journal that synced the store for each of three operations per message. The test now counts store.sync() calls during the 300 sends and requires at most 300, so a commit shared between acceptances would still pass. It turns the framework's periodic store sync off (syncIntervalMs: 0), which the fixture never starts anyway, so every sync it counts is an acceptance's. It reports the time beside the count, and its functional checks are unchanged. This version passes with each store sync slowed by 120 ms and beside six busy loops, making 300 store syncs in every run. With each acceptance committing twice, it fails with 600 store syncs. Co-Authored-By: Claude Opus 5.5 --- test/mcpl-coalescing.test.ts | 21 ++++++++++++++++----- 1 file changed, 16 insertions(+), 5 deletions(-) diff --git a/test/mcpl-coalescing.test.ts b/test/mcpl-coalescing.test.ts index c5bac52d1..47a97deb9 100644 --- a/test/mcpl-coalescing.test.ts +++ b/test/mcpl-coalescing.test.ts @@ -402,15 +402,28 @@ test('vectors 7/47: restart keeps accepted content, receipts, and appends after }); test('#196 finding 2 / vector 34c: a busy channel never hits a subject cap', async (t) => { - const f = await fixture({ framework: { gate: { config: { policies: [{ name: 'attention', match: { tagsAny: ['chat:mention'] }, behavior: 'always' }], default: 'skip' } } } as never }); t.after(f.close); await f.register(); + // The periodic store sync stays off (syncIntervalMs: 0), so every sync + // counted below is an acceptance's. + const f = await fixture({ framework: { gate: { config: { policies: [{ name: 'attention', match: { tagsAny: ['chat:mention'] }, behavior: 'always' }], default: 'skip' } }, syncIntervalMs: 0 } as never }); t.after(f.close); await f.register(); const msg = (i: number | string, tags: string[]) => ({ channelId: 'chat', messageId: 'm' + i, eventId: 'e' + i, timestamp: TS, author: { id: 'u', name: 'User' }, tags, content: [{ type: 'text', text: 'text_' + i }], coalesce: { key: 'message:m' + i, initial: true } }); + // #196's review measured 85 ms a message on this path, because its journal + // synced the store for each of three operations per message. An acceptance + // now awaits one durable commit (RFC-006), so 300 messages sent one at a + // time make 300 store syncs. The bound is on that count, from above, so + // commits shared between acceptances would still pass. The time depends on + // the disk and the host's load, so it's reported, not asserted. + const store = (f.framework as unknown as { store: { sync: (...a: unknown[]) => unknown } }).store; + const sync = store.sync.bind(store); + let syncs = 0; + store.sync = (...a: unknown[]) => { syncs++; return sync(...a); }; const t0 = Date.now(); for (let i = 0; i < 300; i++) { const r = await f.send('channels/incoming', { messages: [msg(i, [])] }); assert.equal(r.result.results[0].accepted, true); } const elapsed = Date.now() - t0; + const synced = syncs; await f.framework.runUntilIdle(); assert.equal(f.membrane.calls.length, 0); const mention = await f.send('channels/incoming', { messages: [msg('mention', ['chat:mention'])] }); @@ -418,10 +431,8 @@ test('#196 finding 2 / vector 34c: a busy channel never hits a subject cap', asy await f.framework.runUntilIdle(); assert.equal(f.membrane.calls.length, 1); assert(f.lastRequest().includes('text_mention') && f.lastRequest().includes('text_0')); - // Each acceptance awaits a group-committed fsync (RFC-006 durability); serial - // sends cannot batch, so this is ~300 fsyncs. Bounded, and reported. - console.log(`# 300 serial coalesced channel messages: ${elapsed}ms (${(elapsed / 300).toFixed(1)} ms/msg incl. fsync)`); - assert(elapsed < 30_000, `300 coalesced messages took ${elapsed}ms`); + console.log(`# 300 serial coalesced channel messages: ${elapsed}ms (${(elapsed / 300).toFixed(1)} ms/msg incl. fsync), ${synced} store syncs`); + assert(synced <= 300, `300 coalesced messages made ${synced} store syncs, more than one a message`); }); test('#196 finding 4: a context-budget restart does not assemble a pending batch', async (t) => { From f446e8d0e2e3dc4e2119ea50f6103667bc2e59f2 Mon Sep 17 00:00:00 2001 From: Meg-2646 Date: Sat, 17 Oct 2026 00:28:26 -0400 Subject: [PATCH 2/2] test(mcpl): vector 34c's count gets a floor, and its comment says what holds it From an internal review of the commit before this one: - The count had a ceiling and no floor, so a count that stopped seeing the commits, or acceptances that stopped committing, read 0 and passed. It must now be at least one as well as at most one a message, and the ceiling comes from the loop's number of sends. - The comment credited syncIntervalMs: 0 with making every counted sync an acceptance's. start() arms the periodic sync, and this fixture never calls it; the option keeps that sync off if one ever does. The comment now says so, and that the count takes every store sync during the sends. - The comment said the time is reported, not asserted. Each send still has the fixture's reply deadline, its guard against a hang, and the comment says that too. Run with each acceptance's commit removed, the test now fails at the floor: "300 coalesced messages made no store sync: the acceptances didn't commit, or the count can't see their commits". With each acceptance committing twice, it fails at the ceiling with 600 store syncs, and as it is it passes with 300. Co-Authored-By: Claude Opus 5.5 --- test/mcpl-coalescing.test.ts | 24 +++++++++++++++--------- 1 file changed, 15 insertions(+), 9 deletions(-) diff --git a/test/mcpl-coalescing.test.ts b/test/mcpl-coalescing.test.ts index 47a97deb9..fff98f187 100644 --- a/test/mcpl-coalescing.test.ts +++ b/test/mcpl-coalescing.test.ts @@ -402,23 +402,28 @@ test('vectors 7/47: restart keeps accepted content, receipts, and appends after }); test('#196 finding 2 / vector 34c: a busy channel never hits a subject cap', async (t) => { - // The periodic store sync stays off (syncIntervalMs: 0), so every sync - // counted below is an acceptance's. + // start() arms the periodic store sync, and this fixture never calls it; + // syncIntervalMs: 0 keeps that sync off if one ever does. const f = await fixture({ framework: { gate: { config: { policies: [{ name: 'attention', match: { tagsAny: ['chat:mention'] }, behavior: 'always' }], default: 'skip' } }, syncIntervalMs: 0 } as never }); t.after(f.close); await f.register(); const msg = (i: number | string, tags: string[]) => ({ channelId: 'chat', messageId: 'm' + i, eventId: 'e' + i, timestamp: TS, author: { id: 'u', name: 'User' }, tags, content: [{ type: 'text', text: 'text_' + i }], coalesce: { key: 'message:m' + i, initial: true } }); // #196's review measured 85 ms a message on this path, because its journal // synced the store for each of three operations per message. An acceptance - // now awaits one durable commit (RFC-006), so 300 messages sent one at a - // time make 300 store syncs. The bound is on that count, from above, so - // commits shared between acceptances would still pass. The time depends on - // the disk and the host's load, so it's reported, not asserted. + // now awaits one durable commit (RFC-006), so messages sent one at a time + // make one store sync each. The count takes every store sync during the + // sends; nothing else in this fixture syncs the store meanwhile. It must be + // at least one, or the count no longer sees the commits, and at most one a + // message, so commits shared between acceptances would still pass. The + // total time depends on the disk and the host's load, so it's reported, not + // asserted; each send keeps the fixture's reply deadline, its guard against + // a hang. const store = (f.framework as unknown as { store: { sync: (...a: unknown[]) => unknown } }).store; const sync = store.sync.bind(store); let syncs = 0; store.sync = (...a: unknown[]) => { syncs++; return sync(...a); }; + const sends = 300; const t0 = Date.now(); - for (let i = 0; i < 300; i++) { + for (let i = 0; i < sends; i++) { const r = await f.send('channels/incoming', { messages: [msg(i, [])] }); assert.equal(r.result.results[0].accepted, true); } @@ -431,8 +436,9 @@ test('#196 finding 2 / vector 34c: a busy channel never hits a subject cap', asy await f.framework.runUntilIdle(); assert.equal(f.membrane.calls.length, 1); assert(f.lastRequest().includes('text_mention') && f.lastRequest().includes('text_0')); - console.log(`# 300 serial coalesced channel messages: ${elapsed}ms (${(elapsed / 300).toFixed(1)} ms/msg incl. fsync), ${synced} store syncs`); - assert(synced <= 300, `300 coalesced messages made ${synced} store syncs, more than one a message`); + console.log(`# ${sends} serial coalesced channel messages: ${elapsed}ms (${(elapsed / sends).toFixed(1)} ms/msg incl. fsync), ${synced} store syncs`); + assert(synced > 0, `${sends} coalesced messages made no store sync: the acceptances didn't commit, or the count can't see their commits`); + assert(synced <= sends, `${sends} coalesced messages made ${synced} store syncs, more than one a message`); }); test('#196 finding 4: a context-budget restart does not assemble a pending batch', async (t) => {