fix(tests): make cargo test --lib green — PATH leak and projector deadline flakes - #209
Closed
jmagar wants to merge 2 commits into
Closed
fix(tests): make cargo test --lib green — PATH leak and projector deadline flakes#209jmagar wants to merge 2 commits into
jmagar wants to merge 2 commits into
Conversation
`cargo test` intermittently failed 7-9 tests in inventory, setup::doctor, and agent_observatory that had nothing to do with whatever was being changed. The failing set varied run to run, and CI never saw any of it, so the failures read as "your branch broke something" to whoever hit them. Three separate causes, all process-global state that `cargo nextest` hides by giving each test its own process. PATH override leaked. `container_probe_reports_unreachable_when_docker_ps_fails` (#205) replaced PATH with a bare tempdir and never restored it, so every later bare-name spawn in the binary resolved against a deleted directory and failed ENOENT. This reproduces at --test-threads=1, so it is a leak, not a race, and `#[serial]` alone would not have fixed it. Now prepends and restores via the file's own EnvGuard, and is `#[serial]` so it cannot collide with the three docker-stubbing tests in setup_tests.rs. PATH replacement had no scoped alternative. `collect_warns_when_optional_device_ commands_are_missing` legitimately wiped PATH to assert `ip`/`ss`/`df` are not installed — which took every concurrent test's spawns down with it. Adding `env::mask_test_programs`, which makes named programs resolve to an absent path so they spawn with the same NotFound an uninstalled binary gives. The test now says what it means, and no test in the tree replaces PATH any more. Projector tests asserted per-cycle values. `oversized_first_rows=1` and `"attempts":2` are overwritten by the projector's next cycle, so each was true for roughly one 10ms window and false forever after — no timeout could fix that, and `notify_projection_work` broadcasts on a process-global channel that any test's `insert_logs_batch` rings, forcing extra cycles. They now assert monotone facts: attempts >= 2, durable cursors, and that health reports the counter rather than what it currently reads. Deadlines also moved to named constants documenting the shared write lock, since every test pool's `init_pool` migrates while holding it. Verified on this tree: `cargo test --no-fail-fast` 2471/2471 (baseline 79adf1f: 8 failures) and `cargo nextest run` 3061/3061. Refs: syslog-mcp-g4frk
…ck deadline `projector_failure_is_queryable_retries_without_advancing_and_stops_after_cancel` failed under `cargo test --lib` while passing in isolation. Captured tracing from a reproduction shows why: the projector's *first* cycle took ~23s (cursor read at 04:59:25.473, cycle completed at 04:59:43.169), so the test's 10s deadline expired before a second retry cycle could ever be recorded. A cycle has no wall-clock bound. It acquires the process-wide SQLite write serialization lock (`db::pool::write_lock`) several times — four source-cursor initialisations plus the health write — and under full-suite parallelism every test's pool queues on that one lock. Nothing about the projector is wrong; the tests were asserting a scheduling property they cannot guarantee. Publish `ProjectorProgress` from the projector on a `watch` channel after each cycle and have the tests await that signal instead. All fields are cumulative and monotonic, so a late observer cannot miss a transition — which matters because the projector only yields when every select branch is pending and can therefore run several cycles between two polls of a waiter. That also removes the old `"attempts":2` substring check, which silently matched 20-29 and 200-299 as well. The three projector tests now have no deadline on the success path, except in `projector_wakes_on_committed_log_ingest_before_fallback_poll`, where the bound *is* the assertion: it discriminates "woken by the commit notification" from "woken by the 60s fallback poll". That one is sized for the gap between those two outcomes (20s) rather than for how fast a cycle usually is. Production drops the receiver; `send_replace` never fails on a dropped receiver, so the signal costs one `watch` cell. Verified with the full `cargo test --lib` suite (676s wall, 2463 passed): the two projector failures reproduced on origin/main are gone.
Collaborator
Author
|
Superseded by the verified consolidation merged in #210. |
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
1 participant
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.
cargo test --libfailed 9 tests onmainwhile every one of them passed in isolation. Two independent causes; the suite is now green (2471 passed, 0 failed).1. A leaked process-global
PATH(7 tests)Not a race — a leak, and it reproduces single-threaded in 0.2s:
heartbeat_agent_tests.rssetPATHto a bare tempdir viacrate::env::set_test_varwith no guard, so it never restored it.crate::env::commandforces the override onto every child it builds, so from that point on every test in the process that spawnssh,git, or a fixture script failed withNotFound.inventory/device_tests.rshad the same shape — it replacedPATHoutright to assert "these commands are missing".Fixed by
mask_test_programsinsrc/env.rs: a test that wants a command to look absent says exactly that, instead of replacingPATHand taking every other test's subprocess down with it.This half is commit 22c18c3, cherry-picked verbatim from #208 — that PR is superseded by this one, which also carries the projector fix below.
2. Projector tests asserting a scheduling property they can't guarantee (2 tests)
projector_failure_is_queryable_retries_without_advancing_and_stops_after_cancelwaited 10s for two retry cycles. Captured tracing from a reproduction shows the first cycle alone took ~23s:A cycle has no wall-clock bound. It takes the process-wide SQLite write lock (
db::pool::write_lock) several times, and under suite parallelism every test's pool queues on that one lock. Nothing about the projector is wrong.spawn_projectornow publishesProjectorProgresson awatchchannel after each cycle, and the tests await that signal — no deadline on the success path. All fields are cumulative and monotonic on purpose: the projector only yields when everyselect!branch is pending, so it can run several cycles between two polls of a waiter, and an "equals N exactly" predicate would be missable. That also removes the old"attempts":2substring check, which silently matched 20-29 and 200-299 too.Production drops the receiver;
send_replacenever fails on a dropped receiver, so the signal costs onewatchcell.One deadline remains, in
projector_wakes_on_committed_log_ingest_before_fallback_poll, because there the bound is the assertion — it discriminates "woken by the commit notification" from "woken by the fallback poll". Sized for the gap between those two outcomes (20s against a 600s fallback), not for how fast a cycle usually is.Verification
main, full suite