Search recovery loses a committed hit and fails repair in merge-round-7a #956

Open
opened 2026-10-02 22:55:03 +00:00 by kayg · 3 comments
Owner

Found by merge-round-7a Round 4 (#427), head ba5134fa2, against a fresh real local server with the production SPA. One full tests/adversarial/run.sh is active on the shared build host. The 20,000-file Search recovery phase reported these exact failures:

FAIL search chaos: second User lost its committed Search hit during rebuild or overflow recovery
FAIL search chaos: watcher overflow recovery missed watchoverflowmarker-19999
FAIL search chaos: admin integrity repair: HTTP 503, b''
FAIL search chaos: startup integrity repair did not finish after SIGKILL

The phase also reported timed-out uploads and renames, then HTTP 429 because upload reservations remained active. A separate status read returned HTTP 200, healthy=true, checked_items=24, running=false, last_error=null. This does not prove that the recovery of the new files completed.

These findings include a lost committed result and a 503. They cannot be declared SLOW-only from the current evidence. They block a positive readiness verdict until a focused test explains or fixes them. Keep the existing assertions. Check Search continuity for the second User while rebuilding the first User, pending scan state, and startup recovery after the crash. Logs: artifacts/round4/adversarial.log in the merge-round-7a worktree. No push or deploy.

Found by merge-round-7a Round 4 (#427), head ba5134fa2, against a fresh real local server with the production SPA. One full tests/adversarial/run.sh is active on the shared build host. The 20,000-file Search recovery phase reported these exact failures: ``` FAIL search chaos: second User lost its committed Search hit during rebuild or overflow recovery FAIL search chaos: watcher overflow recovery missed watchoverflowmarker-19999 FAIL search chaos: admin integrity repair: HTTP 503, b'' FAIL search chaos: startup integrity repair did not finish after SIGKILL ``` The phase also reported timed-out uploads and renames, then HTTP 429 because upload reservations remained active. A separate status read returned HTTP 200, healthy=true, checked_items=24, running=false, last_error=null. This does not prove that the recovery of the new files completed. These findings include a lost committed result and a 503. They cannot be declared SLOW-only from the current evidence. They block a positive readiness verdict until a focused test explains or fixes them. Keep the existing assertions. Check Search continuity for the second User while rebuilding the first User, pending scan state, and startup recovery after the crash. Logs: artifacts/round4/adversarial.log in the merge-round-7a worktree. No push or deploy.
Author
Owner

Fix: 4a26749f3 on job/fix-7a-product (from job/merge-round-7a da5c28901). Not merged, not pushed.

No server log survived the round-4 run, so the root causes come from the code paths and the measured 16–20 s SQLite checkout waits. Three defects, each with a regression test that fails on the old code and passes on the fix (crates/calternal-search/tests/indexer.rs):

  1. Lost hit in a 200 response. Keyword Search awaited the optional per-User frecency boost on the SQLite read pool with no bound. Under contention the provider missed the 200 ms HTTP deadline (timed_out, empty results) or failed on pool timeout, which drops all keyword hits. Fix: frecency gets a 50 ms budget; on timeout or error the committed hits are ranked without it. Test search_returns_committed_hits_while_the_frecency_pool_is_busy (holds the only read connection; old code waits 30 s).
  2. Admin integrity repair: HTTP 503, b''. Overflow recovery drained the actor queue with while receiver.try_recv().is_ok() {}, which also dropped queued CheckAndRepair, Rebuild, RebuildUser and Reconcile requests. Their reply channels closed, so the admin check answered WorkerStopped → empty 503, and the post-rebuild private rebuild jobs failed. Fix: drop only path events; answer a queued check/reconcile with the overflow scan result and run a queued rebuild after it. Test overflow_recovery_answers_a_queued_integrity_check.
  3. Watcher overflow marker missing for 900 s. A staged shared rebuild wrote files only to the staged shared generation and staging manifest, never to ready private generations. After publication the manifest says those files are indexed, so later events and reconciles skip them; a private Index got them only from a later private rebuild (which item 2 could drop). Fix: the staged shared rebuild also writes and deletes in ready private generations (a private rebuild still writes only its own staged generation). Test staged_rebuild_writes_new_files_to_ready_private_generations.

"Startup integrity repair did not finish after SIGKILL" is not explained by a code defect I found. The likely cause is slowness: after restart the resumed rebuild job and the initial reconcile both scan about 24k files under the same contention. The full adversarial round must confirm this on a quiet host.

Gates: cargo fmt --check clean; cargo clippy -p calternal-db -p calternal-search -p calternal-auth -p calternal-plugin-files --all-targets -- -D warnings → Finished; cargo test -p calternal-search all ok (indexer: 24 passed; 0 failed). I did not run tests/adversarial/run.sh again.

Fix: 4a26749f3 on `job/fix-7a-product` (from `job/merge-round-7a` da5c28901). Not merged, not pushed. No server log survived the round-4 run, so the root causes come from the code paths and the measured 16–20 s SQLite checkout waits. Three defects, each with a regression test that fails on the old code and passes on the fix (`crates/calternal-search/tests/indexer.rs`): 1. **Lost hit in a 200 response.** Keyword Search awaited the optional per-User frecency boost on the SQLite read pool with no bound. Under contention the provider missed the 200 ms HTTP deadline (`timed_out`, empty results) or failed on pool timeout, which drops all keyword hits. Fix: frecency gets a 50 ms budget; on timeout or error the committed hits are ranked without it. Test `search_returns_committed_hits_while_the_frecency_pool_is_busy` (holds the only read connection; old code waits 30 s). 2. **Admin integrity repair: HTTP 503, b''.** Overflow recovery drained the actor queue with `while receiver.try_recv().is_ok() {}`, which also dropped queued `CheckAndRepair`, `Rebuild`, `RebuildUser` and `Reconcile` requests. Their reply channels closed, so the admin check answered `WorkerStopped` → empty 503, and the post-rebuild private rebuild jobs failed. Fix: drop only path events; answer a queued check/reconcile with the overflow scan result and run a queued rebuild after it. Test `overflow_recovery_answers_a_queued_integrity_check`. 3. **Watcher overflow marker missing for 900 s.** A staged shared rebuild wrote files only to the staged shared generation and staging manifest, never to ready private generations. After publication the manifest says those files are indexed, so later events and reconciles skip them; a private Index got them only from a later private rebuild (which item 2 could drop). Fix: the staged shared rebuild also writes and deletes in ready private generations (a private rebuild still writes only its own staged generation). Test `staged_rebuild_writes_new_files_to_ready_private_generations`. "Startup integrity repair did not finish after SIGKILL" is not explained by a code defect I found. The likely cause is slowness: after restart the resumed rebuild job and the initial reconcile both scan about 24k files under the same contention. The full adversarial round must confirm this on a quiet host. Gates: `cargo fmt --check` clean; `cargo clippy -p calternal-db -p calternal-search -p calternal-auth -p calternal-plugin-files --all-targets -- -D warnings` → `Finished`; `cargo test -p calternal-search` all ok (indexer: `24 passed; 0 failed`). I did not run tests/adversarial/run.sh again.
Author
Owner

Round 7a update at 516faaa698570bdb468626cf6cd75d9c81b33ac2: the full real-server tests/adversarial/run.sh reached search_chaos.py. It recorded these seven failures during the parallel upload/rename storm:

FAIL search chaos: upload rename-storm fixture storm-011.txt: HTTP -1, b'timed out'
FAIL search chaos: upload rename-storm fixture storm-013.txt: HTTP -1, b'timed out'
FAIL search chaos: upload rename-storm fixture storm-014.txt: HTTP -1, b'timed out'
FAIL search chaos: upload rename-storm fixture storm-015.txt: HTTP -1, b'timed out'
FAIL search chaos: rename storm item 27: HTTP -1, b'timed out'
FAIL search chaos: rename storm item 28: HTTP -1, b'timed out'
FAIL search chaos: rename storm item 29: HTTP -1, b'timed out'

These are client timeouts from the probe's 30-second HTTP timeout while it also runs 32 parallel requests. The run recorded no Search finding for the second User's committed hit, the watcher overflow marker, the admin repair 503, or startup repair after SIGKILL. test_search_result_matching passed all three tests. The full adversarial round and live authorization matrices are still running, so this is not a readiness verdict.

Round 7a update at `516faaa698570bdb468626cf6cd75d9c81b33ac2`: the full real-server `tests/adversarial/run.sh` reached `search_chaos.py`. It recorded these seven failures during the parallel upload/rename storm: ``` FAIL search chaos: upload rename-storm fixture storm-011.txt: HTTP -1, b'timed out' FAIL search chaos: upload rename-storm fixture storm-013.txt: HTTP -1, b'timed out' FAIL search chaos: upload rename-storm fixture storm-014.txt: HTTP -1, b'timed out' FAIL search chaos: upload rename-storm fixture storm-015.txt: HTTP -1, b'timed out' FAIL search chaos: rename storm item 27: HTTP -1, b'timed out' FAIL search chaos: rename storm item 28: HTTP -1, b'timed out' FAIL search chaos: rename storm item 29: HTTP -1, b'timed out' ``` These are client timeouts from the probe's 30-second HTTP timeout while it also runs 32 parallel requests. The run recorded no Search finding for the second User's committed hit, the watcher overflow marker, the admin repair 503, or startup repair after SIGKILL. `test_search_result_matching` passed all three tests. The full adversarial round and live authorization matrices are still running, so this is not a readiness verdict.
Author
Owner

Merge-round 7a follow-up on head 516faaa698. The live XUser matrix confirmed the cross-User Search count leak is absent: Users B/C received neither semantic nor non-semantic result/status counters for User A's private marker. The later main adversarial API probe had no failures in its 64-request Search query storm (p50 864.5 ms, p95 1995.3 ms), but its separate semantic recall fixture did not return Notes/20261003-apartment-hunting-caf0df0f.md within 120 seconds. The saved-search create storm returned only 22 of 40 distinct IDs; 18 create requests timed out. This happened during a broadly saturated API round (host load average was 45.55 / 44.52 / 41.60 after the probe). These are new Search availability/recall findings; the earlier lost committed hit and repair/overflow failures did not recur. No production code was changed in this verification job.

Merge-round 7a follow-up on head 516faaa698570bdb468626cf6cd75d9c81b33ac2. The live XUser matrix confirmed the cross-User Search count leak is absent: Users B/C received neither semantic nor non-semantic result/status counters for User A's private marker. The later main adversarial API probe had no failures in its 64-request Search query storm (p50 864.5 ms, p95 1995.3 ms), but its separate semantic recall fixture did not return `Notes/20261003-apartment-hunting-caf0df0f.md` within 120 seconds. The saved-search create storm returned only 22 of 40 distinct IDs; 18 create requests timed out. This happened during a broadly saturated API round (host load average was 45.55 / 44.52 / 41.60 after the probe). These are new Search availability/recall findings; the earlier lost committed hit and repair/overflow failures did not recur. No production code was changed in this verification job.
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#956
No description provided.