Repository navigation
fix(daemon): root-cause seven load-only daemon test failures - #4144
Conversation
The hook work runs on a native worker and can finish before the admitting test thread resumes, so checking a shared flag right after admit read a background run as a synchronous one. Mark the admitting thread for the duration of the call and count only work that ran inside it. Refs #4135
The cancellation test gave settlement a one second deadline and a one second outer timeout, so a settlement chain that crossed three threads under load hit the timeout. Put the deadline past any run so only the caller's cancellation can request the daemon cancel. Settlement itself bounds both tests: a missed daemon cancel ends in ResetRequired and an undetached work flag, so the outer timeouts are dropped. Refs #4135
A finished hook cycle left the in-flight maps and fired its completions while still holding its permit. An admission in that gap found no cycle to join and no permit, so a replay of a settled cycle was backpressured. Release the permit before settling, so a completion only fires once the next admission can run. Refs #4135
The nested read held its project lease until settlement aborted it after the one second read grace, so quiescence's two second drain spent half its budget on that grace, and a two second outer timeout bounded a settlement that needs one second plus scheduling. Under load the timeout fired. The read now releases its lease when it observes the admitted cancellation and never returns, so settlement still takes its admitted-cancellation branch and aborts it. The Cancelled outcome, not a timer, proves the admitted cancellation settled the read, and a dropped channel proves the abort. Refs #4135
The raw client wrote its preface, handshake and request as separate writes and expected each to succeed. The daemon refuses on the preface and closes once its drain of pipelined input sits idle for 100 ms, so a client stalled between writes under load hit a broken pipe before reading anything. The refusal frame is queued before that close, so the client now stops writing on a broken pipe or reset and reads it. Refs #4135
An idle scan one Codex consumer runs is queued for every other consumer. A consumer that polls after a rollout grew is answered from that queue with the empty pass of a scan that began before the growth, so it converges without the new bytes. This fails until the hub stops serving such stale empty passes. Refs #4135
The shared Codex discovery hub queues each scan's pass for every consumer. A consumer polling after a rollout grew popped the empty pass of a peer's idle scan that began before the growth and converged on it, so the streamed message waited for the next idle recheck a minute later. Under load the journey test read that convergence as a dropped message. Number shared scans and drop a queued empty pass whose scan began before the poll, so the consumer scans again. A pass with paths or a moved frontier is still delivered in order. Refs #4135
|
![devin-ai-integration[bot]](https://avatars.githubusercontent.com/in/811515?s=60&v=4){kind=small}
| if scan <= scans_before_poll | ||
| && queued.pass.report.paths.is_empty() | ||
| && queued.pass.selected_sources.is_empty() | ||
| && queued.pass.next_frontier == queued.base |
There was a problem hiding this comment.
🔴 New Codex rollouts missed after shared scan
When a rollout appears after a shared scan with existing paths, discover_blocking delivers that stale nonempty pass to another consumer. The consumer marks discovery complete without the new rollout and waits for its next idle recheck.
Learn more
Shared Codex scans are queued for every registered consumer. The new staleness check skips only passes with no paths, no selected sources, and an unchanged frontier. A completed scan containing existing rollouts remains queued when another consumer polls later; if a new rollout was created in between, that queued pass lacks it but still advances the second consumer to the completed frontier. The project and profile consumers use this delivery through run_codex and the profile ingestion path, so the missing rollout is not ingested on that recheck.
Example: Profile scans one existing rollout and queues a complete pass for Project. A second rollout is created before Project polls. Project receives the queued pass containing only the first rollout, commits completion, and does not see the second until its later idle recheck.
Recommended fix: Treat queued passes produced before the current poll as potentially stale even when they contain paths or advance the frontier. Preserve each consumer's frontier and ordered delivery while refreshing or validating stale passes against the current corpus; add a two-consumer test that creates a second rollout after a nonempty completed scan.
Was this helpful? React with 👍 or 👎 to provide feedback.
1 participant
Fixes #4135
Summary
Seven daemon tests failed only under CPU load. Two of them exposed production defects: the shared Codex discovery hub served a stale empty scan, and the hook orchestrator held its permit past settlement. The other five relied on test-side timing or thread identity. This PR fixes each at its cause. It adds no sleeps and widens no timeouts. Where a wall-clock bound only stood in for a typed outcome, the bound is gone and the outcome carries the assertion.
Load recipe (the #4124 recipe):
bazel test //crates/tracedecay:unit_test --runs_per_test=30 --nocache_test_results --local_test_jobs=20 --test_timeout=1800 --run_under=<exec taskset -c 0-7 "$@">. Targeted runs restrict with--test_arg=<filter>.Root causes
idle_history_reads_journey_test::streamed_codex_message_reads_only_its_rollout(production fix intracedecay-sessions)Failing before (2 of 30 at baseline, 6 of 30 and 8 of 20 in later runs):
The project scope and the profile scope are two consumers of one shared Codex discovery hub. The hub queues every shared scan's pass for every consumer. A trace of the hub's deliveries in failing runs shows this order:
The project's idle recheck came after the append. It popped the empty pass of a profile scan that began before the append, converged on it as epoch 2, and slept for another minute. In passing runs the profile's scan ran after the append, and the project received a pass with the rollout.
Fix: the hub numbers shared scans. When a consumer polls and finds an empty, frontier-neutral queued pass from a scan that began before the poll, it drops that pass and scans again. Passes that carry paths or move the frontier are still delivered in order.
a_poll_after_growth_is_not_answered_by_an_earlier_empty_scanreproduces the defect without load and fails before the fix (the grown rollout must be rediscovered: []). The journey test itself is unchanged.invocation_tests::types_tests::hook_orchestration_runs_feedback_work_without_scout_lifecycleFailing before (1 of 30 at baseline; 58 of 300 in a targeted run):
The hook work runs on a native worker (
NativeTask::spawn). It can run before the admitting test thread reaches the assertion, so a shared flag read a background run as a synchronous one. This is the #4124 class: the instrumentation assumed the work ran relative to the test thread.Fix: a thread-local marks the admitting thread for the duration of the admission call. Only work that runs inside that call counts as synchronous.
invocation_executor::controlled_invocation_tests::in_process_effect_cancellation_requests_daemon_cancel_and_awaits_settlementFailing before (1 of 30):
The settlement deadline was 1 s and the outer timeout was also 1 s. The chain from caller cancellation to daemon cancel to native completion crosses three threads, and under load it took longer than 1 s. A 1 s deadline also meant the deadline path could stand in for the cancellation path. The test now passes a 24 h deadline, so only the caller's cancellation can request the daemon cancel. The outer timeout is gone: settlement bounds itself, and a missed daemon cancel ends in
ResetRequiredwith an undetached work flag. The deadline sibling (in_process_effect_deadline_requests_daemon_cancel_and_awaits_settlement) had the same 1 s outer bound and gets the same change.invocation_executor::controlled_invocation_tests::in_process_read_observes_admitted_outer_cancellation_after_startFailing before (7 of 30):
The nested read held its project lease until settlement aborted it after the 1 s read grace. That grace spent half of quiescence's 2 s production drain budget (
DAEMON_TASK_ABORT_DEADLINE) and half of the test's 2 s outer timeout, leaving 1 s for scheduling. The read now releases its lease when it observes the admitted cancellation and then never returns. Settlement still takes its admitted-cancellation branch and aborts the read. TheCancelledoutcome proves the admitted cancellation settled the read: without it the read would settleTimedOutat its 10 s deadline. A dropped channel proves the abort.invocation_tests::types_tests::replayed_admission_after_retryable_failure_completes_a_fresh_cycle(production fix intracedecay-daemon-service)Forced before. A 20 ms pause was injected between
settle_operationremoving the in-flight entries and firing completions. It failed 5 of 5:A finished hook cycle left the in-flight maps and fired its completions while it still held its permit. An admission in that gap found no cycle to join and no free permit, so a replay of a settled cycle was backpressured. A completion also fired before the next admission could run.
BoundedHookOrchestratorV1now releases the permit before it settles the operation. The same 20 ms pause with the fix passes 5 of 5 across all oftypes_tests.authentication_refusal_test::rejected_token_reads_typed_refusal_and_daemon_keeps_serving(daemon_suite)Failing in the local merge gate (twice):
The daemon refuses on the preface alone. It writes the refusal frame, drains pipelined input until a line read sits idle for 100 ms, and closes. The raw client wrote preface, handshake and request as separate writes, and each
expected success. A client stalled between writes under load hit a closed socket. A 300 ms pause after the preface reproduces this 3 of 3. The refusal frame is queued before the close, so the client now stops writing on a broken pipe or reset and still reads it.Not changed
lcm_preserved_profile_journey_test::preserved_profile_lcm_discovery_converges_without_blocking_retrievalpassed 90 of 90 at the issue's load. In one overloaded run (17 of 30 suites failing), it failed 5 times on production bounds: the 2 mintool_dispatch_deadline_exceededontracedecay_lcm_statusandtracedecay_sessions_for, atimed_outmessage search, and oneworker_stoppedrefresh worker. None of these is a test race, so this PR does not change the test.project_capacity_reuse_test::projects_past_the_server_cache_open_and_servefailed in the gate atcode_index_journey.rs:186:5, which istracedecay init failed. The gate batch log kept only the first line, so the stderr is lost. It passed 100 of 100 dedicated loaded runs and 20 of 20 loaded fulldaemon_suiteruns here. This PR does not change it.Verification
cancel_candidate_journey(10, whose flaky: cancelled_large_candidate_search_stops_before_the_next_batch fails under load #4124 fix is not on this base) andscheduler_config::concurrent_reenable_creates_one_live_scheduler_owner(1).types_testsandcontrolled_invocation_tests: 300 of 300 pass. Master fails 58 of 300, all on the hook test.authentication_refusal_testunder load: 100 of 100.admit_with_cancellation. The test fails with "hook admission must return before daemon-owned provider or model work begins".request_cancellations.cancelcall insettle_in_process_invocation. Both fail with "work was not detached" after the 30 s grace.Cancelledmatch after the 10 s deadline. Skip the abort: the test hangs on the dropped-channel await until the Bazel timeout.bazel test //crates/tracedecay:unit_test //crates/tracedecay-daemon-service:unit_test //crates/tracedecay-sessions:unit_test;bazel build --config=clippyfor//crates/tracedecay:all,//crates/tracedecay-daemon-service:all,//crates/tracedecay-sessions:all;rustfmt_check_2024for all three crates.