Symptom
SimulatedMeshTests.publicMessageRelaysAcrossLineTopologyWithinTTLBudget fails
intermittently in CI:
SimulatedMeshTests.swift:75:9: Expectation failed:
(mesh.deliveredFrameCount - baseline → 16) <= 12Always 16. Never 13, never 21.
It is not caused by the PR under test
Observed on seven unrelated PRs in ~24h, none of which touch BLE, the mesh, or any transport code:
| PR branch | subject |
|---|---|
feat/thread-message-search | in-thread message search |
feat/message-deep-link-copy | copy deep links |
feat/clear-unread-conversation | clear unread badge |
feat/l10n-catalog-key-scan | CI lint for missing l10n keys |
feat/export-chat-plaintext | export chat as plaintext |
feat/people-sheet-name-filter | filter nicknames in people sheet |
feat/thread-message-search produced the byte-identical assertion, same line,
same value 16.
Root cause
The harness is deterministic in scheduler time but the announce admission decision reads wall-clock time.
BLEService.performMaintenance()runs on the manual scheduler (somesh.advanceTime(_:)drives it), but computesannounceThrottle.elapsed(since: Date())— real time.BLEService.swift:2760—announceThrottle.shouldSend(force:, now: Date()).- Gate:
TransportConfig.bleForceAnnounceMinIntervalSeconds = 0.15.
So whether the maintenance announce is emitted depends on how long the test took in real seconds:
- Fast machine: the whole test runs in ~34 ms. Real elapsed never reaches 0.15 s, every maintenance announce is throttled away, count is 12, passes.
- Loaded CI runner: pumping and engine fences across three nodes cross 0.15 s, all three nodes emit a maintenance announce.
The +4 is exactly those three announces, counted per (packet, receiver, link):
a → b = 1 frame
b → a, b → c = 2 frames
c → b = 1 frame
= 4 → 12 + 4 = 16The test file already acknowledges the gap, at line 133, for the opposite case:
// (The announce throttle runs on wall clock; model elapsed time.)
b.service._test_resetAnnounceThrottle()_test_resetAnnounceThrottle() can force an announce through the throttle.
Nothing can hold one back, and the storm bound depends on them being held back.
Reproduction (local, deterministic)
On an unmodified checkout the test passes 19/19. Insert a real sleep past the 0.15 s gate — changing nothing else — and it fails with the exact CI value:
a.service.sendMessage("hello line", mentions: [])
mesh.pump()
Thread.sleep(forTimeInterval: 0.2) // <-- only change
mesh.advanceTime(by: 2)
mesh.advanceTime(by: 2)Result: (mesh.deliveredFrameCount - baseline → 16) <= 12 — identical to CI.
| Condition | frames | result |
|---|---|---|
| unmodified, 19 consecutive runs | 12 | pass |
| + 0.2 s wall-clock sleep | 16 | fail |
Suggested fix
Two options, not mutually exclusive.
1. Make the storm bound measure what it claims (small, test-only).
The assertion is about a single public message not multiplying across a relay
hop. Counting unrelated maintenance announces in that budget conflates two
things. Filtering the counted frames to the message packet — or exposing a
per-type count on SimulatedMesh — makes the bound immune to announce timing
and tightens what it actually asserts.
2. Put announce admission on scheduler time (deeper).
shouldSend(force:now:) already takes now as a parameter; only the call
sites hardcode Date(). Threading an injectable date provider through
performMaintenance / sendAnnounceNow — defaulting to Date.init — would
close the last wall-clock leak in an otherwise deterministic harness and
retire the _test_resetAnnounceThrottle workaround.
Option 1 unblocks the PR queue immediately. Option 2 is the real fix.
Activity
2.
Correction to the analysis above — the mechanism I named was wrong.
I attributed the extra frames to maintenance announces. That is impossible in this harness:
startMaintenanceTimerguards onmeshBackgroundEnabled, whichSimulatedMeshdisables by constructing every node withinitializeBluetoothManagers: false, soperformMaintenance()never runs. It is also a 5.0sDispatchSourceonbleQueue, whichadvanceTimecould not drive regardless. My "exactly four extra frames" arithmetic was wrong too — I fitted it to16 - 12using the budget as if it were the measurement.What the measurement actually shows. Burning 0.2s of wall clock mid-test, changing nothing else:
So the passing delta is 10, not 12, and the gap is six announce frames. Every other packet type is identical.
The part that survives, because it was measured rather than reasoned: announce admission is gated on wall clock at
BLEService.swift:2760—announceThrottle.shouldSend(force:now: Date())— while the harness controls only scheduler time, and the forced-announce window is 0.15s. That is enough to make the total frame count environment-dependent, which is why this fails on PRs with no transport code in them.I have not isolated which scheduled announce path emits under starvation, and I am not going to guess a third time. The admission gate is common to all of them.
#1622 is updated to match; its diff is unchanged, since
messagestays at 4 under exactly the perturbation that moves the total.