Search trash-race test intermittently misses its completion marker #513

Open
opened 2026-09-30 11:33:47 +00:00 by kayg · 4 comments
Owner

During merge-round-0930 on 40ccef12818eb27592994a2666021ee34b2b3cf5, cargo test -p calternal-search exited101 in the existing test a_file_trashed_during_its_add_never_appears_in_search. It failed at crates/calternal-search/tests/indexer.rs:97: the marker file was not observed for query zebracorn. The indexer binary reported19pass/1fail in64.00s. The same compiled test, run alone with unchanged assertions, passed in11.37s.

The helper polls250times with20ms sleeps. A full follow-up suite is pending after Server gates. These observations establish an intermittent polling failure, not its cause. Investigate actor progress and test synchronization; do not relax or change existing expectations without owner review. The original and isolated logs will be attached to #410 and #473 with the final merge-round report. No search result containing the trashed file was observed.

During merge-round-0930 on `40ccef12818eb27592994a2666021ee34b2b3cf5`, `cargo test -p calternal-search` exited101 in the existing test `a_file_trashed_during_its_add_never_appears_in_search`. It failed at `crates/calternal-search/tests/indexer.rs:97`: the marker file was not observed for query `zebracorn`. The indexer binary reported19pass/1fail in64.00s. The same compiled test, run alone with unchanged assertions, passed in11.37s. The helper polls250times with20ms sleeps. A full follow-up suite is pending after Server gates. These observations establish an intermittent polling failure, not its cause. Investigate actor progress and test synchronization; do not relax or change existing expectations without owner review. The original and isolated logs will be attached to #410 and #473 with the final merge-round report. No search result containing the trashed file was observed.
Author
Owner

The full cargo test -p calternal-search follow-up passed (exit0) with RUST_TEST_THREADS=1 and unchanged assertions. It included the trash-race test, all integration binaries and doc tests. The initial suite failure, isolated pass and full follow-up output are preserved in the final merge-round reports on #410 and #473. The intermittent failure remains open for diagnosis.

The full `cargo test -p calternal-search` follow-up passed (exit0) with `RUST_TEST_THREADS=1` and unchanged assertions. It included the trash-race test, all integration binaries and doc tests. The initial suite failure, isolated pass and full follow-up output are preserved in the final merge-round reports on #410 and #473. The intermittent failure remains open for diagnosis.
Author
Owner

Starting #513 on branch job/flake-513, based at 1aaefe288f. I am tracing the test synchronization and indexer actor progress before changing the test or product code.

Starting #513 on branch job/flake-513, based at 1aaefe288f306498e7757848c50e9988b0e08044. I am tracing the test synchronization and indexer actor progress before changing the test or product code.
Author
Owner

Finding: the race was in test synchronization. The marker wait used wait_for_hit(), which polls for a fixed 5 seconds (250 × 20 ms). The indexer rate-limits applies to 1 second and runs PDF extraction on its single actor, so the marker timeout measured scheduler availability rather than actor completion. I replaced that poll with reconcile() queued after the marker notification; the actor must finish the held add before its reconciliation scan completes. The existing marker and no-ghost assertions remain.

Finding: the race was in test synchronization. The marker wait used wait_for_hit(), which polls for a fixed 5 seconds (250 × 20 ms). The indexer rate-limits applies to 1 second and runs PDF extraction on its single actor, so the marker timeout measured scheduler availability rather than actor completion. I replaced that poll with reconcile() queued after the marker notification; the actor must finish the held add before its reconciliation scan completes. The existing marker and no-ghost assertions remain.
Author
Owner

Finished #513 on job/flake-513.

Commit: 2b97a5f36463b470f27d236002bdd16c089df59a (test(search): wait on reconcile in trash race)

The failure was in test synchronization. The test inferred actor completion by polling Search for a marker for five seconds. Under parallel load, that poll can expire while the serialized indexer actor is still processing work; applies also have a one-second minimum interval. The test now queues Indexer::reconcile() after the marker notification and waits for that FIFO actor barrier. The full scan indexes the marker, and the existing marker and no-ghost expectations remain unchanged. Only crates/calternal-search/tests/indexer.rs changed.

The requested repetition passed under parallel indexer-test load:

PASS: a_file_trashed_during_its_add_never_appears_in_search passed 50/50 consecutive runs
test result: ok. 20 passed; 0 failed; 0 ignored; 0 measured; 1 filtered out; finished in 14.43s

Gates:

  • cargo fmt --check: exit 0; no output.
  • cargo clippy -p calternal-search --all-targets -- -D warnings:
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 2m 51s
  • cargo test -p calternal-search:
    Finished `test` profile [unoptimized + debuginfo] target(s) in 57.39s
test result: ok. 36 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 4.32s
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.79s
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.05s
test result: ok. 21 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 9.81s
test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.03s
test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.03s
test result: ok. 1 passed; 0 failed; 2 ignored; 0 measured; 0 filtered out; finished in 2.81s
test result: ok. 4 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

Known gaps: none identified. No product behavior changed. The test synchronization choice not covered by DESIGN is to use the existing reconciliation command as the actor completion barrier instead of lengthening a timeout.

Finished #513 on `job/flake-513`. Commit: `2b97a5f36463b470f27d236002bdd16c089df59a` (`test(search): wait on reconcile in trash race`) The failure was in test synchronization. The test inferred actor completion by polling Search for a marker for five seconds. Under parallel load, that poll can expire while the serialized indexer actor is still processing work; applies also have a one-second minimum interval. The test now queues `Indexer::reconcile()` after the marker notification and waits for that FIFO actor barrier. The full scan indexes the marker, and the existing marker and no-ghost expectations remain unchanged. Only `crates/calternal-search/tests/indexer.rs` changed. The requested repetition passed under parallel indexer-test load: ```text PASS: a_file_trashed_during_its_add_never_appears_in_search passed 50/50 consecutive runs test result: ok. 20 passed; 0 failed; 0 ignored; 0 measured; 1 filtered out; finished in 14.43s ``` Gates: - `cargo fmt --check`: exit 0; no output. - `cargo clippy -p calternal-search --all-targets -- -D warnings`: ```text Finished `dev` profile [unoptimized + debuginfo] target(s) in 2m 51s ``` - `cargo test -p calternal-search`: ```text Finished `test` profile [unoptimized + debuginfo] target(s) in 57.39s test result: ok. 36 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 4.32s test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.79s test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.05s test result: ok. 21 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 9.81s test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.03s test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.03s test result: ok. 1 passed; 0 failed; 2 ignored; 0 measured; 0 filtered out; finished in 2.81s test result: ok. 4 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s ``` Known gaps: none identified. No product behavior changed. The test synchronization choice not covered by DESIGN is to use the existing reconciliation command as the actor completion barrier instead of lengthening a timeout.
Sign in to join this conversation.
No labels
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
kayg/calternal#513
No description provided.