Repository navigation
Conversation
…ed runners On a saturated runner, startup, Source capture and Dream processing can keep SQLite's writer slot from the model usage recorder for more than the test's 5 s write budget. The recorder then drops the embedding record, as its best-effort contract allows, and the exact-total assertion reads zero. Give this test a 20 s write budget, about three times the slowest write measured under load, and a 30 s flush so a stats read still outlasts one write. Assertions are unchanged.
This branch has not been deployed
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.
Which issue or RFC does this PR close?
No tracking issue. Fixes an intermittent
tests (3.11, e2e)failure intests/e2e/test_dream_usage.py::test_memory_dream_approval_embedding_usage_survives_replay_and_restart, seen on 2026-11-14 in #2550 (run 43546529259) and #2518 (run 43537990051). Usage semantics follow RFC 0072 (docs/en/rfcs/0072_scoped_statistics_and_usage.md).Rationale for this change
Both failures assert
before["totals"]["embedding"] == {"requests": 1, "input_tokens": 7, "output_tokens": None}and read all zeros. Both logs containModel usage write failed; record will not be retried, so the recorder dropped the embedding record fromatomic_memory.create.The failure reproduces locally when the test runs repeatedly under load: 18 xdist workers, 36 CPU-bound processes, 6 processes doing
F_FULLFSYNCwrites, and SQLitefullfsyncon. CPU load alone did not reproduce it (0 of 120 runs). A scratch probe wrapped_ModelUsageRecorder._writeandAsyncDatabase.statistics_transaction. Results:Artifact processing failed(scope-discoveryTimeoutError).TimeoutErrorfrom_writeonceremaining <= 0, so the 5-second write budget had run out. No attempt failed with an unknown commit outcome or a non-contention error.The test's first embedding record competes with runtime startup, Source capture and Dream processing for that slot. On SQLite the recorder's deferred transaction cannot queue for the slot: the read-to-write upgrade fails at once while another connection writes, and the recorder retries every 20 ms. On a saturated runner it can find no free gap within five seconds. RFC 0072 allows the recorder to drop such a record: usage recording is best-effort and must not retry anything that could double-count. The recorder behaves as specified. The test needed more than the best-effort contract promises under load.
The test does not exercise the write budget. It checks that exact totals survive approval, replay and restart. This PR gives it a 20 s write budget, about 3× the slowest write measured under load (6.88 s), and a 30 s flush budget, so one stats read still waits out a full write as it did before (10 s flush against 5 s write). The recorder tests in
tests/builtin/runtime/test_model_usage_recorder.pystill cover drops and bounded shutdown under short budgets.What changes are included in this PR?
tests/e2e/test_dream_usage.py: the approval/replay/restart test usesmodel_usage_write_timeout_seconds=20.0andmodel_usage_flush_timeout_seconds=30.0instead of 5.0 and 10.0. Its comment now states why. Every assertion is unchanged.test_dream_worker_usage_persists_once_in_scope_stats, keeps its 5 s budget. Under the same load it passed 200 of 200 runs, and its single usage batch, written after the Dream run completes, settled in at most 1.81 s.No runtime code changes.
Are there any user-facing changes?
No.
How was this change tested?
Load harness (scratch, not committed): repeated runs of the test under the load described above.
The 30 s row measures how long writes need when the budget is not the limit: 16 of 648 batches needed more than 5 s and would have been dropped at the old budget, and none needed more than 10 s. With the final 20 s budget, 16 of 432 batches again needed more than 5 s and all were written; the slowest needed 6.88 s, so the budget leaves about 3× margin. For one of the two 20 s rounds only the probe output was kept (0 dropped writes); the other round reported
108 passed. Load on GitHub runners may differ from this local setup.Commands:
uv run pytest tests/e2e/test_dream_usage.py tests/builtin/runtime/test_model_usage_recorder.py -n 8: 45 passed, 1 skippedmake check: passed, includingtySelf-review against
REVIEW.mdand an independent Opus review of the diff found no defect. Two review points are applied: the comment names only the first embedding record as competing with capture and processing, and the write budget is 20 s so the 30 s flush still outlasts one write.Remaining notes:
Design notes (non-blocking, not part of this PR):
busy_timeoutthat_sqlite_model_usage_transactionsets has no effect there. A contended attempt fails at once and the recorder polls through the event loop with 20 ms backoff. In the master runs above that meant 14.5 attempts per batch on average, up to 46. Beginning the usage transaction withBEGIN IMMEDIATEcut that to 1.4 attempts per batch, but did not significantly change the failure rate (5 of 432 against 10 of 432 under the same alternating load), so this PR leaves it out.Artifact processing failedscope-discovery timeouts in the same CI logs.AI usage statement
This change was written by Claude Code (Claude Opus 5.5). Claude Code reproduced the failure, ran the load measurements and the checks listed above, and wrote this description.