Repository navigation
Description
Summary
tool_client_transport tests in //crates/tracedecay:runtime_acceptance_suite fail under CPU contention because their fixed time budgets are smaller than the time a tracedecay tool child needs to reach the scripted daemon when cores are oversubscribed. This happens before and after #4003, at about the same rate, so it is a pre-existing test timing problem rather than a regression.
Evidence
Each side ran --runs_per_test=10 --local_test_jobs=10 --nocache_test_results under taskset -c 0-3. Runs alternated before, after, after, before. Before is 603ec9f and after is 28b50ea (#4003). Host load average was 92 to 338 during the runs.
Failures over 40 processes per side, unmodified tests:
| Test | Before | After |
|---|---|---|
tool_client_transport::cancelling_generic_tool_reaps_child_and_closes_request |
38/40 | 32/40 |
tool_client_transport::generic_read_only_tool_times_out_without_late_success |
2/40 | 2/40 |
runtime_surface_acceptance::production_lsp_negotiates_and_projects_canonical_context |
1/40 | 0/40 |
| The other six tests from the #4003 gate list | 0/40 | 0/40 |
Every cancelling_generic_tool_reaps_child_and_closes_request failure is observe cancellable request: Timeout at tool_client_transport.rs:720.
Mechanism
The cancel test waits LOCAL_TIMEOUT (5 s) for the CLI child to spawn, connect, authenticate, and send its request. The scripted daemon's accept loop allows CHILD_TIMEOUT (8 s) for the same thing. A probe build of the test logged the time from spawn() to request receipt, with the 5 s wait raised to 60 s:
- The test alone (10 processes on 4 cores) takes 0.24 to 0.75 s on both sides.
- With the six gate-listed tests co-scheduled, 130 samples per side gave p50 5.8 s before and 6.0 s after, and p90 6.6 s before and 7.3 s after. Of those samples, 114 before and 117 after were over 5 s. Eight after-side samples in one early cluster of three rounds were over 8 s. The 100 later alternated samples per side had none over 8 s on either side.
- CPU time per test process (
/usr/bin/time, children included) was the same on both sides: 13.6 to 15.7 s user for the six-test set, and 8.9 to 9.7 s user for the three real-daemon tests.
The cost is plain CPU oversubscription. The real-daemon tests in the same process (every_cursor_..., dashboard_handoff_..., production_lsp_...) use about 12 s of CPU each, and 10 such processes share 4 cores. The 5 s budget is the tightest of the file's three fixed budgets. The 8 s accept deadline (tool_client_transport.rs:278, "timed out waiting for 1 client connections") and the generic_read_only_tool_times_out_without_late_success elapsed bound (:613/:618) fail at the same load.
Suggested fix
Bound the client's arrival with a readiness signal instead of a wall-clock budget. Wait for the child to connect, or for the child to exit, rather than for a fixed 5 s. At minimum, give the request wait the same budget as the accept loop. The cancel test's contract (killing the CLI closes the request socket) does not depend on how fast the CLI starts.
Also seen once in the #4003 gate and 2/170 after versus 0/170 before in these runs: application_production_reachability::every_cursor_carrying_code_operation_mints_and_spends_a_continuation returned code_references terminated Unavailable 40 ms after start, before the code graph was serving. That difference is not statistically significant. Treat it as the readiness race from #3041 unless it recurs.
Activity