From 0c1eee661a090ceed5d98aa936421cbf2142f6c5 Mon Sep 17 00:00:00 2001 From: Geoff Turk Date: Tue, 1 Sep 2026 10:56:08 +0200 Subject: [PATCH] test(core): wait for the ack instead of assuming it arrives within 20 ms MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `inbound.ack-ordering.mjs` failed in a clean container build of a commit CI had just passed: ✖ the ack waits for a promise-returning handler (the whole R1.6 premise) actual: [ 'handler-start', 'persisted' ] expected: [ 'handler-start', 'persisted', 'ack' ] Nothing had regressed. `vti-didcomm-js` 0.7.0's `_dispatchFrame` still awaits `_deliver` before `_ackReceived`, and the same file passes alone every time. All three tests did `await settle()` — a fixed 20 ms — and then asserted the ack was on the socket. The ack is an authcrypt `pack`, and `node --test tests/*.mjs` runs core's 57 files in parallel with concurrency `cores - 1`. Measured in the container: idle, the ack lands 3-4 ms after the handler resolves; with the suite cold-starting beside it, 14 ms — most of the budget — and on a 24-core machine racing 23 other crypto-heavy files it once took more. GitHub's 4-core runners run three files at a time, which is the only reason CI stays green; every crypto-touching test file added to core moves that runner along the same curve. This is the wrong test to tolerate a flake in. It is the pin on persist-before-ack: the one that goes red if the library ever acks first again, and a pin that goes red for unrelated reasons trains everyone to hit retry past it. The positive assertions now poll for the condition with a 5 s deadline (`until`), so they cost time only when about to fail. The one negative assertion — no ack while the persist is in flight — keeps its fixed wait, because "nothing happened" can only be established by giving it time to happen; under load that window can only false-pass, never false-fail, so it did not share the flake. The KNOWN GAP test's guidance about the library beginning to honour rejections moves into the timeout message, where it now fires. Not reproducible on demand: seen once for certain in four stock container builds, then 0 of 16 further full-suite runs. The fix is argued from the mechanism and the measurements, not from a reproduction. Old and new versions both pass 8/8 in the full parallel suite; the new one also 4/4 under 24 busy loops. Signed-off-by: Geoff Turk --- packages/core/tests/inbound.ack-ordering.mjs | 37 +++++++++++++++----- 1 file changed, 28 insertions(+), 9 deletions(-) diff --git a/packages/core/tests/inbound.ack-ordering.mjs b/packages/core/tests/inbound.ack-ordering.mjs index 00dc66c..b6a0c51 100644 --- a/packages/core/tests/inbound.ack-ordering.mjs +++ b/packages/core/tests/inbound.ack-ordering.mjs @@ -117,6 +117,23 @@ async function harness(onMessage) { const settle = (ms = 20) => new Promise((r) => setTimeout(r, ms)); +// Wait for a condition, not for a fixed interval. `node --test tests/*.mjs` runs +// this suite's files in parallel (concurrency = cores - 1), and the ack is an +// authcrypt `pack`. Idle it lands 3-4 ms after the handler resolves; with the +// rest of the suite cold-starting beside it, 14 ms was measured — most of a +// 20 ms budget — and on a 24-core machine it once took longer, which the test +// read as "the ack never came" (R1.6 regressed) when nothing had regressed. +// GitHub's 4-core runners contend less, which is the only reason CI stayed +// green. The deadline is generous because it only ever costs time when the +// assertion is about to fail anyway. +async function until(predicate, what, deadlineMs = 5000) { + const end = Date.now() + deadlineMs; + while (!predicate()) { + if (Date.now() > end) assert.fail(`timed out waiting for ${what}`); + await settle(5); + } +} + test("the ack waits for a promise-returning handler (the whole R1.6 premise)", async () => { const order = []; let release; @@ -136,13 +153,17 @@ test("the ack waits for a promise-returning handler (the whole R1.6 premise)", a }; ws.inject(jwe); + await until(() => order.length > 0, "the handler to be entered"); + // This one IS a fixed wait, and has to be: "nothing happened" can only be + // established by giving it time to happen. Under load the window can only + // false-pass, never false-fail, so it does not share the flake above. await settle(); assert.deepEqual(order, ["handler-start"], "no ack while the persist is in flight"); assert.equal(ws.sent.length, 0, "the mediator must still hold its copy"); release(); - await settle(); + await until(() => ws.sent.length > 0, "the ack, once the persist settled"); assert.deepEqual(order, ["handler-start", "persisted", "ack"]); const ack = await readAck(); @@ -175,15 +196,13 @@ test("KNOWN GAP: a rejecting handler does NOT suppress the ack (0.6.2)", async ( try { ws.inject(jwe); - await settle(); - - assert.equal( - ws.sent.length, - 1, - "as of 0.6.2 the ack is sent even though the handler rejected — if this " + - "now reads 0, the library began honouring rejections: good news, but " + + await until( + () => ws.sent.length > 0, + "the ack — as of 0.6.2 it is sent even though the handler rejected. If " + + "this timed out, the library began honouring rejections: good news, but " + "update onInboundMessage's comment and this test together", ); + assert.equal(ws.sent.length, 1); } finally { session.close(); } @@ -197,7 +216,7 @@ test("a synchronous handler still acks — nothing regressed for other callers", try { ws.inject(jwe); - await settle(); + await until(() => ws.sent.length > 0, "the ack"); assert.deepEqual(seen, ["urn:uuid:consent-1"]); assert.equal(ws.sent.length, 1);