Skip to content

message-index-async boot-quiet test has an 80ms wall-clock budget for two full reconcile cycles — fails under CI load #333

Description

@iceteaSA

Summary

message-index-async > rebuilds when removal overtakes a boot-quiet reconciliation failed a Check (plugin) run with an assertion failure at 114 ms (not a timeout). The test's verdict depends on wall-clock timing under load rather than on behavior.

Second instance of the class in #330, different mechanism — #330 is raw work volume against the default timeout, this is a race window that must close inside a fixed await.

What I can and cannot show

Being explicit about the evidence, because it is one observation:

  • Observed: one failure in CI (run 32074486840, job 95524587443) on a fork branch based on b27a6d76 (v0.38.0). 4118 pass / 1 fail.
  • Not reproduced locally: 14/14 in isolation, and 0 failures in 10 consecutive idle runs on my machine.
  • The file is byte-identical to upstream (git diff --quiet upstream/master on that path is clean), so the branch does not modify it.
  • I could not re-run the job to check recurrence — no admin rights on the repo. Filing without that evidence rather than sitting on it.

So: not proven systematic. The structural argument below is why I think it is worth a look regardless.

Mechanism

message-index-async.test.ts:361-380:

setBootQuietPeriodForTests(Date.now() - BOOT_QUIET_MS + 20);   // quiet expires in ~20ms

scheduleReconciliation(db, sessionId, readSurviving);
scheduleClearAndReindex(db, sessionId, readSurviving);

await wait(80);

expect(reads).toBe(2);
expect(countMessageRows(db, sessionId, "m-survivor")).toBe(1);
expect(isSessionReconciled(sessionId)).toBe(true);

What has to fit inside that 80 ms, twice over:

  1. scheduleAfterBootQuietsetTimeout(task, bootQuietRemainingMs())20 ms (boot-quiet.ts:22)
  2. defer(() => …) — a second scheduling hop (message-index-async.ts:208)
  3. reconcileSessionIndex / clear-and-reindex — real SQLite work, async
  4. the .finally() bookkeeping that flips isSessionReconciled

So ~60 ms of slack covers two complete reconcile cycles including DB writes. A late setTimeout fire or slower disk on a shared runner eats that.

For contrast, the same file uses await wait(140) 10 times and await wait(20) 14 times — the 20 ms ones cover a single already-past-quiet defer, and the 140 ms ones have real slack. This is the only site where a ~20 ms timer, two scheduling hops, and two DB cycles all have to land inside one fixed window.

One cross-signal worth noting

On my hardware, this test passes and #330's storage-embedding-measurements cap test fails. On the CI runner, the reverse: #330's test passes (faster box) and this one fails. Two different tests, two different machines, each failing on the machine that happens to disfavor it.

That is the general shape of the problem rather than an argument about either test specifically: the plugin suite currently has at least two verdicts that are functions of hardware speed. Related to my note in #330 that no test in the package declares an explicit timeout — the defaults are doing load-bearing work they were not chosen for.

Suggested fix

Prefer determinism over a bigger number:

  1. Drive the scheduling with fake timers so the test asserts ordering rather than racing a stopwatch. setBootQuietPeriodForTests already exists as a seam and its own docstring says "test seam for deterministic fake-timer coverage" — this test uses it with real timers.
  2. Failing that, poll for the condition instead of sleeping a fixed budget (await until(() => reads === 2, { timeout: 5_000 })), so a slow runner is slow rather than red.

Raising 80 → 300 would also work but only moves the threshold; the verdict stays hardware-dependent.

Environment

  • Failure: GitHub Actions ubuntu-latest, run 32074486840
  • Local non-repro: Linux, bun 1.3.14, 16 cores idle
  • Upstream master CI is green at b27a6d76, so this is not a standing breakage

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions