Search visibility read fails during the concurrent indexer integration suite #1293

Open
opened 2026-10-07 01:11:03 +00:00 by kayg · 4 comments
Owner

Observed during #1197 integration at 86ed8e4ad6, which contains round 31 (139d4378ef).

Command: cargo test --workspace -- --test-threads=4, with CARGO_BUILD_JOBS=4, CARGO_INCREMENTAL=0, CARGO_PROFILE_DEV_DEBUG=line-tables-only, CARGO_TARGET_DIR=/mnt/hdd/targets/collabloss4 and worktree-local TMPDIR.

The Search indexer integration binary returned:

---- rebuild_matches_incremental_results stdout ----

thread 'rebuild_matches_incremental_results' (743594) panicked at crates/calternal-search/tests/indexer.rs:93:10:
called `Result::unwrap()` on an `Err` value: Background("Item visibility settings unavailable")
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

failures:
    rebuild_matches_incremental_results

test result: FAILED. 28 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 635.21s

error: test failed, to rerun pass `-p calternal-search --test indexer`

One isolated diagnostic run of the same compiled binary, with unchanged source and assertions, passed:

running 1 test
test rebuild_matches_incremental_results ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 28 filtered out; finished in 5.36s

The failed message maps from user_settings::hidden_items through Indexer::search_grouped_with_visibility. The helper hides the underlying SQL error as UserSettingsError::Unavailable; no evidence identifies which SQL error occurred. The visibility pool has two read-only connections. The integration fixture uses a file-backed SQLite pool with one writer connection and the default journal mode. Concurrent indexing and shared-host load may contribute, but this is not established as a SLOW-only finding.

No Search behavior or test expectation was changed by #1197. Its scope is checkpoint integration, upgrade pins and reload/recovery verification. Investigate the visibility read under concurrent indexing and preserve fail-closed hidden-item filtering. Do not remove the query or weaken the equality/assertion. Complete gate logs will be attached to #1197. The workspace command retains exit 101; the focused pass does not replace that result.

Observed during #1197 integration at 86ed8e4ad69f31738b533af373675659becaa653, which contains round 31 (139d4378ef974c9ea3e253f59cf23c02db2bab73). Command: `cargo test --workspace -- --test-threads=4`, with `CARGO_BUILD_JOBS=4`, `CARGO_INCREMENTAL=0`, `CARGO_PROFILE_DEV_DEBUG=line-tables-only`, `CARGO_TARGET_DIR=/mnt/hdd/targets/collabloss4` and worktree-local `TMPDIR`. The Search indexer integration binary returned: ```text ---- rebuild_matches_incremental_results stdout ---- thread 'rebuild_matches_incremental_results' (743594) panicked at crates/calternal-search/tests/indexer.rs:93:10: called `Result::unwrap()` on an `Err` value: Background("Item visibility settings unavailable") note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace failures: rebuild_matches_incremental_results test result: FAILED. 28 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 635.21s error: test failed, to rerun pass `-p calternal-search --test indexer` ``` One isolated diagnostic run of the same compiled binary, with unchanged source and assertions, passed: ```text running 1 test test rebuild_matches_incremental_results ... ok test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 28 filtered out; finished in 5.36s ``` The failed message maps from `user_settings::hidden_items` through `Indexer::search_grouped_with_visibility`. The helper hides the underlying SQL error as `UserSettingsError::Unavailable`; no evidence identifies which SQL error occurred. The visibility pool has two read-only connections. The integration fixture uses a file-backed SQLite pool with one writer connection and the default journal mode. Concurrent indexing and shared-host load may contribute, but this is not established as a SLOW-only finding. No Search behavior or test expectation was changed by #1197. Its scope is checkpoint integration, upgrade pins and reload/recovery verification. Investigate the visibility read under concurrent indexing and preserve fail-closed hidden-item filtering. Do not remove the query or weaken the equality/assertion. Complete gate logs will be attached to #1197. The workspace command retains exit 101; the focused pass does not replace that result.
Author
Owner

Full verification stdout/stderr from #1197 is attached here: Complete verification logs (verification-1197.tar.gz)

The workspace failure stays exit 101. The one isolated diagnostic pass does not replace it. Remaining test targets, the full server suite, the recovery example and documentation tests passed. No Search behavior or assertion was changed.

Full verification stdout/stderr from #1197 is attached here: [Complete verification logs (verification-1197.tar.gz)](https://git.kayg.org/attachments/47115333-e6fd-4ff7-b929-7c37a2cd48af) The workspace failure stays exit 101. The one isolated diagnostic pass does not replace it. Remaining test targets, the full server suite, the recovery example and documentation tests passed. No Search behavior or assertion was changed.
Author
Owner

Starting investigation on branch job/vis-1293 from 3601719b80 (HEAD 3601719b80). I will trace visibility loading across projections and reproduce the concurrent read failure before changing behavior.

Starting investigation on branch job/vis-1293 from 3601719b80a39f712daf07b37879b22929dfffa0 (HEAD 3601719b80a39f712daf07b37879b22929dfffa0). I will trace visibility loading across projections and reproduce the concurrent read failure before changing behavior.
Author
Owner

Finding: Indexer::open_inner creates user_hidden_items and calls recover_hidden_items before Search starts; missing per-User rows read as []. Production Db::connect configures WAL and a 5-second SQLite busy timeout, while the reported indexer fixture creates a file-backed database in default rollback-journal mode without an explicit timeout. hidden_items mapped every SQL error to Unavailable without retry, so a transient SQLITE_BUSY under concurrent indexing can fail Search (and other callers of this shared loader); real users can still hit it if an Index lock lasts past their timeout. The new regression test confirms SQLITE_BUSY under an exclusive rollback-journal lock and passes when the lock clears during the bounded retry.

Finding: Indexer::open_inner creates user_hidden_items and calls recover_hidden_items before Search starts; missing per-User rows read as []. Production Db::connect configures WAL and a 5-second SQLite busy timeout, while the reported indexer fixture creates a file-backed database in default rollback-journal mode without an explicit timeout. hidden_items mapped every SQL error to Unavailable without retry, so a transient SQLITE_BUSY under concurrent indexing can fail Search (and other callers of this shared loader); real users can still hit it if an Index lock lasts past their timeout. The new regression test confirms SQLITE_BUSY under an exclusive rollback-journal lock and passes when the lock clears during the bounded retry.
Author
Owner

Completed #1293 on job/vis-1293.

Built: hidden_items now retries transient SQLite BUSY and LOCKED reads using the existing bounded database retry policy. Search and all projections that use this shared loader recover from short writer contention. Errors that persist still fail closed. Added a deterministic exclusive-lock regression test; it also checks the empty default for a new User.

Files: crates/calternal-plugin/src/user_settings.rs.

Head: ec8d73fd72f70e7c2109b1e8ff82ed0063508170 (ec8d73fd7, ahead of origin/dev by one commit).

Gates and verification output:

  • cargo fmt --check: no output; exit 0.
  • cargo clippy -p calternal-plugin --all-targets -- -D warnings:
    Finished dev profile [unoptimized + debuginfo] target(s) in 1m 17s
  • Focused regression test:
    test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 61 filtered out; finished in 0.38s
  • Regression stress: 30/30 regression runs passed under two CPU stress workers
  • cargo test -p calternal-plugin:
    test result: ok. 62 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 10.07s
    Doc tests: test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

Root cause evidence: Search startup creates the visibility table and restores User settings before Search starts; absent rows return an empty set. Production uses WAL and a 5-second busy timeout. The reported file-backed test fixture uses SQLite's rollback journal and no explicit timeout. A transient lock error was mapped directly to “Item visibility settings unavailable.”

Decision not specified in DESIGN: use the existing bounded SQLite lock retry for BUSY/LOCKED only. The normal read remains one bounded query (up to 4096 keys); contention adds at most two retry reads. Other persistent errors remain fail-closed.

Known gap: inline SQL predicates that filter hidden Items continue to rely on the shared Index reader's WAL and configured busy timeout; this change covers the shared settings loader used by Search, Notes, Files, Tasks, Calendar and Share projections. No UI or API contract changed.

Completed #1293 on `job/vis-1293`. Built: `hidden_items` now retries transient SQLite `BUSY` and `LOCKED` reads using the existing bounded database retry policy. Search and all projections that use this shared loader recover from short writer contention. Errors that persist still fail closed. Added a deterministic exclusive-lock regression test; it also checks the empty default for a new User. Files: `crates/calternal-plugin/src/user_settings.rs`. Head: `ec8d73fd72f70e7c2109b1e8ff82ed0063508170` (`ec8d73fd7`, ahead of `origin/dev` by one commit). Gates and verification output: - `cargo fmt --check`: no output; exit 0. - `cargo clippy -p calternal-plugin --all-targets -- -D warnings`: `Finished `dev` profile [unoptimized + debuginfo] target(s) in 1m 17s` - Focused regression test: `test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 61 filtered out; finished in 0.38s` - Regression stress: `30/30 regression runs passed under two CPU stress workers` - `cargo test -p calternal-plugin`: `test result: ok. 62 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 10.07s` Doc tests: `test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s` Root cause evidence: Search startup creates the visibility table and restores User settings before Search starts; absent rows return an empty set. Production uses WAL and a 5-second busy timeout. The reported file-backed test fixture uses SQLite's rollback journal and no explicit timeout. A transient lock error was mapped directly to “Item visibility settings unavailable.” Decision not specified in DESIGN: use the existing bounded SQLite lock retry for `BUSY`/`LOCKED` only. The normal read remains one bounded query (up to 4096 keys); contention adds at most two retry reads. Other persistent errors remain fail-closed. Known gap: inline SQL predicates that filter hidden Items continue to rely on the shared Index reader's WAL and configured busy timeout; this change covers the shared settings loader used by Search, Notes, Files, Tasks, Calendar and Share projections. No UI or API contract changed.
Commenting is not possible because the repository is archived.
No labels
No milestone
No project
No assignees
1 participant
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-v0#1293
No description provided.