fix(test): de-flake auditLog 'check log after writes and prune' - #1993
Closed
kriszyp wants to merge 5 commits into
Closed
fix(test): de-flake auditLog 'check log after writes and prune'#1993kriszyp wants to merge 5 commits into
kriszyp wants to merge 5 commits into
Conversation
Contributor
There was a problem hiding this comment.
Code Review
This pull request refactors the audit log unit test to address flakiness under CI load. It replaces a fragile fixed-delay polling loop with a robust waitFor utility that asserts on specific terminal events by content rather than just checking the event count. Additionally, a non-superseded write (ID 99) is introduced to ensure its event survives coalescing. I have no feedback to provide as the changes are well-implemented and follow the repository's testing practices.
Contributor
|
Reviewed; no blockers found. |
kriszyp
marked this pull request as ready for review
July 29, 2026 14:48
The subscription event count in this test raced against the async, setImmediate-deferred notify pass in transactionBroadcast.ts. Table.ts's subscription listener only forwards the *latest* value for a given id (an intentional coalescing: an audit record whose version no longer matches the primary entry's live version is dropped as "out of order"). With only two distinct ids touched (id 1: put+delete, id 2: put+put), the guaranteed delivered-event floor was 2, not >2 - the assertion only passed when the notify pass happened to interleave between same-id writes, which is exactly the runner-load-dependent race in #1939. Add a third id with a single, never-superseded write. Its event can never be coalesced away, so events.length reaching 3 is now a deterministic floor instead of a timing gamble; the poll loop just accounts for the notify pass's async delivery latency, with a generous timeout for a loaded runner. Verified stable over 20 local runs and 15 runs under artificial full-core CPU load, plus 10 runs under the LMDB storage engine (which exercises the prune path this test also covers). Refs #1939 Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Independent review (codex) caught that events.length >= 3 alone can be satisfied by early, coalescible events (the id 1 / id 2 puts) without ever proving the terminal writes were delivered - a regression that drops put(2, two-changed) or delete(1) could still pass. Wait for and assert each terminal event by id/type/value instead, using the shared waitFor() helper. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
kriszyp
force-pushed
the
fix/deflake-audit-log-prune-test
branch
from
July 30, 2026 17:35
8dd6e3a to
74f00a1
Compare
Windows CI Integration Tests 1/6 fails the entire early-hints suite in before() with an uncaught fetch HeadersTimeoutError: deploy_component uses restart: true, so Harper can restart before the HTTP response for the deploy call lands, and a slow runner exceeds undici's default headers timeout. The readiness poll right after (which waits for /hints + seed data) is the real success check, so tolerate a missing/failed deploy response instead of failing the suite. This mirrors the same fix from #1504 (closed unmerged, unrelated reasons) — reproduced independently from PR #1993's CI logs, confirmed as a pre-existing flake on main (unrelated to this PR's audit-log change) by diffing two green/red main runs from earlier today, both hitting the same test/error/duration signature. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Independent review (Codex, Gemini, Grok) unanimously flagged the prior broad catch: sendOperation throws an AssertionError (via assert.equal) for a non-200 response, distinct from the TypeError fetch throws for a transport-level failure. Rethrow anything that isn't the transport TypeError so a genuine Operations API regression still fails the test instead of being masked by the readiness poll succeeding. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Independent review flagged if (deployBody) as skipping the message/deployment_id contract assertions on any falsy-but-successful response (e.g. a 200 with a null body), not just a missing one. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
What
De-flakes the
Audit log > check log after writes and pruneunit test (unitTests/resources/auditLog.test.js), which was intermittently failing onmain'sUnit Testworkflow (Node 22 leg) withAssertionError: Should have at least a couple of update events.Why it was flaky (root cause, not just symptoms)
Investigated the write→subscription-event path (
resources/transactionBroadcast.ts,resources/Table.ts) before touching the test, per the task's instruction to rule out a real product bug first.Table.ts's per-key subscription listener intentionally forwards only the latest value for a given id: if the current primary-store entry's version no longer matches the audit record being processed, the record is dropped as "out of order" (an accepted design choice — confirmed by a prior commit, "It is possible that not every write will result in an event", which is what relaxed this assertion from=== 4to> 2in the first place). Delivery itself is asynchronous: a'committed'event is coalesced and deferred viasetImmediatebefore the audit log is walked and subscribers notified.The test's write sequence only touched two distinct ids:
put→deleteput→put(changed)Given the coalescing rule above, the guaranteed floor of delivered events for this sequence is exactly 2 (the final write to each id) — not 3. Getting a 3rd event depended on the async notify pass happening to run between two same-id writes, which is inherently timing-dependent and explains the correlation with loaded/degraded CI runners in issue #1939.
This is not a product bug: the coalescing behavior is intentional and was already accepted product behavior. It is a test that asserted a floor the design doesn't actually guarantee.
Fix
events.length >= 3count check with content-based assertions for the three specific terminal events (put(99),put(2, two-changed),delete(1)), using the sharedunitTests/waitFor.jscondition-wait helper. A bare count could otherwise be satisfied by early, coalescible events without ever proving the terminal writes were delivered.Testing
npm run build(TypeScript build, clean)unitTests/resources/auditLog.test.js(targeted test): 20/20 passing locally (idle), 12/12 passing under artificial full-core CPU load (nprocbusy-loop processes), 10/10 passing underHARPER_STORAGE_ENGINE=lmdb(exercises the prune branch this test also covers)unitTests/resources/auditLog.test.jssuite: 19/19 passingnpm run test:unit:resources: 1286 passing, 14 pending, 0 failing (matches the clean-run baseline noted in the dispatch)verdict: LGTM, no findings.Out of scope
The same workflow's Node 24/26 legs fail on an unrelated rocksdb-js
Invalid column family specified in write batcherror (issue #1381) — not touched here.Refs #1939
🤖 Generated with Claude Code