PERF: search & indexing — stupid fast and reliable (targets, benchmark, fixes, chaos) #258

Open
opened 2026-09-27 18:16:12 +00:00 by kayg · 76 comments
Owner

Owner (2026-09-27): "indexing/searching should be stupid fast and reliable." Benchmark, find the bottlenecks, fix them. Not a merge-gate rule (periodic perf review stays non-blocking), but this issue delivers the targets below.

Targets (production build, the calternal-cloud-sized VM profile: 4 vCPU, 7.7 GiB RAM, SSD state + HDD user data; also measure on the build host)

  • Corpus: 100k items mixed (60k files incl. 20k photos with EXIF, 20k notes with headings/blocks/tags, 10k events, 10k tasks) + a 1M-item stress run for keyword search.
  • Keyword query (plain words, #tags, filters, folder scope): p50 ≤ 10 ms, p95 ≤ 30 ms, p99 ≤ 80 ms server-side at 100k; ≤ 60 ms p95 at 1M.
  • Search-as-you-type in the palette: first results painted ≤ 50 ms after keystroke (client + server), no jank (no long task > 50 ms on the main thread).
  • Semantic/hybrid query: p95 ≤ 150 ms at 100k (embedding model warm); cold start stated.
  • Freshness: a write through the API, a sync client or an outside change on disk is searchable within ≤ 1 s p95 (≤ 3 s p99), including under a 1,000-writes/min storm.
  • Full reindex of 100k items: state the time and peak RSS; must not block queries (queries keep answering from the old index until the swap).
  • Reliability: zero missed or duplicate documents after: kill -9 at random points during indexing, disk-full on the SSD, watcher overflow (inotify queue overflow → must trigger a targeted rescan, never silent loss), rename/move storms, Unicode NFC/NFD names, concurrent reindex + queries. An integrity checker compares index vs filesystem and repairs.
  • Memory: indexer RSS bounded (state the cap), idle CPU ~0.

Deliverables

  1. Extend bench/ (reuse #164's runner and compare) with a search/indexing profile and corpus generator; record results in docs/perf.
  2. Profile (flamegraphs / tokio-console / SQLite EXPLAIN) and fix bottlenecks: tantivy reader reload policy, commit batching, segment merge policy, schema/field choices, query parsing, SQLite indexes, embedding batching, watcher debounce, API serialisation, client-side palette rendering (virtualised list, debounced but instant first paint, request cancellation).
  3. Chaos/reliability suite in tests/adversarial (search section) for the reliability targets, plus the integrity checker (admin-visible status, runs after crashes and on a schedule at idle priority).
  4. Report with before/after numbers for every target; anything missing a target listed with the reason and the next step.
Owner (2026-09-27): "indexing/searching should be stupid fast and reliable." Benchmark, find the bottlenecks, fix them. Not a merge-gate rule (periodic perf review stays non-blocking), but this issue delivers the targets below. ## Targets (production build, the calternal-cloud-sized VM profile: 4 vCPU, 7.7 GiB RAM, SSD state + HDD user data; also measure on the build host) - Corpus: 100k items mixed (60k files incl. 20k photos with EXIF, 20k notes with headings/blocks/tags, 10k events, 10k tasks) + a 1M-item stress run for keyword search. - **Keyword query** (plain words, #tags, filters, folder scope): p50 ≤ 10 ms, p95 ≤ 30 ms, p99 ≤ 80 ms server-side at 100k; ≤ 60 ms p95 at 1M. - **Search-as-you-type** in the palette: first results painted ≤ 50 ms after keystroke (client + server), no jank (no long task > 50 ms on the main thread). - **Semantic/hybrid** query: p95 ≤ 150 ms at 100k (embedding model warm); cold start stated. - **Freshness:** a write through the API, a sync client or an outside change on disk is searchable within ≤ 1 s p95 (≤ 3 s p99), including under a 1,000-writes/min storm. - **Full reindex** of 100k items: state the time and peak RSS; must not block queries (queries keep answering from the old index until the swap). - **Reliability:** zero missed or duplicate documents after: kill -9 at random points during indexing, disk-full on the SSD, watcher overflow (inotify queue overflow → must trigger a targeted rescan, never silent loss), rename/move storms, Unicode NFC/NFD names, concurrent reindex + queries. An integrity checker compares index vs filesystem and repairs. - Memory: indexer RSS bounded (state the cap), idle CPU ~0. ## Deliverables 1. Extend `bench/` (reuse #164's runner and compare) with a search/indexing profile and corpus generator; record results in docs/perf. 2. Profile (flamegraphs / tokio-console / SQLite EXPLAIN) and fix bottlenecks: tantivy reader reload policy, commit batching, segment merge policy, schema/field choices, query parsing, SQLite indexes, embedding batching, watcher debounce, API serialisation, client-side palette rendering (virtualised list, debounced but instant first paint, request cancellation). 3. Chaos/reliability suite in tests/adversarial (search section) for the reliability targets, plus the integrity checker (admin-visible status, runs after crashes and on a schedule at idle priority). 4. Report with before/after numbers for every target; anything missing a target listed with the reason and the next step.
Author
Owner

Starting search/indexing performance work on job/search-perf.

  • Base (dev): ac048aa4b8828ada23e2e6145739a70e146af1df
  • Scope: search benchmark profile, search/index reliability checks, integrity repair, bottleneck fixes, and before/after measurements.
Starting search/indexing performance work on `job/search-perf`. - Base (`dev`): `ac048aa4b8828ada23e2e6145739a70e146af1df` - Scope: search benchmark profile, search/index reliability checks, integrity repair, bottleneck fixes, and before/after measurements.
Author
Owner

Baseline finding from code inspection:

  • Indexer::scan_tree flushes each 128-document batch through flush_upserts; each flush commits Tantivy and reloads the reader (crates/calternal-search/src/indexer.rs). A 100k-item scan therefore performs at least 782 write commits before deletes.
  • Indexer::rebuild_all clears the active Tantivy Index and SQLite manifest before scanning again, so a rebuild query sees an empty or partial Index.
  • Watcher overflow requests a full reconcile with try_send; when the event queue is already full, that reconcile can also be dropped. The periodic five-minute reconcile is the only fallback.
Baseline finding from code inspection: - `Indexer::scan_tree` flushes each 128-document batch through `flush_upserts`; each flush commits Tantivy and reloads the reader (`crates/calternal-search/src/indexer.rs`). A 100k-item scan therefore performs at least 782 write commits before deletes. - `Indexer::rebuild_all` clears the active Tantivy Index and SQLite manifest before scanning again, so a rebuild query sees an empty or partial Index. - Watcher overflow requests a full reconcile with `try_send`; when the event queue is already full, that reconcile can also be dropped. The periodic five-minute reconcile is the only fallback.
Author
Owner

Progress on job/search-perf: committed 3726dbe8 (perf(search): batch indexing and verify index integrity). The indexer now batches up to 1024 documents with a 32 MiB retained-text budget, reloads Tantivy readers explicitly after commits, builds full reindexes in a staged generation, checks stored result identities against the filesystem and SQLite manifest, and signals targeted/full rescans when the bounded watcher queue overflows. The calternal-search suite passed: 27 passed, 0 failed, 1 ignored in unit tests; all integration suites passed (16 indexer, 4 operators, 2 query properties, 1 relevance, 4 retrieval; 2 model-dependent tests ignored). The initial server compile hit a shared sccache temp path under another worktree; I retried with RUSTC_WRAPPER= to avoid that stale daemon environment.

Progress on `job/search-perf`: committed `3726dbe8` (`perf(search): batch indexing and verify index integrity`). The indexer now batches up to 1024 documents with a 32 MiB retained-text budget, reloads Tantivy readers explicitly after commits, builds full reindexes in a staged generation, checks stored result identities against the filesystem and SQLite manifest, and signals targeted/full rescans when the bounded watcher queue overflows. The `calternal-search` suite passed: 27 passed, 0 failed, 1 ignored in unit tests; all integration suites passed (16 indexer, 4 operators, 2 query properties, 1 relevance, 4 retrieval; 2 model-dependent tests ignored). The initial server compile hit a shared sccache temp path under another worktree; I retried with `RUSTC_WRAPPER=` to avoid that stale daemon environment.
Author
Owner

Progress on job/search-perf (base ac048aa4): commit 0706d10f adds admin-visible search integrity status, repair, and staged rebuild routes, then refreshes the checked-in OpenAPI and TypeScript client contracts. The focused server route test passed: test tests::openapi_contains_reference_plugin_and_search_paths ... ok and test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 45 filtered out. I am completing real-server profiles for mixed 100k indexing, 1M keyword stress, semantic cold/warm queries, freshness, concurrent rebuild queries, and production palette timing, then I will run the required final gates and chaos round.

Progress on `job/search-perf` (base `ac048aa4`): commit `0706d10f` adds admin-visible search integrity status, repair, and staged rebuild routes, then refreshes the checked-in OpenAPI and TypeScript client contracts. The focused server route test passed: `test tests::openapi_contains_reference_plugin_and_search_paths ... ok` and `test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 45 filtered out`. I am completing real-server profiles for mixed 100k indexing, 1M keyword stress, semantic cold/warm queries, freshness, concurrent rebuild queries, and production palette timing, then I will run the required final gates and chaos round.
Author
Owner

Finding and progress on job/search-perf (commit 89c869a9): the first real-server smoke run got HTTP 403 from POST /api/v1/admin/search/rebuild. The route correctly requires a fresh assertion; the benchmark had seeded an installation session without asserted_at. The fixture now seeds a fresh assertion, and the 100-item mixed smoke run passed the full rebuild while queries ran (1.59 s, 0 failed queries). That diagnostic run measured initial indexing at 4.99 s / 108.5 MiB peak RSS and semantic cold start at 15.06 s. It indexed 70/70 text paths; its warm hybrid p95 was 164.05 ms. These are debug-build, 100-item smoke figures, not the 100k target result. PYTHONDONTWRITEBYTECODE=1 python3 -m unittest bench.test_record passed (2 tests).

Finding and progress on `job/search-perf` (commit `89c869a9`): the first real-server smoke run got HTTP 403 from `POST /api/v1/admin/search/rebuild`. The route correctly requires a fresh assertion; the benchmark had seeded an installation session without `asserted_at`. The fixture now seeds a fresh assertion, and the 100-item mixed smoke run passed the full rebuild while queries ran (1.59 s, 0 failed queries). That diagnostic run measured initial indexing at 4.99 s / 108.5 MiB peak RSS and semantic cold start at 15.06 s. It indexed 70/70 text paths; its warm hybrid p95 was 164.05 ms. These are debug-build, 100-item smoke figures, not the 100k target result. `PYTHONDONTWRITEBYTECODE=1 python3 -m unittest bench.test_record` passed (2 tests).
Author
Owner

Finding: the search profile now measures outside filesystem writes during the API upload storm as a separate watcher-freshness distribution. Evidence: the measurement writes uniquely marked files under the real Home and polls the search API until each marker appears; bench.test_record covers the JSON and Markdown metrics. Targeted benchmark recorder tests pass (2 tests). The merge from dev is recorded at 5170aeaa; baseline release build is still compiling for the before/after run.

Finding: the search profile now measures outside filesystem writes during the API upload storm as a separate watcher-freshness distribution. Evidence: the measurement writes uniquely marked files under the real Home and polls the search API until each marker appears; bench.test_record covers the JSON and Markdown metrics. Targeted benchmark recorder tests pass (2 tests). The merge from dev is recorded at 5170aeaa; baseline release build is still compiling for the before/after run.
Author
Owner

Finding: the first production palette benchmark exited before browser startup. Evidence: its log reports Cannot find module .../search-perf/file:/tmp/bunx-1001-playwright@1.63.0/node_modules/playwright/index.mjs; playwrightEntry() already returns a file URL, and search.mjs converted it to a file URL a second time. The regression is reproduced. I am fixing this import boundary, then I will rerun the real palette profile.

Finding: the first production palette benchmark exited before browser startup. Evidence: its log reports `Cannot find module .../search-perf/file:/tmp/bunx-1001-playwright@1.63.0/node_modules/playwright/index.mjs`; `playwrightEntry()` already returns a file URL, and search.mjs converted it to a file URL a second time. The regression is reproduced. I am fixing this import boundary, then I will rerun the real palette profile.
Author
Owner

Fix: apps/web/e2e/search.mjs now imports the file URL returned by playwrightEntry() directly and converts PLAYWRIGHT_MODULE paths once. Commit: 48a8eb5d. Verification: the baseline production palette run completed all search flows; 60 server round trips measured p50 26.1 ms and p95 133.2 ms. Its JSON also records palette frame/DOM and main-thread long-task distributions.

Fix: `apps/web/e2e/search.mjs` now imports the file URL returned by `playwrightEntry()` directly and converts `PLAYWRIGHT_MODULE` paths once. Commit: 48a8eb5d. Verification: the baseline production palette run completed all search flows; 60 server round trips measured p50 26.1 ms and p95 133.2 ms. Its JSON also records palette frame/DOM and main-thread long-task distributions.
Author
Owner

Finding: the baseline 100k mixed profile reached its second server start after generating the corpus, then failed with server did not become ready. The process remained alive; Server.start() stopped polling after 2,400 × 50 ms (120 seconds). Its finally block removed the temporary workspace, so the failed run did not preserve startup logs. This is a benchmark readiness timeout that is too short for a large indexed Home, not an observed server crash. I am making the timeout configurable and recording wait progress/status before retrying the profile.

Finding: the baseline 100k mixed profile reached its second server start after generating the corpus, then failed with `server did not become ready`. The process remained alive; `Server.start()` stopped polling after 2,400 × 50 ms (120 seconds). Its `finally` block removed the temporary workspace, so the failed run did not preserve startup logs. This is a benchmark readiness timeout that is too short for a large indexed Home, not an observed server crash. I am making the timeout configurable and recording wait progress/status before retrying the profile.
Author
Owner

Fix: Server.start() now accepts a bounded readiness timeout, reports /readyz wait progress and the last response, and returns elapsed readiness time. The search runner exposes PERF_SEARCH_STARTUP_TIMEOUT (default 3600 s) and records startup separately within initial-index timing. The default gives large Homes time to reach readiness while remaining bounded. Commits: 06ce0363 and 52a388d5. Verification: the original upload fixture and sampler tests remain; all 3 tests in test_upload_scale.py pass, and both recorder tests pass.

Fix: `Server.start()` now accepts a bounded readiness timeout, reports `/readyz` wait progress and the last response, and returns elapsed readiness time. The search runner exposes `PERF_SEARCH_STARTUP_TIMEOUT` (default 3600 s) and records startup separately within initial-index timing. The default gives large Homes time to reach readiness while remaining bounded. Commits: 06ce0363 and 52a388d5. Verification: the original upload fixture and sampler tests remain; all 3 tests in `test_upload_scale.py` pass, and both recorder tests pass.
Author
Owner

Measured bottleneck: while the baseline binary indexes the 100k Home, /readyz remains connection-refused and the server log shows repeated small Tantivy commits. Evidence from one second of log output: commit opstamps advanced from 184626 to 184650, with each record preparing/committing and running segment garbage collection. The listener is delayed while this initial scan runs. This is the baseline behavior the new 1024-item/32 MiB update batching is intended to reduce; paired current measurements will quantify it.

Measured bottleneck: while the baseline binary indexes the 100k Home, `/readyz` remains connection-refused and the server log shows repeated small Tantivy commits. Evidence from one second of log output: commit opstamps advanced from 184626 to 184650, with each record preparing/committing and running segment garbage collection. The listener is delayed while this initial scan runs. This is the baseline behavior the new 1024-item/32 MiB update batching is intended to reduce; paired current measurements will quantify it.
Author
Owner

Measured database contention in the baseline 100k startup scan: SQLx logged slow connection acquisitions of 4.28 s, 3.63 s, and 11.17 s, each above the 2 s threshold. The same log has no error records. The after run will show whether the batched SQLite manifest writes reduce this contention.

Measured database contention in the baseline 100k startup scan: SQLx logged slow connection acquisitions of 4.28 s, 3.63 s, and 11.17 s, each above the 2 s threshold. The same log has no error records. The after run will show whether the batched SQLite manifest writes reduce this contention.
Author
Owner

Timeboxed baseline result: the 100k mixed profile did not reach /readyz within 31 minutes, so I stopped it before its 3600 s readiness limit to reserve time for complete optimized runs and final gates. Partial snapshot: 70,000 semantic documents, 90,101 manifest paths, 95,512 Tantivy documents across 11 segments, 2,131 Tantivy commit records, 7 SQLx slow-acquire warnings, 0 server errors, and 434 MiB server RSS. The machine result is marked complete: false; it is a lower bound for baseline readiness, not a completed benchmark.

Timeboxed baseline result: the 100k mixed profile did not reach `/readyz` within 31 minutes, so I stopped it before its 3600 s readiness limit to reserve time for complete optimized runs and final gates. Partial snapshot: 70,000 semantic documents, 90,101 manifest paths, 95,512 Tantivy documents across 11 segments, 2,131 Tantivy commit records, 7 SQLx slow-acquire warnings, 0 server errors, and 434 MiB server RSS. The machine result is marked `complete: false`; it is a lower bound for baseline readiness, not a completed benchmark.
Author
Owner

Post-merge mixed 100k profile is still in server startup indexing after 7m27s. At this checkpoint the SQLite manifest has 90,099 paths; semantic search has 36,320 distinct paths. The process has spent time in jbd2_log_wait_commit, and Tantivy emitted 340 Preparing commit entries so far. This is progress, not a completed timing. The earlier baseline was stopped after 31m with 90,101 manifest paths and 70,000 semantic paths, without /readyz. I will report a final comparison after the current profile completes or reaches its timebox. The shared host is running other builds and servers, so these startup timings include contention.

Post-merge mixed 100k profile is still in server startup indexing after 7m27s. At this checkpoint the SQLite manifest has 90,099 paths; semantic search has 36,320 distinct paths. The process has spent time in `jbd2_log_wait_commit`, and Tantivy emitted 340 `Preparing commit` entries so far. This is progress, not a completed timing. The earlier baseline was stopped after 31m with 90,101 manifest paths and 70,000 semantic paths, without `/readyz`. I will report a final comparison after the current profile completes or reaches its timebox. The shared host is running other builds and servers, so these startup timings include contention.
Author
Owner

Orchestrator add-on (route loading, same 'stupid fast' goal): at 200 ms RTT the first open of Files shows 'Opening Files…' for ~1 s, i.e. several sequential requests. Collapse each mode's first paint to ONE round trip (parallel fetches or a combined bootstrap endpoint, HTTP/2), preload on pointerdown (#243 added the hook), and measure first-content time per mode at 200 ms RTT in the bench.

Orchestrator add-on (route loading, same 'stupid fast' goal): at 200 ms RTT the first open of Files shows 'Opening Files…' for ~1 s, i.e. several sequential requests. Collapse each mode's first paint to ONE round trip (parallel fetches or a combined bootstrap endpoint, HTTP/2), preload on pointerdown (#243 added the hook), and measure first-content time per mode at 200 ms RTT in the bench.
Author
Owner

The merged mixed 100k profile was timeboxed after 20m because the app never opened its listener (/readyz stayed connection-refused). The sanitized checkpoint at 19m09s of server process time shows 90,100 manifest paths, all 70,000 expected semantic paths, 1,288 Tantivy commit records, last Tantivy opstamp 196,217, one SQLx slow-acquire warning, zero server error logs, 481,771,520 bytes RSS, and 801.83 seconds process CPU. The search manifest and semantic corpus counts were complete, but the profile did not reach queries, external-write freshness, or full rebuild. The Python harness returned 130 on the intentional interrupt; temp cleanup is still waiting on journal I/O. The single completed production UI run measured server round trips p50 36.9ms / p95 96.5ms, keystroke-to-frame server results p50 166.0ms / p95 542.8ms, and 20 long tasks (max 549ms). This host had other active builds and servers. The earlier baseline remained unready after 31m and had 90,101 manifest paths / 70,000 semantic paths; a direct complete server-startup comparison is not available.

The merged mixed 100k profile was timeboxed after 20m because the app never opened its listener (`/readyz` stayed connection-refused). The sanitized checkpoint at 19m09s of server process time shows 90,100 manifest paths, all 70,000 expected semantic paths, 1,288 Tantivy commit records, last Tantivy opstamp 196,217, one SQLx slow-acquire warning, zero server error logs, 481,771,520 bytes RSS, and 801.83 seconds process CPU. The search manifest and semantic corpus counts were complete, but the profile did not reach queries, external-write freshness, or full rebuild. The Python harness returned 130 on the intentional interrupt; temp cleanup is still waiting on journal I/O. The single completed production UI run measured server round trips p50 36.9ms / p95 96.5ms, keystroke-to-frame server results p50 166.0ms / p95 542.8ms, and 20 long tasks (max 549ms). This host had other active builds and servers. The earlier baseline remained unready after 31m and had 90,101 manifest paths / 70,000 semantic paths; a direct complete server-startup comparison is not available.
Author
Owner

The adversarial overflow probe currently reports a false negative for valid indexed results. A direct read-only query for watchoverflowmarker-00000 returned HTTP 200 and the expected first result (Files/SearchOverflow/overflow-00000.txt), but the snippet is highlighted as <b>watchoverflowmarker</b>-<b>00000</b>. wait_for_hit searches the raw JSON bytes for the unbroken marker, so it cannot match that result. I will fix the test matcher to normalize highlighted snippets and verify it against the actual response; this is a probe defect, not evidence that search dropped the file.

The adversarial overflow probe currently reports a false negative for valid indexed results. A direct read-only query for `watchoverflowmarker-00000` returned HTTP 200 and the expected first result (`Files/SearchOverflow/overflow-00000.txt`), but the snippet is highlighted as `<b>watchoverflowmarker</b>-<b>00000</b>`. `wait_for_hit` searches the raw JSON bytes for the unbroken marker, so it cannot match that result. I will fix the test matcher to normalize highlighted snippets and verify it against the actual response; this is a probe defect, not evidence that search dropped the file.
Author
Owner

Continuing #258 in job/search-perf. Current HEAD: 651f2206edbc70e13c8c77b9319c8ed0b90e51c1; current merge base with dev: 14de1c8ffdea892b685827e6fa911f74168af106. The worktree has four uncommitted search adversarial-suite changes from the prior work; I am reviewing and preserving them before the single final merge/gate pass.

Continuing #258 in `job/search-perf`. Current HEAD: `651f2206edbc70e13c8c77b9319c8ed0b90e51c1`; current merge base with `dev`: `14de1c8ffdea892b685827e6fa911f74168af106`. The worktree has four uncommitted search adversarial-suite changes from the prior work; I am reviewing and preserving them before the single final merge/gate pass.
Author
Owner

The 2026-09-28 performance report is committed in docs/perf/2026-09-28.md. The 100k server profiles stopped before readiness, so query, freshness and full reindex targets remain unmeasured. The production palette samples measured 166.0 ms p50 / 542.8 ms p95 to the next frame with server results and 20 long tasks (549 ms maximum), both above target. I am now running one time-boxed real-server search chaos round against the merged branch.

The 2026-09-28 performance report is committed in `docs/perf/2026-09-28.md`. The 100k server profiles stopped before readiness, so query, freshness and full reindex targets remain unmeasured. The production palette samples measured 166.0 ms p50 / 542.8 ms p95 to the next frame with server results and 20 long tasks (549 ms maximum), both above target. I am now running one time-boxed real-server search chaos round against the merged branch.
Author
Owner

The scoped real-server search chaos round passed on the merged branch: search chaos: passed (01a0e51e, 32 concurrent renames, concurrent queries and rebuild). It covered Unicode NFC/NFD, 20,000 watcher-overflow writes, rename/move storms, queries during staged rebuild, integrity repair and crash/restart. The split-highlight matcher regression passed (Ran 1 test in 0.001s, OK), and the Calendar Event tag probe passed. The run skipped the authz/editor rounds by scope. Search-index disk-full recovery remains untested; the existing ENOSPC probe is for client sync.

The scoped real-server search chaos round passed on the merged branch: `search chaos: passed (01a0e51e, 32 concurrent renames, concurrent queries and rebuild)`. It covered Unicode NFC/NFD, 20,000 watcher-overflow writes, rename/move storms, queries during staged rebuild, integrity repair and crash/restart. The split-highlight matcher regression passed (`Ran 1 test in 0.001s`, `OK`), and the Calendar Event tag probe passed. The run skipped the authz/editor rounds by scope. Search-index disk-full recovery remains untested; the existing ENOSPC probe is for client sync.
Author
Owner

#258 final report

Branch: job/search-perf (pushed). Head: 81944f0c4db1f4df97de8681cb66c5ce2ccbb985. dev was merged once at 7e388dab.

Built

  • Batched Index updates at up to 1,024 Items / 32 MiB retained text, staged full Index generations, integrity status and repair/rebuild routes, and watcher overflow rescans.
  • Added bench/run.sh --search for the production palette, mixed 100k indexing, 1M keyword stress, freshness and concurrent reindex measurements.
  • Added search chaos coverage and corrected the probe to match Tantivy results when highlight tags split a marker. Added step-up assertion refreshes before protected search admin operations.
  • Recorded the available before/after numbers and every target status in docs/perf/2026-09-28.md.

Target status and next step

  • 100k mixed corpus indexing/readiness — NOT MEASURED. Baseline did not become ready after 31 min (90,101 manifest paths; 434 MiB RSS). The post-merge run did not become ready in its 20 min time box (90,100 paths; 459.4 MiB RSS; all 70,000 semantic paths indexed). Next: complete the production profile on the 4-vCPU, 7.7-GiB target VM and record ready time and peak RSS.
  • 100k keyword p50/p95/p99 — NOT MEASURED. Neither server reached query readiness. Next: complete word, tag, filter and folder-scope samples at 100k.
  • 1M keyword p95 — NOT MEASURED. No stress result is recorded. Next: run the 1M keyword profile.
  • Palette first result ≤ 50 ms — NOT MET. Current production sample measured keystroke to the next frame with server results at p50 166.0 ms / p95 542.8 ms. The earlier run measured server round trips at p50 26.1 ms / p95 133.2 ms. The host load differed. Next: profile and reduce keystroke-to-frame time, then repeat on a quiet host.
  • No main-thread task > 50 ms — NOT MET. Current palette sample recorded 20 long tasks, maximum 549 ms. Next: profile and remove long tasks, then repeat the production run.
  • 100k warm hybrid p95 ≤ 150 ms and cold start — NOT MEASURED at target scale. A 100-Item debug diagnostic measured 15.06 s cold start and 164.05 ms warm p95. Next: run cold and warm semantic cases on the 100k production profile.
  • Freshness ≤ 1 s p95 / 3 s p99, including 1,000 writes/min — NOT MEASURED. The 100k run stopped before sampling. No active client sync protocol endpoint exists. Next: measure API and outside disk writes in the completed profile; measure sync when its endpoint exists.
  • 100k full reindex time/RSS and old-Index query continuity — NOT MEASURED at target scale. A 100-Item debug smoke rebuild took 1.59 s with zero failed concurrent queries. Next: record elapsed time, peak RSS and failed query count at 100k.
  • Reliability across kill, disk full, overflow, rename/move, NFC/NFD and concurrent rebuild/query — NOT MEASURED as a complete target. The scoped real-server search chaos run passed Unicode NFC/NFD, 20,000 watcher-overflow writes, 32 concurrent renames, move storm, staged rebuild queries, integrity repair and crash/restart. The matcher regression passed. A separate sync-client ENOSPC test exists; a search-index disk-full case is missing. Next: add and run that case, then compare the Index with the filesystem.
  • Indexer RSS bound and idle CPU near zero — NOT MEASURED. Pending Index work is bounded to 1,024 Items / 32 MiB retained text; the incomplete after checkpoint used 459.4 MiB server RSS. Idle CPU was not measured. Next: record peak Indexer/server RSS and idle CPU after a complete run.

No search profile ran on the target VM. The detailed measurements and limitations are in docs/perf/2026-09-28.md. The scoped adversarial run skipped the authz and editor rounds.

Gates

  • cargo fmt --check: exit 0; no output.
  • cargo clippy --all-targets -- -D warnings: final run passed. Exact output: Finished \dev` profile [unoptimized + debuginfo] target(s) in 51.12s. The first run found error: redundant closureanderror: call to std::mem::drop with a value that does not implement Drop; both were fixed in 81944f0c`, then clippy passed.
  • cargo test: exit 0. Search unit result: test result: ok. 27 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 2.64s. Indexer integration result: test result: ok. 16 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 13.53s.
  • bun run check: svelte-check found 0 errors and 0 warnings.
  • bun run test: Test Files 89 passed (89); Tests 620 passed (620); Duration 51.54s (transform 62%, import 15%, environment 13%, tests 8%, setup 2%).
  • Real-server search chaos: search chaos: passed (01a0e51e, 32 concurrent renames, concurrent queries and rebuild). Matcher test: Ran 1 test in 0.001s / OK. Calendar Event tag probe: Calendar Event tag probe: Unicode/bidi, 65536-byte category, 7 malformed inputs, and 24 parallel reads passed.

cargo clean removed 20.7 GiB, and apps/web/build was removed. No new product design decisions were needed.

#258 final report Branch: `job/search-perf` (pushed). Head: `81944f0c4db1f4df97de8681cb66c5ce2ccbb985`. `dev` was merged once at `7e388dab`. ## Built - Batched Index updates at up to 1,024 Items / 32 MiB retained text, staged full Index generations, integrity status and repair/rebuild routes, and watcher overflow rescans. - Added `bench/run.sh --search` for the production palette, mixed 100k indexing, 1M keyword stress, freshness and concurrent reindex measurements. - Added search chaos coverage and corrected the probe to match Tantivy results when highlight tags split a marker. Added step-up assertion refreshes before protected search admin operations. - Recorded the available before/after numbers and every target status in `docs/perf/2026-09-28.md`. ## Target status and next step - **100k mixed corpus indexing/readiness — NOT MEASURED.** Baseline did not become ready after 31 min (90,101 manifest paths; 434 MiB RSS). The post-merge run did not become ready in its 20 min time box (90,100 paths; 459.4 MiB RSS; all 70,000 semantic paths indexed). Next: complete the production profile on the 4-vCPU, 7.7-GiB target VM and record ready time and peak RSS. - **100k keyword p50/p95/p99 — NOT MEASURED.** Neither server reached query readiness. Next: complete word, tag, filter and folder-scope samples at 100k. - **1M keyword p95 — NOT MEASURED.** No stress result is recorded. Next: run the 1M keyword profile. - **Palette first result ≤ 50 ms — NOT MET.** Current production sample measured keystroke to the next frame with server results at p50 166.0 ms / p95 542.8 ms. The earlier run measured server round trips at p50 26.1 ms / p95 133.2 ms. The host load differed. Next: profile and reduce keystroke-to-frame time, then repeat on a quiet host. - **No main-thread task > 50 ms — NOT MET.** Current palette sample recorded 20 long tasks, maximum 549 ms. Next: profile and remove long tasks, then repeat the production run. - **100k warm hybrid p95 ≤ 150 ms and cold start — NOT MEASURED at target scale.** A 100-Item debug diagnostic measured 15.06 s cold start and 164.05 ms warm p95. Next: run cold and warm semantic cases on the 100k production profile. - **Freshness ≤ 1 s p95 / 3 s p99, including 1,000 writes/min — NOT MEASURED.** The 100k run stopped before sampling. No active client sync protocol endpoint exists. Next: measure API and outside disk writes in the completed profile; measure sync when its endpoint exists. - **100k full reindex time/RSS and old-Index query continuity — NOT MEASURED at target scale.** A 100-Item debug smoke rebuild took 1.59 s with zero failed concurrent queries. Next: record elapsed time, peak RSS and failed query count at 100k. - **Reliability across kill, disk full, overflow, rename/move, NFC/NFD and concurrent rebuild/query — NOT MEASURED as a complete target.** The scoped real-server search chaos run passed Unicode NFC/NFD, 20,000 watcher-overflow writes, 32 concurrent renames, move storm, staged rebuild queries, integrity repair and crash/restart. The matcher regression passed. A separate sync-client ENOSPC test exists; a search-index disk-full case is missing. Next: add and run that case, then compare the Index with the filesystem. - **Indexer RSS bound and idle CPU near zero — NOT MEASURED.** Pending Index work is bounded to 1,024 Items / 32 MiB retained text; the incomplete after checkpoint used 459.4 MiB server RSS. Idle CPU was not measured. Next: record peak Indexer/server RSS and idle CPU after a complete run. No search profile ran on the target VM. The detailed measurements and limitations are in `docs/perf/2026-09-28.md`. The scoped adversarial run skipped the authz and editor rounds. ## Gates - `cargo fmt --check`: exit 0; no output. - `cargo clippy --all-targets -- -D warnings`: final run passed. Exact output: `Finished \`dev\` profile [unoptimized + debuginfo] target(s) in 51.12s`. The first run found `error: redundant closure` and `error: call to std::mem::drop with a value that does not implement Drop`; both were fixed in `81944f0c`, then clippy passed. - `cargo test`: exit 0. Search unit result: `test result: ok. 27 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 2.64s`. Indexer integration result: `test result: ok. 16 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 13.53s`. - `bun run check`: `svelte-check found 0 errors and 0 warnings`. - `bun run test`: `Test Files 89 passed (89)`; `Tests 620 passed (620)`; `Duration 51.54s (transform 62%, import 15%, environment 13%, tests 8%, setup 2%)`. - Real-server search chaos: `search chaos: passed (01a0e51e, 32 concurrent renames, concurrent queries and rebuild)`. Matcher test: `Ran 1 test in 0.001s` / `OK`. Calendar Event tag probe: `Calendar Event tag probe: Unicode/bidi, 65536-byte category, 7 malformed inputs, and 24 parallel reads passed`. `cargo clean` removed 20.7 GiB, and `apps/web/build` was removed. No new product design decisions were needed.
Author
Owner

Orchestrator review of phase 1: the most important finding is the one that stopped the measurements. With the 100k corpus the server did not open its listener after 31 minutes: startup indexing blocks readiness. On calternal.cloud that means a restart after the photo import = downtime for the whole initial index. Phase 2 priorities: (1) the HTTP listener opens immediately on start; indexing/reconciliation runs in the background at low priority; queries serve from the existing on-disk index and report an 'indexing N%' status (API + a quiet UI hint); readiness (/healthz) is true once the listener and DB are up, with a separate /readyz-style index status; restart with an existing 100k index must be ready in < 5 s; (2) complete the 100k and 1M measurements for every target; (3) palette keystroke-to-frame p95 ≤ 50 ms with no long task > 50 ms (virtualised list, incremental rendering, move highlighting/snippets off the main thread, cancel stale requests); (4) a disk-full probe for the search index.

Orchestrator review of phase 1: the most important finding is the one that stopped the measurements. With the 100k corpus the server did not open its listener after 31 minutes: startup indexing blocks readiness. On calternal.cloud that means a restart after the photo import = downtime for the whole initial index. Phase 2 priorities: (1) the HTTP listener opens immediately on start; indexing/reconciliation runs in the background at low priority; queries serve from the existing on-disk index and report an 'indexing N%' status (API + a quiet UI hint); readiness (/healthz) is true once the listener and DB are up, with a separate /readyz-style index status; restart with an existing 100k index must be ready in < 5 s; (2) complete the 100k and 1M measurements for every target; (3) palette keystroke-to-frame p95 ≤ 50 ms with no long task > 50 ms (virtualised list, incremental rendering, move highlighting/snippets off the main thread, cancel stale requests); (4) a disk-full probe for the search index.
Author
Owner

Starting Phase 2 on job/search-perf. Branch base dev: 088e17d4fe; current head: 81944f0c4d. I will read the latest Phase 2 direction and continue without merging dev because the phase-specific merge freeze is active.

Starting Phase 2 on job/search-perf. Branch base dev: 088e17d4fe49d6a7b41f03fcc13f5f4959346be9; current head: 81944f0c4db1f4df97de8681cb66c5ce2ccbb985. I will read the latest Phase 2 direction and continue without merging dev because the phase-specific merge freeze is active.
Author
Owner

Finding: the server creates the listener only after wire::build_live_app returns, while build_live_app waits for sync_homes, Files reconciliation, Notes recovery/reconciliation, and tag recovery/reconciliation. The search actor runs on a separate thread, but these awaited startup reconciliations keep /healthz and every other route unavailable while it indexes. I will gate that work until after the socket bind and expose search indexing progress with responses.

Finding: the server creates the listener only after `wire::build_live_app` returns, while `build_live_app` waits for `sync_homes`, Files reconciliation, Notes recovery/reconciliation, and tag recovery/reconciliation. The search actor runs on a separate thread, but these awaited startup reconciliations keep `/healthz` and every other route unavailable while it indexes. I will gate that work until after the socket bind and expose search indexing progress with responses.
Author
Owner

Finding: the previous client search debounce was 80 ms, so the server result could not meet the 50 ms paint target even before request and render time. The last recorded palette p95 was 542.8 ms. I changed the debounce to 8 ms, isolated the measurement window, added p95/long-task checks, and added production palette measurements to both the 100k and 1M corpus runs.

Finding: the previous client search debounce was 80 ms, so the server result could not meet the 50 ms paint target even before request and render time. The last recorded palette p95 was 542.8 ms. I changed the debounce to 8 ms, isolated the measurement window, added p95/long-task checks, and added production palette measurements to both the 100k and 1M corpus runs.
Author
Owner

Finding from the real private-tmpfs ENOSPC probe: the live Index and API stayed available, but integrity repair against the same Tantivy writer remained unhealthy after two repair passes (missing_items 1 then 3). A staged rebuild then indexed both files and returned a healthy report. I am making recovery from a failed live writer use a staged generation while keeping its current reader available.

Finding from the real private-tmpfs ENOSPC probe: the live Index and API stayed available, but integrity repair against the same Tantivy writer remained unhealthy after two repair passes (missing_items 1 then 3). A staged rebuild then indexed both files and returned a healthy report. I am making recovery from a failed live writer use a staged generation while keeping its current reader available.
Author
Owner

Recovery fix: the Index actor now marks its writer generation for recovery when a live Tantivy mutation, reader reload, or manifest commit fails. The next integrity pass publishes a staged generation while existing queries keep using the prior reader until publication. Focused search tests pass (28 unit tests plus 16 indexer integration tests), and the real 4 MiB tmpfs ENOSPC probe now passes: old results stayed searchable during ENOSPC, then the new file was indexed and final integrity was healthy after space returned.

Recovery fix: the Index actor now marks its writer generation for recovery when a live Tantivy mutation, reader reload, or manifest commit fails. The next integrity pass publishes a staged generation while existing queries keep using the prior reader until publication. Focused search tests pass (28 unit tests plus 16 indexer integration tests), and the real 4 MiB tmpfs ENOSPC probe now passes: old results stayed searchable during ENOSPC, then the new file was indexed and final integrity was healthy after space returned.
Author
Owner

100k production palette finding: first non-empty result frame p95 was 519.2 ms (50 samples). The long-task observer recorded 20 tasks over 50 ms, maximum 322 ms. At the run, the shared host load average was 27.18 / 23.27 / 20.14 with concurrent test and server jobs. The palette target is not met in this host measurement; I am completing the index and query profiles and will separate load-affected timings in the report.

100k production palette finding: first non-empty result frame p95 was 519.2 ms (50 samples). The long-task observer recorded 20 tasks over 50 ms, maximum 322 ms. At the run, the shared host load average was 27.18 / 23.27 / 20.14 with concurrent test and server jobs. The palette target is not met in this host measurement; I am completing the index and query profiles and will separate load-affected timings in the report.
Author
Owner

100k query sampling finding: server.log records 161 slow calendar_events_fts statements, with logged elapsed times from 1.027 s to 10.009 s and one Event row returned. The Search API fans out to Calendar Event search, so this path is included in the measured query latency. The profile host was busy (load average varied from 13.98 to 27.18) with other server/test jobs active. I will include this with the completed query percentiles and keep any Calendar-plugin change out of this Search-owned worktree.

100k query sampling finding: `server.log` records 161 slow `calendar_events_fts` statements, with logged elapsed times from 1.027 s to 10.009 s and one Event row returned. The Search API fans out to Calendar Event search, so this path is included in the measured query latency. The profile host was busy (load average varied from 13.98 to 27.18) with other server/test jobs active. I will include this with the completed query percentiles and keep any Calendar-plugin change out of this Search-owned worktree.
Author
Owner

The first 100k run reached the rebuild step after about 30 minutes and got HTTP 403. The seeded owner had the admin role and scope, but its seeded passkey assertion was older than the server's 300-second freshness window. I have updated the benchmark fixture to renew that assertion immediately before the admin request; the endpoint's authorization check stays unchanged. The runner now saves completed measurements on later-stage errors. I am rerunning the mixed profile.

The first 100k run reached the rebuild step after about 30 minutes and got HTTP 403. The seeded owner had the admin role and scope, but its seeded passkey assertion was older than the server's 300-second freshness window. I have updated the benchmark fixture to renew that assertion immediately before the admin request; the endpoint's authorization check stays unchanged. The runner now saves completed measurements on later-stage errors. I am rerunning the mixed profile.
Author
Owner

100k production mixed profile completed (100 samples per keyword case; shared build host load varied from about 10 to 24):

  • Listener ready: 1.11 s. A completed existing Index reopened in 2.496 s (<5 s), and its first query returned HTTP 200 with 20 Search results while Index status still reported indexing.
  • Initial Index: 64.52 s; integrity healthy across 90,099 checked Items; peak RSS 462,700,544 bytes.
  • Keyword API p50 / p95 / p99: plain 526.03 / 894.62 / 1,552.53 ms; tag 450.26 / 713.11 / 775.44 ms; type filter 366.63 / 600.83 / 647.18 ms; folder scope 407.97 / 639.44 / 739.73 ms. These miss the 100k targets. Server logs also recorded slow calendar_events_fts queries during the profile.
  • Palette first-result frame: p95 425.8 ms (48 samples); 24 long tasks over 50 ms, maximum 339 ms. Browser errors: 0.
  • Hybrid search: semantic coverage 70,000/70,000; model cold start 4.53 s; warm p95 2,666.51 ms (25 samples), above 150 ms.
  • Freshness storm: 1,000 scheduled writes, 765 successful, 255 HTTP 429 (too_many_active_uploads), measured 84.65 successful writes/min. API freshness p95/p99 850.27/1,169.49 ms (76 samples); outside-file freshness p95/p99 3,980.43/4,279.76 ms (56 samples).
  • Full reindex: 69.71 s; peak RSS 1,120,384,? bytes; 0 concurrent query failures. I will correct the rounded RSS value in the final table from the machine JSON.

Production Indexing progress at 45 percent

100k production mixed profile completed (100 samples per keyword case; shared build host load varied from about 10 to 24): - Listener ready: 1.11 s. A completed existing Index reopened in 2.496 s (<5 s), and its first query returned HTTP 200 with 20 Search results while Index status still reported indexing. - Initial Index: 64.52 s; integrity healthy across 90,099 checked Items; peak RSS 462,700,544 bytes. - Keyword API p50 / p95 / p99: plain 526.03 / 894.62 / 1,552.53 ms; tag 450.26 / 713.11 / 775.44 ms; type filter 366.63 / 600.83 / 647.18 ms; folder scope 407.97 / 639.44 / 739.73 ms. These miss the 100k targets. Server logs also recorded slow `calendar_events_fts` queries during the profile. - Palette first-result frame: p95 425.8 ms (48 samples); 24 long tasks over 50 ms, maximum 339 ms. Browser errors: 0. - Hybrid search: semantic coverage 70,000/70,000; model cold start 4.53 s; warm p95 2,666.51 ms (25 samples), above 150 ms. - Freshness storm: 1,000 scheduled writes, 765 successful, 255 HTTP 429 (`too_many_active_uploads`), measured 84.65 successful writes/min. API freshness p95/p99 850.27/1,169.49 ms (76 samples); outside-file freshness p95/p99 3,980.43/4,279.76 ms (56 samples). - Full reindex: 69.71 s; peak RSS 1,120,384,? bytes; 0 concurrent query failures. I will correct the rounded RSS value in the final table from the machine JSON. ![Production Indexing progress at 45 percent](https://git.kayg.org/attachments/7ba3196a-4d98-473f-831d-4f36431b9b82)
Author
Owner

Correction to my previous 100k summary: the full-reindex peak RSS is exactly 1,120,382,976 bytes (from resources.peak_rss_bytes in the machine JSON). The previous comment contained an unfinished placeholder on that value.

Correction to my previous 100k summary: the full-reindex peak RSS is exactly 1,120,382,976 bytes (from `resources.peak_rss_bytes` in the machine JSON). The previous comment contained an unfinished placeholder on that value.
Author
Owner

The first 1M stress profile stopped after an integrity-status GET timed out at its fixed 10-second request limit. The server remained alive, and the read-only SQLite manifest had reached 1,001,006 entries; the partial result recorded first listener readiness at 6.01 seconds. I updated the test-only scale runner to retry transient status-request timeouts until the indexing deadline and committed that change as 904d7aa6. A single rerun is in progress; its status route is currently responding with running: true.

The first 1M stress profile stopped after an integrity-status GET timed out at its fixed 10-second request limit. The server remained alive, and the read-only SQLite manifest had reached 1,001,006 entries; the partial result recorded first listener readiness at 6.01 seconds. I updated the test-only scale runner to retry transient status-request timeouts until the indexing deadline and committed that change as `904d7aa6`. A single rerun is in progress; its status route is currently responding with `running: true`.
Author
Owner

During the single 1M stress rerun, after the Search manifest reached 1,001,006 entries, the admin integrity-status GET returned HTTP 503 with service_unavailable: Authentication database is busy; retry shortly. The server log also recorded SQLite pool timeouts in the job worker, plus authentication DB and initial reconciliation errors. The server process remained alive (about 1.7 GiB RSS at the last sample). These observations are under the 1M startup-index load; I am checking whether the profile recovers and whether query stages can run before classifying the impact.

During the single 1M stress rerun, after the Search manifest reached 1,001,006 entries, the admin integrity-status GET returned HTTP 503 with `service_unavailable: Authentication database is busy; retry shortly`. The server log also recorded SQLite pool timeouts in the job worker, plus authentication DB and initial reconciliation errors. The server process remained alive (about 1.7 GiB RSS at the last sample). These observations are under the 1M startup-index load; I am checking whether the profile recovers and whether query stages can run before classifying the impact.
Author
Owner

Phase 2 report

Branch: job/search-perf
Base SHA: 088e17d4fe49d6a7b41f03fcc13f5f4959346be9
Head SHA: 8e0ebf5327575dc92436d04409b9e2949bc46603

The branch is pushed. The remote branch head matches this SHA. I did not merge dev; the active merge freeze says to wait for #156.

Built

  • Search startup now opens the listener before the first reconciliation. The persisted Index stays available to queries while background indexing runs. Search responses include indexing progress. Failed live Index writes trigger recovery.
  • The production palette probe now measures the first non-empty result frame and reports server-frame latency separately. It also records long tasks and browser errors.
  • The scale runner retains partial results, retries slow integrity-status reads, and marks interrupted runs. It does not treat an incomplete integrity report as a healthy Index.
  • The 100k mixed profile and the incomplete 1M stress profile are documented in docs/perf/2026-09-28.md. The real disk-full probe passed.

Full target table

Target Phase 2 result Status Next step
Listener opens during a 100k Index; existing 100k Index restarts in <5 s and answers the first query with progress status Listener ready in 1.11 s while indexing. Progress API and production UI showed indexing. After completion, restart ready in 2.496 s; first query returned 20 Search hits with indexing: true. Met Compare on production VM.
Build and index 100k mixed Items Integrity checked 90,099 Items and reported healthy. Indexing took 64.52 s; peak RSS 462,700,544 bytes (441.3 MiB). Corpus: 40k files, 20k Photos, 20k Notes, 10k Events, 10k Tasks. Measured Compare on production VM.
Keyword query at 100k: p50 ≤10 ms, p95 ≤30 ms, p99 ≤80 ms 100 samples/case. Plain 526.03 / 894.62 / 1,552.53 ms; tag 450.26 / 713.11 / 775.44 ms; type filter 366.63 / 600.83 / 647.18 ms; folder scope 407.97 / 639.44 / 739.73 ms (p50/p95/p99). Not met Profile Search and Calendar Event query paths on production VM.
Keyword query at 1M: p95 ≤60 ms Not measured. On the second 1M run, listener ready in 4.42 s and the Search manifest reached 1,001,006 entries for 1,001,003 filesystem paths. The authenticated integrity route then returned HTTP 503 and timed out while the authentication SQLite pool was busy. The run stopped before integrity, palette, or keyword samples. Not measured Investigate SQLite pool contention during 1M startup before repeating.
First Search result frame ≤50 ms after key press First non-empty result frame p50 92 ms, p95 425.8 ms (48 samples). Server result-frame p95 513.6 ms. Host load was about 20. Not met Profile palette and main-thread work on production VM.
No main-thread long task >50 ms while typing 24 long tasks over 50 ms; maximum 339 ms. Browser errors: 0. Not met Profile palette on production VM.
Warm hybrid query at 100k: p95 ≤150 ms; report cold start Semantic coverage 70,000/70,000 paths. Model cold start 4.53 s; first query 1,155.53 ms; warm p50/p95/p99 820.66 / 2,666.51 / 3,920.00 ms (25 samples). Not met Profile hybrid query and Calendar Event fan-out on production VM.
Freshness ≤1 s p95 / 3 s p99, including 1,000 writes/min Runner scheduled 1,000 API uploads; 765 succeeded and 255 returned HTTP 429 (too_many_active_uploads), for 84.65 successful writes/min. API freshness p95/p99 850.27 / 1,169.49 ms (76 samples). Outside-file freshness p95/p99 3,980.43 / 4,279.76 ms (56 samples). No HTTP 5xx or crash in this 100k profile. Not met Investigate upload back-pressure and outside-file indexing. Measure sync after its endpoint exists.
Full 100k reindex; queries keep serving old Index Reindex took 69.71 s; peak RSS 1,120,382,976 bytes. Concurrent query failures: 0; query p50/p95/p99 602.00 / 1,493.17 / 2,465.31 ms (45 samples). Measured Compare on production VM.
Reliability: kill, disk full, watcher overflow, rename/move, Unicode, concurrent rebuild/query Search chaos round passed NFC/NFD names, 20,000 watcher-overflow writes, 32 concurrent renames, moves, staged rebuild queries, integrity repair, and crash/restart. Real ENOSPC probe output: filled Search Index tmpfs with 4,091,904 bytes; PASS existing Index remains queryable after real ENOSPC; PASS Search Index recovers and verifies files after disk space returns. Measured Keep one time-boxed adversarial round per merge.
Bounded Indexer memory; idle CPU near zero Caps: 64,000,000-byte writer heap, 32 MiB pending text, 1,024 pending Items. 100k initial-index peak RSS 441.3 MiB; full-reindex peak RSS 1.04 GiB. Separate route run measured 0.2% idle CPU for one core; it did not isolate the Search Indexer. Measured Measure idle Indexer CPU on production VM.

The first 1M attempt stopped on a fixed 10-second integrity-status request timeout. The second was stopped after about 20 minutes of repeated HTTP 503 responses and request timeouts. Server logs recorded SQLite pool timeouts and failed Files and tag reconciliation attempts. The server process stayed alive. Both 1M runs and the follow-up are recorded on this issue. The 1M query target remains unmeasured; the manifest count alone is not a healthy integrity result.

Gates

cargo fmt --check exited 0 with empty output.

Final cargo clippy --all-targets -- -D warnings output:

    Finished `dev` profile [unoptimized + debuginfo] target(s) in 33.73s

cargo test exited 0. Output included:

    Finished `test` profile [unoptimized + debuginfo] target(s) in 5m 52s

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

bun run check output:

svelte-check found 0 errors and 0 warnings

bun run test output:

 Test Files  89 passed (89)
      Tests  620 passed (620)
   Duration  38.35s (transform 62%, import 14%, environment 13%, tests 8%, setup 3%)

cargo clean output: Removed 29411 files, 20.4GiB total. apps/web/build was removed.

Files changed

  • Search and server: crates/calternal-api/src/lib.rs, crates/calternal-fs/src/lib.rs, crates/calternal-fs/src/root.rs, crates/calternal-search/Cargo.toml, crates/calternal-search/src/index.rs, crates/calternal-search/src/indexer.rs, crates/calternal-search/src/lib.rs, crates/calternal-search/tests/indexer.rs, crates/calternal-search/tests/retrieval.rs, crates/calternal-server/src/main.rs, crates/calternal-server/src/wire.rs, crates/plugins/ai/src/routes.rs, Cargo.toml, Cargo.lock.
  • Web palette: apps/web/e2e/search-scale-palette.mjs, apps/web/e2e/search.mjs, apps/web/src/lib/components/search-dialog.svelte, apps/web/src/lib/search/registry.ts, apps/web/src/lib/search/server.ts, apps/web/src/lib/search/window.svelte.ts.
  • Perf and adversarial work: bench/record.py, bench/run.sh, bench/test_record.py, tests/adversarial/authz_matrix.py, tests/adversarial/run.sh, tests/adversarial/search_chaos.py, tests/adversarial/search_disk_full.py, tests/adversarial/test_search_result_matching.py, tests/perf/search_photo_fixture.mjs, tests/perf/search_scale.py, tests/perf/test_upload_scale.py, tests/perf/upload_scale.py.
  • Generated contracts and reports: contracts/openapi.json, packages/api-client/src/generated.ts, docs/perf/README.md, docs/perf/2026-09-28.md.

Decisions for owner review

  • The palette latency metric uses the first non-empty provider result frame; the server result frame remains a separate measurement.
  • A complete manifest count without a healthy integrity snapshot is not enough to report the 1M index as complete. The 1M query and palette rows stay Not measured.
  • The first 1M corpus used one million small Files and blocked semantic-model downloads so that the keyword stress profile would not trigger an unrelated embedding pass.

Progress screenshot from the production palette is attached: Search indexing progress

## Phase 2 report Branch: `job/search-perf` Base SHA: `088e17d4fe49d6a7b41f03fcc13f5f4959346be9` Head SHA: `8e0ebf5327575dc92436d04409b9e2949bc46603` The branch is pushed. The remote branch head matches this SHA. I did not merge `dev`; the active merge freeze says to wait for #156. ### Built - Search startup now opens the listener before the first reconciliation. The persisted Index stays available to queries while background indexing runs. Search responses include indexing progress. Failed live Index writes trigger recovery. - The production palette probe now measures the first non-empty result frame and reports server-frame latency separately. It also records long tasks and browser errors. - The scale runner retains partial results, retries slow integrity-status reads, and marks interrupted runs. It does not treat an incomplete integrity report as a healthy Index. - The 100k mixed profile and the incomplete 1M stress profile are documented in `docs/perf/2026-09-28.md`. The real disk-full probe passed. ### Full target table | Target | Phase 2 result | Status | Next step | |---|---|---|---| | Listener opens during a 100k Index; existing 100k Index restarts in <5 s and answers the first query with progress status | Listener ready in 1.11 s while indexing. Progress API and production UI showed indexing. After completion, restart ready in 2.496 s; first query returned 20 Search hits with `indexing: true`. | **Met** | Compare on production VM. | | Build and index 100k mixed Items | Integrity checked 90,099 Items and reported healthy. Indexing took 64.52 s; peak RSS 462,700,544 bytes (441.3 MiB). Corpus: 40k files, 20k Photos, 20k Notes, 10k Events, 10k Tasks. | **Measured** | Compare on production VM. | | Keyword query at 100k: p50 ≤10 ms, p95 ≤30 ms, p99 ≤80 ms | 100 samples/case. Plain 526.03 / 894.62 / 1,552.53 ms; tag 450.26 / 713.11 / 775.44 ms; type filter 366.63 / 600.83 / 647.18 ms; folder scope 407.97 / 639.44 / 739.73 ms (p50/p95/p99). | **Not met** | Profile Search and Calendar Event query paths on production VM. | | Keyword query at 1M: p95 ≤60 ms | Not measured. On the second 1M run, listener ready in 4.42 s and the Search manifest reached 1,001,006 entries for 1,001,003 filesystem paths. The authenticated integrity route then returned HTTP 503 and timed out while the authentication SQLite pool was busy. The run stopped before integrity, palette, or keyword samples. | **Not measured** | Investigate SQLite pool contention during 1M startup before repeating. | | First Search result frame ≤50 ms after key press | First non-empty result frame p50 92 ms, p95 425.8 ms (48 samples). Server result-frame p95 513.6 ms. Host load was about 20. | **Not met** | Profile palette and main-thread work on production VM. | | No main-thread long task >50 ms while typing | 24 long tasks over 50 ms; maximum 339 ms. Browser errors: 0. | **Not met** | Profile palette on production VM. | | Warm hybrid query at 100k: p95 ≤150 ms; report cold start | Semantic coverage 70,000/70,000 paths. Model cold start 4.53 s; first query 1,155.53 ms; warm p50/p95/p99 820.66 / 2,666.51 / 3,920.00 ms (25 samples). | **Not met** | Profile hybrid query and Calendar Event fan-out on production VM. | | Freshness ≤1 s p95 / 3 s p99, including 1,000 writes/min | Runner scheduled 1,000 API uploads; 765 succeeded and 255 returned HTTP 429 (`too_many_active_uploads`), for 84.65 successful writes/min. API freshness p95/p99 850.27 / 1,169.49 ms (76 samples). Outside-file freshness p95/p99 3,980.43 / 4,279.76 ms (56 samples). No HTTP 5xx or crash in this 100k profile. | **Not met** | Investigate upload back-pressure and outside-file indexing. Measure sync after its endpoint exists. | | Full 100k reindex; queries keep serving old Index | Reindex took 69.71 s; peak RSS 1,120,382,976 bytes. Concurrent query failures: 0; query p50/p95/p99 602.00 / 1,493.17 / 2,465.31 ms (45 samples). | **Measured** | Compare on production VM. | | Reliability: kill, disk full, watcher overflow, rename/move, Unicode, concurrent rebuild/query | Search chaos round passed NFC/NFD names, 20,000 watcher-overflow writes, 32 concurrent renames, moves, staged rebuild queries, integrity repair, and crash/restart. Real ENOSPC probe output: `filled Search Index tmpfs with 4,091,904 bytes`; `PASS existing Index remains queryable after real ENOSPC`; `PASS Search Index recovers and verifies files after disk space returns`. | **Measured** | Keep one time-boxed adversarial round per merge. | | Bounded Indexer memory; idle CPU near zero | Caps: 64,000,000-byte writer heap, 32 MiB pending text, 1,024 pending Items. 100k initial-index peak RSS 441.3 MiB; full-reindex peak RSS 1.04 GiB. Separate route run measured 0.2% idle CPU for one core; it did not isolate the Search Indexer. | **Measured** | Measure idle Indexer CPU on production VM. | The first 1M attempt stopped on a fixed 10-second integrity-status request timeout. The second was stopped after about 20 minutes of repeated HTTP 503 responses and request timeouts. Server logs recorded SQLite pool timeouts and failed Files and tag reconciliation attempts. The server process stayed alive. Both 1M runs and the follow-up are recorded on this issue. The 1M query target remains unmeasured; the manifest count alone is not a healthy integrity result. ### Gates `cargo fmt --check` exited 0 with empty output. Final `cargo clippy --all-targets -- -D warnings` output: ```text Finished `dev` profile [unoptimized + debuginfo] target(s) in 33.73s ``` `cargo test` exited 0. Output included: ```text Finished `test` profile [unoptimized + debuginfo] target(s) in 5m 52s test result: ok. 28 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 2.14s ``` `bun run check` output: ```text svelte-check found 0 errors and 0 warnings ``` `bun run test` output: ```text Test Files 89 passed (89) Tests 620 passed (620) Duration 38.35s (transform 62%, import 14%, environment 13%, tests 8%, setup 3%) ``` `cargo clean` output: `Removed 29411 files, 20.4GiB total`. `apps/web/build` was removed. ### Files changed - Search and server: `crates/calternal-api/src/lib.rs`, `crates/calternal-fs/src/lib.rs`, `crates/calternal-fs/src/root.rs`, `crates/calternal-search/Cargo.toml`, `crates/calternal-search/src/index.rs`, `crates/calternal-search/src/indexer.rs`, `crates/calternal-search/src/lib.rs`, `crates/calternal-search/tests/indexer.rs`, `crates/calternal-search/tests/retrieval.rs`, `crates/calternal-server/src/main.rs`, `crates/calternal-server/src/wire.rs`, `crates/plugins/ai/src/routes.rs`, `Cargo.toml`, `Cargo.lock`. - Web palette: `apps/web/e2e/search-scale-palette.mjs`, `apps/web/e2e/search.mjs`, `apps/web/src/lib/components/search-dialog.svelte`, `apps/web/src/lib/search/registry.ts`, `apps/web/src/lib/search/server.ts`, `apps/web/src/lib/search/window.svelte.ts`. - Perf and adversarial work: `bench/record.py`, `bench/run.sh`, `bench/test_record.py`, `tests/adversarial/authz_matrix.py`, `tests/adversarial/run.sh`, `tests/adversarial/search_chaos.py`, `tests/adversarial/search_disk_full.py`, `tests/adversarial/test_search_result_matching.py`, `tests/perf/search_photo_fixture.mjs`, `tests/perf/search_scale.py`, `tests/perf/test_upload_scale.py`, `tests/perf/upload_scale.py`. - Generated contracts and reports: `contracts/openapi.json`, `packages/api-client/src/generated.ts`, `docs/perf/README.md`, `docs/perf/2026-09-28.md`. ### Decisions for owner review - The palette latency metric uses the first non-empty provider result frame; the server result frame remains a separate measurement. - A complete manifest count without a healthy integrity snapshot is not enough to report the 1M index as complete. The 1M query and palette rows stay **Not measured**. - The first 1M corpus used one million small Files and blocked semantic-model downloads so that the keyword stress profile would not trigger an unrelated embedding pass. Progress screenshot from the production palette is attached: ![Search indexing progress](https://git.kayg.org/attachments/7ba3196a-4d98-473f-831d-4f36431b9b82)
Author
Owner

Orchestrator review of phase 2: startup fixed (listener 1.11 s with a 100k index still building), reliability good (disk-full, overflow, renames, rebuild with 0 failed queries). NOT met and now the priority: keyword query latency at 100k is ~50× off target (plain p50 526 / p95 895 / p99 1,553 ms vs 10/30/80; tag and filter cases similar), which also drives the palette's 426 ms p95 first frame and 339 ms long tasks. Phase 3: profile one plain query end to end (tracing spans + flamegraph): tantivy search vs hit hydration (SQLite N+1 per hit?), snippet/highlight generation, semantic fusion running on every keystroke, reader reload per query, JSON size. Fix to reach the targets; keep the palette's first frame ≤ 50 ms (keyword-only first, semantic merged in later).

Orchestrator review of phase 2: startup fixed (listener 1.11 s with a 100k index still building), reliability good (disk-full, overflow, renames, rebuild with 0 failed queries). NOT met and now the priority: keyword query latency at 100k is ~50× off target (plain p50 526 / p95 895 / p99 1,553 ms vs 10/30/80; tag and filter cases similar), which also drives the palette's 426 ms p95 first frame and 339 ms long tasks. Phase 3: profile one plain query end to end (tracing spans + flamegraph): tantivy search vs hit hydration (SQLite N+1 per hit?), snippet/highlight generation, semantic fusion running on every keystroke, reader reload per query, JSON size. Fix to reach the targets; keep the palette's first frame ≤ 50 ms (keyword-only first, semantic merged in later).
Author
Owner

Started search-perf STEP A on branch job/search-perf at 8e0ebf53. Reading the latest issue direction, then merging origin/dev once.

Started search-perf STEP A on branch job/search-perf at 8e0ebf53. Reading the latest issue direction, then merging origin/dev once.
Author
Owner

STEP A start: job/search-perf at 8e0ebf5327; merge base with origin/dev is 088e17d4fe. origin/dev is b8adafb9.

STEP A start: job/search-perf at 8e0ebf5327575dc92436d04409b9e2949bc46603; merge base with origin/dev is 088e17d4fe49d6a7b41f03fcc13f5f4959346be9. origin/dev is b8adafb9.
Author
Owner

STEP A done 106cd6c487

Merged origin/dev (b8adafb9) once on job/search-perf and pushed the branch. The wire.rs conflict keeps the Search integrity routes and puts them behind the shared Role and RecentAssertion guards. The authz matrix retains invalid/stale-session and malformed-body probes with its strict status checks. The adversarial runner retains Search chaos and the Round 2 selector. bash packages/api-client/check-generated.sh passed after building apps/web because the server embeds that build.

Step A gates:

  • cargo fmt --all -- --check: exit 0, no output.
  • cargo clippy --all-targets -- -D warnings: Finished \dev` profile [unoptimized + debuginfo] target(s) in 49.83s`.
  • cargo test: exit 0. Search unit result: test result: ok. 28 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 1.06s. Search indexer result: test result: ok. 16 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 5.51s.
  • bun run check: svelte-check found 0 errors and 0 warnings.
  • bun run test: Test Files 104 passed (104); Tests 691 passed (691); Duration 36.35s (transform 54%, environment 17%, import 16%, tests 10%, setup 3%).
STEP A done 106cd6c48789c0dc7f846144893fc7df1bfb96fa Merged origin/dev (`b8adafb9`) once on `job/search-perf` and pushed the branch. The `wire.rs` conflict keeps the Search integrity routes and puts them behind the shared Role and RecentAssertion guards. The authz matrix retains invalid/stale-session and malformed-body probes with its strict status checks. The adversarial runner retains Search chaos and the Round 2 selector. `bash packages/api-client/check-generated.sh` passed after building `apps/web` because the server embeds that build. Step A gates: - `cargo fmt --all -- --check`: exit 0, no output. - `cargo clippy --all-targets -- -D warnings`: `Finished \`dev\` profile [unoptimized + debuginfo] target(s) in 49.83s`. - `cargo test`: exit 0. Search unit result: `test result: ok. 28 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 1.06s`. Search indexer result: `test result: ok. 16 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 5.51s`. - `bun run check`: `svelte-check found 0 errors and 0 warnings`. - `bun run test`: `Test Files 104 passed (104)`; `Tests 691 passed (691)`; `Duration 36.35s (transform 54%, environment 17%, import 16%, tests 10%, setup 3%)`.
Author
Owner

100k Step B baseline finding (release server, 100 samples/case): plain keyword/hybrid p50/p95/p99 was 376.17/525.28/589.57 ms; tag 328.58/477.38/731.75 ms; type filter 273.86/401.25/487.87 ms; folder scope 289.66/452.38/542.96 ms. The one-request trace measured Tantivy query plus snippets at 6,008 µs, frecency lookup at 107,083 µs for 160 candidates, Search provider total at 175,387 µs, and route total at 200,832 µs with its 200 ms deadline reached. Code inspection shows the frecency read uses the single writer pool. I am moving this read to the dedicated read pool. The API currently waits for semantic retrieval; I am adding an opt-in keyword-only response and letting the palette paint it before a debounced hybrid update. The production palette probe measured first-result frame p95 378.8 ms and seven main-thread long tasks, max 850 ms. This was a busy shared host and the profile overlapped semantic indexing, freshness writes and reindex work; treat timings as a baseline measurement, not a controlled comparison.

100k Step B baseline finding (release server, 100 samples/case): plain keyword/hybrid p50/p95/p99 was 376.17/525.28/589.57 ms; tag 328.58/477.38/731.75 ms; type filter 273.86/401.25/487.87 ms; folder scope 289.66/452.38/542.96 ms. The one-request trace measured Tantivy query plus snippets at 6,008 µs, frecency lookup at 107,083 µs for 160 candidates, Search provider total at 175,387 µs, and route total at 200,832 µs with its 200 ms deadline reached. Code inspection shows the frecency read uses the single writer pool. I am moving this read to the dedicated read pool. The API currently waits for semantic retrieval; I am adding an opt-in keyword-only response and letting the palette paint it before a debounced hybrid update. The production palette probe measured first-result frame p95 378.8 ms and seven main-thread long tasks, max 850 ms. This was a busy shared host and the profile overlapped semantic indexing, freshness writes and reindex work; treat timings as a baseline measurement, not a controlled comparison.
Author
Owner

Step A merged in 10ebdfc5: non-blocking startup (listener in ~1 s with a 100k index building), indexing progress, integrity checker, disk-full + chaos probes. Orchestrator verified: web 701/701, generated client OK, clippy clean, full workspace 1,352/1,352. Step B (query latency) continues on the branch.

Step A merged in 10ebdfc5: non-blocking startup (listener in ~1 s with a 100k index building), indexing progress, integrity checker, disk-full + chaos probes. Orchestrator verified: web 701/701, generated client OK, clippy clean, full workspace 1,352/1,352. Step B (query latency) continues on the branch.
Author
Owner

Follow-up finding: the separate Search read pool reduced frecency lookup from the baseline 107 ms to mostly 0.5–7 ms in the current traces. The 6-character keyword query then completed the Tantivy and snippet stages in about 14 ms, but Files and Notes providers each took about 150 ms and the route still reached its 200 ms deadline. The palette's first-stage semantic=false request currently fans out to every Plugin. I am making that explicit fast mode return only Search Plugin Index keyword hits; the regular hybrid request remains unchanged and replaces those results after its short typing debounce.

Follow-up finding: the separate Search read pool reduced frecency lookup from the baseline 107 ms to mostly 0.5–7 ms in the current traces. The 6-character keyword query then completed the Tantivy and snippet stages in about 14 ms, but Files and Notes providers each took about 150 ms and the route still reached its 200 ms deadline. The palette's first-stage `semantic=false` request currently fans out to every Plugin. I am making that explicit fast mode return only Search Plugin Index keyword hits; the regular hybrid request remains unchanged and replaces those results after its short typing debounce.
Author
Owner

Step B finding: the 100k Search-only profile returned keyword p50 5.57–7.95 ms, but p95 was 35.61–36.52 ms across the four cases (target ≤30 ms). The 10-query production palette probe measured first-frame p50/p95 66.3/215.2 ms and 9 main-thread long tasks, maximum 224 ms. Chromium Long Animation Frame entries attributed up to 78.9 ms to a requestAnimationFrame callback with 50.8 ms forced style/layout; the palette remeasurement path also inserted two hidden probes per measurement and rewrote unchanged viewport CSS variables. I’m addressing those repeated layout reads/writes and will report the follow-up measurement.

Step B finding: the 100k Search-only profile returned keyword p50 5.57–7.95 ms, but p95 was 35.61–36.52 ms across the four cases (target ≤30 ms). The 10-query production palette probe measured first-frame p50/p95 66.3/215.2 ms and 9 main-thread long tasks, maximum 224 ms. Chromium Long Animation Frame entries attributed up to 78.9 ms to a requestAnimationFrame callback with 50.8 ms forced style/layout; the palette remeasurement path also inserted two hidden probes per measurement and rewrote unchanged viewport CSS variables. I’m addressing those repeated layout reads/writes and will report the follow-up measurement.
Author
Owner

Step B profile finding: the 100k profile after the palette observer change completed its 100-sample query cases, then stopped in full reindex with 1 search queries failed during full reindex. A concurrent cargo build -p calternal-server was still running on the shared host; the benchmark server used 244% CPU during this stage. The runner deleted its temporary server log and kept only the failure count, so this run cannot distinguish a timeout from an HTTP error. I committed a harness change to retain up to 10 bounded failure details on future runs. The search and palette stages from this run are recorded as load-contaminated; I did not repeat the profile.

Step B profile finding: the 100k profile after the palette observer change completed its 100-sample query cases, then stopped in full reindex with `1 search queries failed during full reindex`. A concurrent `cargo build -p calternal-server` was still running on the shared host; the benchmark server used 244% CPU during this stage. The runner deleted its temporary server log and kept only the failure count, so this run cannot distinguish a timeout from an HTTP error. I committed a harness change to retain up to 10 bounded failure details on future runs. The search and palette stages from this run are recorded as load-contaminated; I did not repeat the profile.
Author
Owner

STEP B done — HEAD 2f1f9ace888084a5b83b6d1220a1b0fa88d17ab7 on job/search-perf. The branch is pushed. Step A and its one origin/dev merge were completed earlier.

Built

  • Added an optional semantic search query parameter. false returns Search Plugin keyword hits only; true or an omitted value keeps hybrid fan-out as the default.
  • The palette now paints keyword hits first and requests hybrid results after an 80 ms delay. Search Plugin frecency reads use the database reader pool so they do not wait behind a writer transaction.
  • Added Search query stage traces without query text, long-frame attribution in the production palette probe, and bounded failure details for concurrent reindex queries.
  • Reduced repeated palette geometry reads and viewport CSS writes. These changes reduced long tasks in one complete follow-up but did not meet the palette targets.

Files

  • apps/web/e2e/search-scale-palette.mjs
  • apps/web/src/lib/components/search-dialog.svelte
  • apps/web/src/lib/search/registry.ts
  • apps/web/src/lib/search/server.ts
  • apps/web/src/lib/search/window.svelte.ts
  • contracts/openapi.json
  • crates/calternal-plugin/src/lib.rs
  • crates/calternal-search/src/indexer.rs
  • crates/calternal-search/src/plugin.rs
  • crates/calternal-search/src/query.rs
  • crates/calternal-search/tests/indexer.rs
  • crates/calternal-server/src/main.rs
  • crates/calternal-server/src/wire.rs
  • docs/perf/2026-09-28.md
  • packages/api-client/src/generated.ts
  • tests/perf/search_scale.py

100k profile

One completed 100-sample keyword-only profile measured p50 / p95 / p99 in ms:

  • Plain: 9.64 / 30.09 / 38.07
  • Tag: 7.71 / 37.77 / 53.75
  • Type filter: 8.87 / 18.27 / 52.28
  • Folder scope: 8.60 / 33.04 / 71.34

All p50 and p99 targets passed in this run. The p95 target passed for type filter; plain missed by 0.09 ms, and tag and folder missed. A second complete profile after the palette layout change also missed plain, tag and folder p95, and missed plain p99. The latest profile overlapped another server cargo build; it measured p95 between 39.37 and 113.63 ms and then stopped after one concurrent Search request failed during reindex. The server used 244% CPU in that phase. Its old harness did not retain the response or timeout detail, so I did not repeat this load-heavy profile. The harness now retains up to 10 bounded details for a future run.

The palette target remains unmet. One complete follow-up measured first-frame p50 / p95 at 69.6 / 182.2 ms, with 6 tasks over 50 ms and a 90 ms maximum. The latest load-heavy sample measured 91.8 / 199.8 ms, with 12 tasks and a 164 ms maximum. The latest hybrid profile indexed 6,960 of 70,000 semantic paths; do not treat its 210.76 ms warm p95 as a full-corpus result. The 1M keyword target was not measured in this phase.

Production palette screenshot from the real 100k profile:

Production Search palette at 100k

Gates

cargo fmt --all -- --check: exit 0; stdout was empty.

cargo clippy --all-targets -- -D warnings:

Finished `dev` profile [unoptimized + debuginfo] target(s) in 23.28s

cargo test full workspace had 1,355 passed, 0 failed and 12 ignored across 72 test-result lines. Exact Search and server summaries:

test result: ok. 28 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 1.12s
test result: ok. 17 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 6.10s
test result: ok. 65 passed; 0 failed; 2 ignored; 0 measured; 0 filtered out; finished in 4.88s

bun run check:

svelte-check found 0 errors and 0 warnings

bun run test:

Test Files  104 passed (104)
      Tests  691 passed (691)

bun run build:

✓ built in 18.09s
Wrote site to "build"

packages/api-client/check-generated.sh:

Finished `dev` profile [unoptimized + debuginfo] target(s) in 24.50s
Running `target/debug/calternal-server openapi`
✨ openapi-typescript 7.13.0
🚀 ../../contracts/openapi.json → src/generated.ts [480.4ms]

Decisions not specified in DESIGN §32

  • Use an optional semantic query flag for keyword-only requests while keeping hybrid results as the default.
  • Wait 80 ms after the keyword response before starting hybrid fan-out.

Known gaps: keyword p95 does not meet the target in all cases; palette frame p95 and the no-long-task target remain unmet; semantic coverage was incomplete; 1M query latency was not measured.

STEP B done — HEAD `2f1f9ace888084a5b83b6d1220a1b0fa88d17ab7` on `job/search-perf`. The branch is pushed. Step A and its one `origin/dev` merge were completed earlier. ### Built - Added an optional `semantic` search query parameter. `false` returns Search Plugin keyword hits only; `true` or an omitted value keeps hybrid fan-out as the default. - The palette now paints keyword hits first and requests hybrid results after an 80 ms delay. Search Plugin frecency reads use the database reader pool so they do not wait behind a writer transaction. - Added Search query stage traces without query text, long-frame attribution in the production palette probe, and bounded failure details for concurrent reindex queries. - Reduced repeated palette geometry reads and viewport CSS writes. These changes reduced long tasks in one complete follow-up but did not meet the palette targets. ### Files - `apps/web/e2e/search-scale-palette.mjs` - `apps/web/src/lib/components/search-dialog.svelte` - `apps/web/src/lib/search/registry.ts` - `apps/web/src/lib/search/server.ts` - `apps/web/src/lib/search/window.svelte.ts` - `contracts/openapi.json` - `crates/calternal-plugin/src/lib.rs` - `crates/calternal-search/src/indexer.rs` - `crates/calternal-search/src/plugin.rs` - `crates/calternal-search/src/query.rs` - `crates/calternal-search/tests/indexer.rs` - `crates/calternal-server/src/main.rs` - `crates/calternal-server/src/wire.rs` - `docs/perf/2026-09-28.md` - `packages/api-client/src/generated.ts` - `tests/perf/search_scale.py` ### 100k profile One completed 100-sample keyword-only profile measured p50 / p95 / p99 in ms: - Plain: 9.64 / 30.09 / 38.07 - Tag: 7.71 / 37.77 / 53.75 - Type filter: 8.87 / 18.27 / 52.28 - Folder scope: 8.60 / 33.04 / 71.34 All p50 and p99 targets passed in this run. The p95 target passed for type filter; plain missed by 0.09 ms, and tag and folder missed. A second complete profile after the palette layout change also missed plain, tag and folder p95, and missed plain p99. The latest profile overlapped another server cargo build; it measured p95 between 39.37 and 113.63 ms and then stopped after one concurrent Search request failed during reindex. The server used 244% CPU in that phase. Its old harness did not retain the response or timeout detail, so I did not repeat this load-heavy profile. The harness now retains up to 10 bounded details for a future run. The palette target remains unmet. One complete follow-up measured first-frame p50 / p95 at 69.6 / 182.2 ms, with 6 tasks over 50 ms and a 90 ms maximum. The latest load-heavy sample measured 91.8 / 199.8 ms, with 12 tasks and a 164 ms maximum. The latest hybrid profile indexed 6,960 of 70,000 semantic paths; do not treat its 210.76 ms warm p95 as a full-corpus result. The 1M keyword target was not measured in this phase. Production palette screenshot from the real 100k profile: ![Production Search palette at 100k](https://git.kayg.org/attachments/a5c758df-59b1-47dd-8c2d-badee372fa65) ### Gates `cargo fmt --all -- --check`: exit 0; stdout was empty. `cargo clippy --all-targets -- -D warnings`: ```text Finished `dev` profile [unoptimized + debuginfo] target(s) in 23.28s ``` `cargo test` full workspace had 1,355 passed, 0 failed and 12 ignored across 72 test-result lines. Exact Search and server summaries: ```text test result: ok. 28 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 1.12s test result: ok. 17 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 6.10s test result: ok. 65 passed; 0 failed; 2 ignored; 0 measured; 0 filtered out; finished in 4.88s ``` `bun run check`: ```text svelte-check found 0 errors and 0 warnings ``` `bun run test`: ```text Test Files 104 passed (104) Tests 691 passed (691) ``` `bun run build`: ```text ✓ built in 18.09s Wrote site to "build" ``` `packages/api-client/check-generated.sh`: ```text Finished `dev` profile [unoptimized + debuginfo] target(s) in 24.50s Running `target/debug/calternal-server openapi` ✨ openapi-typescript 7.13.0 🚀 ../../contracts/openapi.json → src/generated.ts [480.4ms] ``` ### Decisions not specified in DESIGN §32 - Use an optional `semantic` query flag for keyword-only requests while keeping hybrid results as the default. - Wait 80 ms after the keyword response before starting hybrid fan-out. Known gaps: keyword p95 does not meet the target in all cases; palette frame p95 and the no-long-task target remain unmet; semantic coverage was incomplete; 1M query latency was not measured.
Author
Owner

Starting step C on job/search-perf-c at base f9c0a06609f267e718509dedf07aa340a8de9a50 (includes step B 75edcb0d). I will reproduce the reported query failure during reindex first, then profile the open 100k tail, palette first frame, 1M keyword run, and embedding backlog. I will merge dev once before final gates as requested.

Starting step C on `job/search-perf-c` at base `f9c0a06609f267e718509dedf07aa340a8de9a50` (includes step B `75edcb0d`). I will reproduce the reported query failure during reindex first, then profile the open 100k tail, palette first frame, 1M keyword run, and embedding backlog. I will merge `dev` once before final gates as requested.
Author
Owner

Code inspection finding for semantic backlog: calternal-embed::reconcile_all walks each Home and calls index_files sequentially. For each file, prepare_path starts a blocking file read and then executes one SELECT MIN(content_hash), COUNT(*) against semantic_documents; inference is batched only after those serial checks. The 70k-path checkpoint may therefore be spending substantial time in per-file preparation. I will measure this against the real 100k profile before changing the worker.

Code inspection finding for semantic backlog: `calternal-embed::reconcile_all` walks each Home and calls `index_files` sequentially. For each file, `prepare_path` starts a blocking file read and then executes one `SELECT MIN(content_hash), COUNT(*)` against `semantic_documents`; inference is batched only after those serial checks. The 70k-path checkpoint may therefore be spending substantial time in per-file preparation. I will measure this against the real 100k profile before changing the worker.
Author
Owner

Measurement environment finding: this worktree is not on a quiet host. At 08:48 Europe/Berlin, systemctl --user list-units 'codex-cal-*' showed 8 active services and load average was 10.27 / 12.27 / 10.20 (8 CPU cores). Other server, browser, and Rust build work was active. I will proceed without waiting, capture load around each profile, and label the results as shared-host measurements.

Measurement environment finding: this worktree is not on a quiet host. At 08:48 Europe/Berlin, `systemctl --user list-units 'codex-cal-*'` showed 8 active services and load average was 10.27 / 12.27 / 10.20 (8 CPU cores). Other server, browser, and Rust build work was active. I will proceed without waiting, capture load around each profile, and label the results as shared-host measurements.
Author
Owner

First production palette probe in the live mixed 100k profile: keystroke-to-first-frame p50/p95 was 114.1 / 273.8 ms (65 samples), with 14 main-thread tasks over 50 ms and a 346 ms maximum. Long Animation Frame details include a palette FrameRequestCallback with up to 62.9 ms forced style/layout. This profile ran while the shared-host load was elevated, so it is a diagnostic signal, not a quiet-host comparison. The 100k run is still indexing semantic content; query and reindex results are pending.

First production palette probe in the live mixed 100k profile: keystroke-to-first-frame p50/p95 was 114.1 / 273.8 ms (65 samples), with 14 main-thread tasks over 50 ms and a 346 ms maximum. Long Animation Frame details include a palette `FrameRequestCallback` with up to 62.9 ms forced style/layout. This profile ran while the shared-host load was elevated, so it is a diagnostic signal, not a quiet-host comparison. The 100k run is still indexing semantic content; query and reindex results are pending.
Author
Owner

Mid-profile host sample at 08:58 Europe/Berlin: load average 29.24 / 25.45 / 17.60, with 22 runnable processes on the 8-CPU host. Semantic coverage moved from 20,192 to 22,400 paths over the next progress interval. I am retaining the run as shared-host evidence and will include this load sample next to its results.

Mid-profile host sample at 08:58 Europe/Berlin: load average 29.24 / 25.45 / 17.60, with 22 runnable processes on the 8-CPU host. Semantic coverage moved from 20,192 to 22,400 paths over the next progress interval. I am retaining the run as shared-host evidence and will include this load sample next to its results.
Author
Owner

The live profile's semantic SQLite index currently contains 57,216 distinct paths of 70,000 after 22 minutes. The 15-minute wait expired before completion, but the worker continues to advance. This shows a slow backlog, not a stopped worker. The scheduled 100k keyword samples are in the same server process while this work continues; their latencies will show whether that load affects keyword search on this shared host.

The live profile's semantic SQLite index currently contains 57,216 distinct paths of 70,000 after 22 minutes. The 15-minute wait expired before completion, but the worker continues to advance. This shows a slow backlog, not a stopped worker. The scheduled 100k keyword samples are in the same server process while this work continues; their latencies will show whether that load affects keyword search on this shared host.
Author
Owner

The live 100k profile's semantic database now contains 70,324 distinct paths, above the expected 70,000. It reached full coverage after roughly 30 minutes on this shared, heavily loaded host. The worker was slow but did not stop. I am waiting for the profile's keyword measurements to see whether they overlapped with embedding work.

The live 100k profile's semantic database now contains 70,324 distinct paths, above the expected 70,000. It reached full coverage after roughly 30 minutes on this shared, heavily loaded host. The worker was slow but did not stop. I am waiting for the profile's keyword measurements to see whether they overlapped with embedding work.
Author
Owner

The real 100k profile reproduced the rebuild failure: 3 Search requests failed during concurrent full reindex. The updated harness did not persist their details: measure_rebuild holds them in a local result and raises before returning it, so the artifact has failure.error = "3 search queries failed during full reindex" and full_reindex = null. Its plain stage trace is also empty because the server defaults to RUST_LOG=info, while the Search stage events are debug-level. End-of-run load was 23.03 / 21.85 / 22.79 on the shared host, with 15 active codex-cal-* services. I will fix the harness output/filter, then rerun a bounded rebuild profile to distinguish a 5xx from a load timeout.

The real 100k profile reproduced the rebuild failure: 3 Search requests failed during concurrent full reindex. The updated harness did not persist their details: `measure_rebuild` holds them in a local result and raises before returning it, so the artifact has `failure.error = "3 search queries failed during full reindex"` and `full_reindex = null`. Its plain stage trace is also empty because the server defaults to `RUST_LOG=info`, while the Search stage events are debug-level. End-of-run load was 23.03 / 21.85 / 22.79 on the shared host, with 15 active `codex-cal-*` services. I will fix the harness output/filter, then rerun a bounded rebuild profile to distinguish a 5xx from a load timeout.
Author
Owner

Focused-harness finding (evidence): the updated 5k-item mixed profile completed a staged full rebuild with 5 Search samples and 0 failures. It now persists query-failure details before raising, emits the Search stage trace, and reports load average at profile start/end. The trace parser captured Tantivy exact query, snippets, frecency, filesystem hydration, route, and provider stages. A p95 outlier in the type-filter case was 29.42 ms in frecency lookup (shared-host load was 24.67/23.72/22.83 at start and 24.06/23.62/22.80 at end; 15 codex-cal units active), so this is diagnostic only. The harness also now supports skipping palette, semantic, and freshness work for focused reindex repros; the standard 100k run retains the UI probe.

Focused-harness finding (evidence): the updated 5k-item mixed profile completed a staged full rebuild with 5 Search samples and 0 failures. It now persists query-failure details before raising, emits the Search stage trace, and reports load average at profile start/end. The trace parser captured Tantivy exact query, snippets, frecency, filesystem hydration, route, and provider stages. A p95 outlier in the type-filter case was 29.42 ms in frecency lookup (shared-host load was 24.67/23.72/22.83 at start and 24.06/23.62/22.80 at end; 15 codex-cal units active), so this is diagnostic only. The harness also now supports skipping palette, semantic, and freshness work for focused reindex repros; the standard 100k run retains the UI probe.
Author
Owner

Instrumented 100k mixed profile (release server + production build): the old failure could not be reproduced. The full staged reindex served 47 concurrent Search requests with 0 failures (query p50/p95/p99 205.42/337.02/2,697.26 ms). The previous three errors cannot be classified as HTTP failures or client timeouts because that run discarded the details; the updated runner preserves up to 10 details for the next occurrence. A deterministic 5k run also had 0 failures across 5 requests.

Keyword query results, 100 samples/case, p50/p95/p99 ms: plain 8.52/16.55/25.89; tag 5.88/14.49/21.38; type 7.09/16.49/20.66; folder 7.11/15.03/20.21. All meet p50 ≤10, p95 ≤30, p99 ≤50. Stage traces place the plain-query p95 mostly in Tantivy exact query + snippet generation (11.96 ms combined), with frecency p95 1.01 ms and filesystem hydration p95 0.53 ms. Palette first-frame p95 was 193.7 ms; there were 12 long tasks >50 ms, max 358 ms.

This was not a quiet-host run: 8-vCPU host load averages were 15.14/20.58/21.81 at start and 15.52/18.10/20.62 at end, with 15 codex-cal services active. Treat the timings as shared-host diagnostics. The full report is in the worktree at target/perf/search-step-c-focused-100k.json; the production-build indexing screenshot is target/perf/search-indexing-progress.png.

Instrumented 100k mixed profile (release server + production build): the old failure could not be reproduced. The full staged reindex served 47 concurrent Search requests with 0 failures (query p50/p95/p99 205.42/337.02/2,697.26 ms). The previous three errors cannot be classified as HTTP failures or client timeouts because that run discarded the details; the updated runner preserves up to 10 details for the next occurrence. A deterministic 5k run also had 0 failures across 5 requests. Keyword query results, 100 samples/case, p50/p95/p99 ms: plain 8.52/16.55/25.89; tag 5.88/14.49/21.38; type 7.09/16.49/20.66; folder 7.11/15.03/20.21. All meet p50 ≤10, p95 ≤30, p99 ≤50. Stage traces place the plain-query p95 mostly in Tantivy exact query + snippet generation (11.96 ms combined), with frecency p95 1.01 ms and filesystem hydration p95 0.53 ms. Palette first-frame p95 was 193.7 ms; there were 12 long tasks >50 ms, max 358 ms. This was not a quiet-host run: 8-vCPU host load averages were 15.14/20.58/21.81 at start and 15.52/18.10/20.62 at end, with 15 codex-cal services active. Treat the timings as shared-host diagnostics. The full report is in the worktree at target/perf/search-step-c-focused-100k.json; the production-build indexing screenshot is target/perf/search-indexing-progress.png.
Author
Owner

The real production-build screenshot from the 100k indexing progress probe is attached:

Search indexing progress at 48 percent

The real production-build screenshot from the 100k indexing progress probe is attached: ![Search indexing progress at 48 percent](https://git.kayg.org/attachments/a8f25e4e-f59f-468c-8ef7-28efd73c7d83)
Author
Owner

Reliability regression added and targeted test passed. reindex_keeps_the_previous_index_searchable_until_the_new_scan_finishes now runs 8 concurrent readers × 16 Search queries while the full rebuild is deliberately blocked in PDF extraction; all 128 queries must return the old committed hit and no Indexer error. The real-server search_chaos.py staged-rebuild case also starts an 8-request Search burst and checks every response is HTTP 200 with the committed sentinel, then continues querying through the rebuild.

Gate output: test reindex_keeps_the_previous_index_searchable_until_the_new_scan_finishes ... ok; test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 16 filtered out; finished in 2.15s.

Reliability regression added and targeted test passed. `reindex_keeps_the_previous_index_searchable_until_the_new_scan_finishes` now runs 8 concurrent readers × 16 Search queries while the full rebuild is deliberately blocked in PDF extraction; all 128 queries must return the old committed hit and no Indexer error. The real-server `search_chaos.py` staged-rebuild case also starts an 8-request Search burst and checks every response is HTTP 200 with the committed sentinel, then continues querying through the rebuild. Gate output: `test reindex_keeps_the_previous_index_searchable_until_the_new_scan_finishes ... ok`; `test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 16 filtered out; finished in 2.15s`.
Author
Owner

The 1M stress runner previously stopped before keyword samples when the authenticated integrity route returned 503 despite a complete Search manifest. For the keyword-only stress profile, readiness now checks committed search_manifest coverage plus a successful real needle Search hit; it records the admin integrity route separately after the measurements. The 100-document smoke profile passed this readiness path (107 manifest entries, keyword probe HTTP 200 with 20 hits), and its separate integrity probe returned HTTP 200/healthy. This preserves the 1M keyword measurement even if the unrelated admin status route is busy, while reporting that route's result explicitly.

The 1M stress runner previously stopped before keyword samples when the authenticated integrity route returned 503 despite a complete Search manifest. For the keyword-only stress profile, readiness now checks committed `search_manifest` coverage plus a successful real `needle` Search hit; it records the admin integrity route separately after the measurements. The 100-document smoke profile passed this readiness path (107 manifest entries, keyword probe HTTP 200 with 20 hits), and its separate integrity probe returned HTTP 200/healthy. This preserves the 1M keyword measurement even if the unrelated admin status route is busy, while reporting that route's result explicitly.
Author
Owner

1M keyword stress progress (single run): at 4m39s of server uptime the committed Search manifest had 57,183/1,001,003 entries. Host load was 30.76/29.25/24.62 on the 8-vCPU build host, with 15 codex-cal-* services active. This is a shared-host diagnostic; I will report whether the bounded index wait reaches full coverage and records the keyword samples.

1M keyword stress progress (single run): at 4m39s of server uptime the committed Search manifest had 57,183/1,001,003 entries. Host load was 30.76/29.25/24.62 on the 8-vCPU build host, with 15 `codex-cal-*` services active. This is a shared-host diagnostic; I will report whether the bounded index wait reaches full coverage and records the keyword samples.
Author
Owner

The 1M run is progressing rather than stuck: the Search manifest advanced from 57,183 to 75,561 entries. Server logs show SQLx connection acquisition taking 3.11–4.04 s (slow threshold 2 s) while Tantivy commits continue. This is evidence of SQLite pool contention under the current shared-host load (~30). It may explain why the earlier admin integrity route returned 503, but it does not establish the cause of the earlier three Search query failures.

The 1M run is progressing rather than stuck: the Search manifest advanced from 57,183 to 75,561 entries. Server logs show SQLx connection acquisition taking 3.11–4.04 s (slow threshold 2 s) while Tantivy commits continue. This is evidence of SQLite pool contention under the current shared-host load (~30). It may explain why the earlier admin integrity route returned 503, but it does not establish the cause of the earlier three Search query failures.
Author
Owner

1M probe update: the single in-progress corpus has 267,513 / 1,001,003 committed Search manifest entries after about 22 minutes. The shared host is busy (load averages 32.91 / 29.28 / 27.42; 17 codex-cal-* units). I am continuing this same run to completion, without regenerating or repeating the corpus.

1M probe update: the single in-progress corpus has 267,513 / 1,001,003 committed Search manifest entries after about 22 minutes. The shared host is busy (load averages 32.91 / 29.28 / 27.42; 17 codex-cal-* units). I am continuing this same run to completion, without regenerating or repeating the corpus.
Author
Owner

Finding: the previous palette probe collected Long Task entries from palette lazy-mount and open/close transitions, although the target is tasks while typing. I updated the probe to open once, wait for the entry animation, keep the palette mounted during typing, and include only tasks overlapping keystroke-to-result windows. This makes the 100k palette result match the requested scope; I will capture the scoped run after the current 1M index finishes.

Finding: the previous palette probe collected Long Task entries from palette lazy-mount and open/close transitions, although the target is tasks while typing. I updated the probe to open once, wait for the entry animation, keep the palette mounted during typing, and include only tasks overlapping keystroke-to-result windows. This makes the 100k palette result match the requested scope; I will capture the scoped run after the current 1M index finishes.
Author
Owner

1M probe update: 470,185 / 1,001,003 manifest entries. The shared host load has risen to 48.55 / 39.60 / 34.98 with 14 codex-cal-* units. This is not a quiet-host measurement; the run continues under the one bounded probe, per the no-wait rule.

1M probe update: 470,185 / 1,001,003 manifest entries. The shared host load has risen to 48.55 / 39.60 / 34.98 with 14 codex-cal-* units. This is not a quiet-host measurement; the run continues under the one bounded probe, per the no-wait rule.
Author
Owner

1M profile is at 663,158 / 1,001,003 manifest entries. Load is 22.60 / 26.79 / 30.41 with 16 codex-cal-* units. The same corpus continues; no quiet interval was assumed.

1M profile is at 663,158 / 1,001,003 manifest entries. Load is 22.60 / 26.79 / 30.41 with 16 codex-cal-* units. The same corpus continues; no quiet interval was assumed.
Author
Owner

1M Search reliability finding: the 1,001,006 / 1,001,003 manifest is committed, but one authenticated GET /api/v1/search?q=needle&semantic=false returned HTTP 503 after 30.01 s. At that time load averages were 25.07 / 22.87 / 24.03 with 15 codex-cal-* units. The server log records SQLite pool acquisition delays of 2.4–5.7 s, pool timeouts in background workers, and authentication DB busy errors. This is a 5xx, not a latency-only miss. The 1M p50/p95 sample is withheld until Search readiness succeeds; the route stage causing this response is not yet attributed.

1M Search reliability finding: the 1,001,006 / 1,001,003 manifest is committed, but one authenticated GET /api/v1/search?q=needle&semantic=false returned HTTP 503 after 30.01 s. At that time load averages were 25.07 / 22.87 / 24.03 with 15 codex-cal-* units. The server log records SQLite pool acquisition delays of 2.4–5.7 s, pool timeouts in background workers, and authentication DB busy errors. This is a 5xx, not a latency-only miss. The 1M p50/p95 sample is withheld until Search readiness succeeds; the route stage causing this response is not yet attributed.
Author
Owner

Follow-up to the 1M HTTP 503: I stopped the readiness polling after the single 30 s diagnostic request. There are no Search route completion traces in the server log during this interval; the same log has repeated authentication DB busy and SQLite pool timeout errors. This points to request setup/authentication contention before the Search route, but does not identify the exact pool or recover the lost response body. No 1M p50/p95 values were produced.

Follow-up to the 1M HTTP 503: I stopped the readiness polling after the single 30 s diagnostic request. There are no Search route completion traces in the server log during this interval; the same log has repeated authentication DB busy and SQLite pool timeout errors. This points to request setup/authentication contention before the Search route, but does not identify the exact pool or recover the lost response body. No 1M p50/p95 values were produced.
Author
Owner

Post-merge 100k profile completed with 0 Search failures during full reindex (194 query samples; p50/p95/p99 258.25/833.61/3314.22 ms). Reindex took 259.23 s; peak RSS was 483,061,760 bytes. This run was not quiet: load average moved from 14.82/18.46/21.54 to 40.58/36.44/28.65 on 8 CPUs, with 16 codex-cal-* units. Plain/tag/type/folder p95 was 60.87/54.11/45.21/49.78 ms. The trace sample remains dominated by Tantivy query plus snippet construction (3.70 ms of 5.10 ms provider time; frecency 0.55 ms, filesystem hydration 0.55 ms). These loaded-host results do not establish the quiet-host target. Palette typing remained over target in this loaded run; the captured probe still had two no-hit query timeouts because the corrected query list was committed after this production build/run.

Post-merge 100k profile completed with 0 Search failures during full reindex (194 query samples; p50/p95/p99 258.25/833.61/3314.22 ms). Reindex took 259.23 s; peak RSS was 483,061,760 bytes. This run was not quiet: load average moved from 14.82/18.46/21.54 to 40.58/36.44/28.65 on 8 CPUs, with 16 codex-cal-* units. Plain/tag/type/folder p95 was 60.87/54.11/45.21/49.78 ms. The trace sample remains dominated by Tantivy query plus snippet construction (3.70 ms of 5.10 ms provider time; frecency 0.55 ms, filesystem hydration 0.55 ms). These loaded-host results do not establish the quiet-host target. Palette typing remained over target in this loaded run; the captured probe still had two no-hit query timeouts because the corrected query list was committed after this production build/run.
Author
Owner

The one post-merge Search adversarial round failed two checks after the watcher-overflow stage had written 15,000 of 20,000 fixture files: concurrent Search during full rebuild 0 lost the committed hit and rebuild did not enter its running state before the crash probe. The result-matcher test passed (Ran 1 test in 0.001s, OK). The runner removed its temporary server log on exit, so this round did not retain an HTTP status or Search response body for the failing query. I am tracing the probe setup and Index swap path before final gates.

The one post-merge Search adversarial round failed two checks after the watcher-overflow stage had written 15,000 of 20,000 fixture files: `concurrent Search during full rebuild 0 lost the committed hit` and `rebuild did not enter its running state before the crash probe`. The result-matcher test passed (`Ran 1 test in 0.001s`, `OK`). The runner removed its temporary server log on exit, so this round did not retain an HTTP status or Search response body for the failing query. I am tracing the probe setup and Index swap path before final gates.
Author
Owner

Follow-up on the Search chaos result: the concurrent-hit assertion checked raw JSON bytes, while wait_for_hit already removes <b> highlight tags before matching. The runner did not retain the failing response body, so markup is a likely explanation, not a confirmed root cause. I changed both checks to parse Search result fields and normalize highlight tags, and added a split-highlight regression; both focused Python tests pass. The second failure was the crash probe not seeing integrity.running within 30 seconds after the 20k watcher burst had written 15k files. The host load during the round was 24.80 / 30.75 / 30.13 with 16 codex-cal-* units. The probe found no HTTP 5xx and did not send SIGKILL. I extended its bounded start wait to 180 seconds. The round remains a failed/partial adversarial check; the crash recovery case was not exercised.

Follow-up on the Search chaos result: the concurrent-hit assertion checked raw JSON bytes, while `wait_for_hit` already removes `<b>` highlight tags before matching. The runner did not retain the failing response body, so markup is a likely explanation, not a confirmed root cause. I changed both checks to parse Search result fields and normalize highlight tags, and added a split-highlight regression; both focused Python tests pass. The second failure was the crash probe not seeing `integrity.running` within 30 seconds after the 20k watcher burst had written 15k files. The host load during the round was 24.80 / 30.75 / 30.13 with 16 `codex-cal-*` units. The probe found no HTTP 5xx and did not send SIGKILL. I extended its bounded start wait to 180 seconds. The round remains a failed/partial adversarial check; the crash recovery case was not exercised.
Author
Owner

Additional evidence from the required local adversarial run for #303 (2026-09-28, after merging dev once):

  • search_chaos.py observed four HTTP 200 queries that omitted the already indexed unicodenfcsentinel hit while a staged rebuild ran.
  • The tz-days probe created a Log on 2026-08-14 and confirmed it in Journal/calendar reads, but the search query did not return it after 60 attempts (30 seconds).

The suite ran under heavy shared-host load. These responses were HTTP 200 with missing results, not request timeouts, and match the freshness/old-index reliability target here.

Additional evidence from the required local adversarial run for #303 (2026-09-28, after merging dev once): - `search_chaos.py` observed four HTTP 200 queries that omitted the already indexed `unicodenfcsentinel` hit while a staged rebuild ran. - The `tz-days` probe created a Log on 2026-08-14 and confirmed it in Journal/calendar reads, but the search query did not return it after 60 attempts (30 seconds). The suite ran under heavy shared-host load. These responses were HTTP 200 with missing results, not request timeouts, and match the freshness/old-index reliability target here.
Author
Owner

Starting the finish-now pass for #258 on job/search-perf-c. Base SHA: 82843b08e2a3d83139d56de2319aae13e192cf1e (dev). Current head: ada267716beeecaecb5bf1455cc0fc3dfdc28132. The worktree is clean. I am finishing the existing Search chaos marker/recovery slice, then I will merge dev once, run final gates and the requested evidence pass, and report remaining targets as follow-ups.

Starting the finish-now pass for #258 on `job/search-perf-c`. Base SHA: `82843b08e2a3d83139d56de2319aae13e192cf1e` (dev). Current head: `ada267716beeecaecb5bf1455cc0fc3dfdc28132`. The worktree is clean. I am finishing the existing Search chaos marker/recovery slice, then I will merge `dev` once, run final gates and the requested evidence pass, and report remaining targets as follow-ups.
Author
Owner

Post-merge Search adversarial result for #258 (head be951e55fbf514cffe78125b8f21ee40fbc23311): ADVERSARIAL_SEARCH_ONLY=1 ./tests/adversarial/run.sh exited 1. The real local Search API returned HTTP 200 with one unicodenfcsentinel result during the run. The watcher-overflow stage wrote 15,000 of 20,000 files, then restart_on_request timed out after 1,800 polls at 0.1 s while waiting for restart-ready-4. The probe reported three Owner passkey refresh failed before a search admin operation findings and did not reach SIGKILL. No HTTP 5xx was reported. This round is partial. Follow-up: make the crash restart handshake and Owner refresh survive a watcher scan longer than 180 s under shared-host load, then complete the SIGKILL check. No repeat run in this finish-now pass.

Post-merge Search adversarial result for #258 (head `be951e55fbf514cffe78125b8f21ee40fbc23311`): `ADVERSARIAL_SEARCH_ONLY=1 ./tests/adversarial/run.sh` exited 1. The real local Search API returned HTTP 200 with one `unicodenfcsentinel` result during the run. The watcher-overflow stage wrote 15,000 of 20,000 files, then `restart_on_request` timed out after 1,800 polls at 0.1 s while waiting for `restart-ready-4`. The probe reported three `Owner passkey refresh failed before a search admin operation` findings and did not reach SIGKILL. No HTTP 5xx was reported. This round is partial. Follow-up: make the crash restart handshake and Owner refresh survive a watcher scan longer than 180 s under shared-host load, then complete the SIGKILL check. No repeat run in this finish-now pass.
Author
Owner

The post-merge workspace cargo test gate stopped at the existing collaboration timing assertion session::public_edit_limit_tests::ten_thousand_markdown_blocks_open_and_sync_within_two_seconds. It measured 2.921247938 s against its 2 s limit (parse 2.219217185 s, Yrs 624.775483 ms, block index 20.49739 ms, first sync 29.440246 ms, snapshot 27.317634 ms). The assertions on behavior passed; only the elapsed-time limit failed. This is a SLOW-only shared-host result. I left the expected limit unchanged. Cargo stopped before later test binaries ran.

The post-merge workspace `cargo test` gate stopped at the existing collaboration timing assertion `session::public_edit_limit_tests::ten_thousand_markdown_blocks_open_and_sync_within_two_seconds`. It measured 2.921247938 s against its 2 s limit (parse 2.219217185 s, Yrs 624.775483 ms, block index 20.49739 ms, first sync 29.440246 ms, snapshot 27.317634 ms). The assertions on behavior passed; only the elapsed-time limit failed. This is a SLOW-only shared-host result. I left the expected limit unchanged. Cargo stopped before later test binaries ran.
Author
Owner

#258 finish-now report

Branch: job/search-perf-c
Head: be951e55fbf514cffe78125b8f21ee40fbc23311
Push: git push origin job/search-perf-c returned Everything up-to-date; HEAD and origin/job/search-perf-c both resolve to this SHA.

Built

  • Extended the Search scale runner and palette probe. The palette samples now use terms that match the corpus and scope long tasks to typing.
  • Kept an Index searchability regression during a blocked staged rebuild.
  • Made the Search chaos matcher parse result fields and remove <b> highlight wrappers. Extended its bounded crash-start wait to 180 seconds.
  • Recorded the loaded-host profile and remaining target gaps in docs/perf/2026-09-28.md.

Job files: apps/web/e2e/search-scale-palette.mjs, crates/calternal-search/tests/indexer.rs, docs/perf/2026-09-28.md, tests/adversarial/run.sh, tests/adversarial/search_chaos.py, tests/adversarial/test_search_result_matching.py, tests/perf/search_scale.py.

Measurements

All full profiles below ran on the shared 8-vCPU build host, not the 4-vCPU production VM. Other builds and server jobs were active.

  • 100k keyword p50 / p95 / p99 ms (post-merge loaded run): plain 20.29 / 60.87 / 97.20; tag 14.93 / 54.11 / 87.57; type filter 15.51 / 45.21 / 86.88; folder 17.93 / 49.78 / 59.56. Targets were not met in this run.
  • 1M: the manifest reached 1,001,006 entries for 1,001,003 filesystem paths. A keyword Search request returned HTTP 503 after 30.01 s; no 1M latency percentile was produced.
  • Palette typing (loaded run): first-result frame p50 / p95 183.3 / 712.9 ms; 7 long tasks over 50 ms, maximum 440 ms. The corrected query list was committed after that production build, so it has not been measured yet.
  • Full 100k reindex: 259.23 s, peak RSS 483,061,760 bytes, 0 failed Search requests across 194 samples. Concurrent query p50 / p95 / p99 was 258.25 / 833.61 / 3,314.22 ms under load.
  • Earlier 100k initial Index: 64.52 s, peak RSS 462,700,544 bytes; integrity checked 90,099 Items. The 100k profile does not cover the full mixed corpus target.
  • Freshness run scheduled 1,000 API writes but reached 84.65 successful writes/min; 765 succeeded and 255 returned HTTP 429. API freshness p95 / p99 was 850.27 / 1,169.49 ms; outside-file freshness was 3,980.43 / 4,279.76 ms.
  • Semantic indexing previously reached 7,040 / 70,000 paths before the profile ended; its 214.64 ms warm p95 is incomplete-corpus data. Idle Indexer CPU was not isolated.

The prior cross-job adversarial evidence in this issue also records four HTTP 200 Search responses that omitted a committed hit during rebuild, plus a tz-days entry that Search did not return within 30 seconds. Those are reliability follow-ups, not load-only latency misses.

Screenshots

Captured from the production web build on a local server. The disposable Home used one Note created through the real Notes API. All six captures are attached to this issue:

Width Light Dark
Phone 390 px phone light phone dark
Tablet 820 px tablet light tablet dark
Desktop 1440 px desktop light desktop dark

Gates

  • cargo fmt --all -- --check: exit 0; stdout was empty.

  • cargo clippy --all-targets -- -D warnings:

    Finished `dev` profile [unoptimized + debuginfo] target(s) in 3m 34s
    

    The adversarial server build used the vendored OpenSSL configuration. For the final clippy/test checks I used host OpenSSL 3.5.7 with OPENSSL_NO_VENDOR=1 and a temporary direct-rustc wrapper after shared sccache tried to use a removed temp directory in another worktree.

  • cargo test stopped at an existing timing assertion in calternal-collab (exit 101):

    10,000-block collaboration phases: parse=2.219217185s, Yrs=624.775483ms, block-index=20.49739ms, first-sync=29.440246ms (616204 bytes), snapshot=27.317634ms (616199 bytes), total=2.921247938s
    test session::public_edit_limit_tests::ten_thousand_markdown_blocks_open_and_sync_within_two_seconds ... FAILED
    test result: FAILED. 14 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 4.24s
    

    This is a SLOW-only miss: the existing 2-second expectation remains unchanged. Cargo stopped before later test binaries ran.

  • bun run check in apps/web printed:

    svelte-check found 0 errors and 0 warnings
    

    The wrapper pipeline returned 1 because its tee path was wrong (../target/tmp from apps/web); the checker itself reported zero errors and warnings.

  • bun run test:

    Test Files  1 failed | 109 passed (110)
          Tests  1 failed | 709 passed (710)
    

    The one failure was menu-open-focus.svelte.test.ts, which timed out at 5,000 ms. The suite took 277.91 s; this is a SLOW-only shared-host result.

  • Post-merge Search-only adversarial round exited 1. It wrote 15,000 / 20,000 watcher-overflow files, then timed out waiting 180 seconds for restart-ready-4; it reported three Owner passkey refresh failures. No HTTP 5xx was reported, and the SIGKILL check did not run. This round is partial.

Follow-ups

  1. Investigate the HTTP 200 missing-hit cases during concurrent rebuild and add a regression that preserves the hit.
  2. Investigate the 1M HTTP 503 / database-pool contention, then record actual 1M latency.
  3. Re-run the corrected palette probe and keyword/semantic/freshness targets on the production VM. The palette, semantic coverage, write rate, outside-file freshness, and idle Indexer CPU targets remain unmet or unmeasured.
  4. Complete the crash/SIGKILL check after the watcher scan and refresh the Owner session in the adversarial harness.
  5. Keep the collaboration 2-second and menu 5-second timing expectations unchanged; re-evaluate them on a controlled host.

Decisions not specified in DESIGN §32

  • Keep hybrid Search as the default and use an optional semantic=false query flag for keyword-only requests.
  • Wait 80 ms after keyword results before starting hybrid fan-out.
  • Give the adversarial crash-start handshake a 180-second bounded wait under load.
# #258 finish-now report Branch: `job/search-perf-c` Head: `be951e55fbf514cffe78125b8f21ee40fbc23311` Push: `git push origin job/search-perf-c` returned `Everything up-to-date`; `HEAD` and `origin/job/search-perf-c` both resolve to this SHA. ## Built - Extended the Search scale runner and palette probe. The palette samples now use terms that match the corpus and scope long tasks to typing. - Kept an Index searchability regression during a blocked staged rebuild. - Made the Search chaos matcher parse result fields and remove `<b>` highlight wrappers. Extended its bounded crash-start wait to 180 seconds. - Recorded the loaded-host profile and remaining target gaps in `docs/perf/2026-09-28.md`. Job files: `apps/web/e2e/search-scale-palette.mjs`, `crates/calternal-search/tests/indexer.rs`, `docs/perf/2026-09-28.md`, `tests/adversarial/run.sh`, `tests/adversarial/search_chaos.py`, `tests/adversarial/test_search_result_matching.py`, `tests/perf/search_scale.py`. ## Measurements All full profiles below ran on the shared 8-vCPU build host, not the 4-vCPU production VM. Other builds and server jobs were active. - 100k keyword p50 / p95 / p99 ms (post-merge loaded run): plain `20.29 / 60.87 / 97.20`; tag `14.93 / 54.11 / 87.57`; type filter `15.51 / 45.21 / 86.88`; folder `17.93 / 49.78 / 59.56`. Targets were not met in this run. - 1M: the manifest reached `1,001,006` entries for `1,001,003` filesystem paths. A keyword Search request returned HTTP 503 after `30.01 s`; no 1M latency percentile was produced. - Palette typing (loaded run): first-result frame p50 / p95 `183.3 / 712.9 ms`; 7 long tasks over 50 ms, maximum `440 ms`. The corrected query list was committed after that production build, so it has not been measured yet. - Full 100k reindex: `259.23 s`, peak RSS `483,061,760 bytes`, 0 failed Search requests across 194 samples. Concurrent query p50 / p95 / p99 was `258.25 / 833.61 / 3,314.22 ms` under load. - Earlier 100k initial Index: `64.52 s`, peak RSS `462,700,544 bytes`; integrity checked 90,099 Items. The 100k profile does not cover the full mixed corpus target. - Freshness run scheduled 1,000 API writes but reached `84.65 successful writes/min`; 765 succeeded and 255 returned HTTP 429. API freshness p95 / p99 was `850.27 / 1,169.49 ms`; outside-file freshness was `3,980.43 / 4,279.76 ms`. - Semantic indexing previously reached `7,040 / 70,000` paths before the profile ended; its `214.64 ms` warm p95 is incomplete-corpus data. Idle Indexer CPU was not isolated. The prior cross-job adversarial evidence in this issue also records four HTTP 200 Search responses that omitted a committed hit during rebuild, plus a `tz-days` entry that Search did not return within 30 seconds. Those are reliability follow-ups, not load-only latency misses. ## Screenshots Captured from the production web build on a local server. The disposable Home used one Note created through the real Notes API. All six captures are attached to this issue: | Width | Light | Dark | |---|---|---| | Phone 390 px | [phone light](https://git.kayg.org/attachments/12e5554c-0a04-4fb5-a32e-e515c1ea73ad) | [phone dark](https://git.kayg.org/attachments/dec09542-6f3c-4677-9cb6-ec38e76b9cd1) | | Tablet 820 px | [tablet light](https://git.kayg.org/attachments/d079dd27-5027-4f28-811f-a2f4ceed0f87) | [tablet dark](https://git.kayg.org/attachments/9d6b495d-49cb-4407-83b8-22317dfae0ce) | | Desktop 1440 px | [desktop light](https://git.kayg.org/attachments/be0a9cd0-d591-47f4-acec-e06efdb6d7f9) | [desktop dark](https://git.kayg.org/attachments/ec0c8187-676f-438b-acf2-c5e7dc498639) | ## Gates - `cargo fmt --all -- --check`: exit 0; stdout was empty. - `cargo clippy --all-targets -- -D warnings`: ```text Finished `dev` profile [unoptimized + debuginfo] target(s) in 3m 34s ``` The adversarial server build used the vendored OpenSSL configuration. For the final clippy/test checks I used host OpenSSL 3.5.7 with `OPENSSL_NO_VENDOR=1` and a temporary direct-`rustc` wrapper after shared `sccache` tried to use a removed temp directory in another worktree. - `cargo test` stopped at an existing timing assertion in `calternal-collab` (exit 101): ```text 10,000-block collaboration phases: parse=2.219217185s, Yrs=624.775483ms, block-index=20.49739ms, first-sync=29.440246ms (616204 bytes), snapshot=27.317634ms (616199 bytes), total=2.921247938s test session::public_edit_limit_tests::ten_thousand_markdown_blocks_open_and_sync_within_two_seconds ... FAILED test result: FAILED. 14 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 4.24s ``` This is a SLOW-only miss: the existing 2-second expectation remains unchanged. Cargo stopped before later test binaries ran. - `bun run check` in `apps/web` printed: ```text svelte-check found 0 errors and 0 warnings ``` The wrapper pipeline returned 1 because its `tee` path was wrong (`../target/tmp` from `apps/web`); the checker itself reported zero errors and warnings. - `bun run test`: ```text Test Files 1 failed | 109 passed (110) Tests 1 failed | 709 passed (710) ``` The one failure was `menu-open-focus.svelte.test.ts`, which timed out at 5,000 ms. The suite took 277.91 s; this is a SLOW-only shared-host result. - Post-merge Search-only adversarial round exited 1. It wrote 15,000 / 20,000 watcher-overflow files, then timed out waiting 180 seconds for `restart-ready-4`; it reported three Owner passkey refresh failures. No HTTP 5xx was reported, and the SIGKILL check did not run. This round is partial. ## Follow-ups 1. Investigate the HTTP 200 missing-hit cases during concurrent rebuild and add a regression that preserves the hit. 2. Investigate the 1M HTTP 503 / database-pool contention, then record actual 1M latency. 3. Re-run the corrected palette probe and keyword/semantic/freshness targets on the production VM. The palette, semantic coverage, write rate, outside-file freshness, and idle Indexer CPU targets remain unmet or unmeasured. 4. Complete the crash/SIGKILL check after the watcher scan and refresh the Owner session in the adversarial harness. 5. Keep the collaboration 2-second and menu 5-second timing expectations unchanged; re-evaluate them on a controlled host. ## Decisions not specified in DESIGN §32 - Keep hybrid Search as the default and use an optional `semantic=false` query flag for keyword-only requests. - Wait 80 ms after keyword results before starting hybrid fan-out. - Give the adversarial crash-start handshake a 180-second bounded wait under load.
Author
Owner

During the #188 adversarial run at HEAD 9bd81553, the Search semantic-recall probe created the Apartment hunting Note and polled for the query renting a home close to public transport for 120 seconds. The committed Note did not appear in the results within that deadline. This ran after the watcher-overflow fixture and during heavy shared-host load; no cause was established. The Search chaos rebuild misses from the same run are tracked in #362.

During the #188 adversarial run at HEAD 9bd81553, the Search semantic-recall probe created the `Apartment hunting` Note and polled for the query `renting a home close to public transport` for 120 seconds. The committed Note did not appear in the results within that deadline. This ran after the watcher-overflow fixture and during heavy shared-host load; no cause was established. The Search chaos rebuild misses from the same run are tracked in #362.
Author
Owner

Hygiene review: the final report lists missing Search hits during rebuild, a 1M-request 503, unmet or unmeasured palette/semantic/freshness/CPU targets, and an unrun SIGKILL check. Keeping #258 open for those follow-ups.

Hygiene review: the final report lists missing Search hits during rebuild, a 1M-request 503, unmet or unmeasured palette/semantic/freshness/CPU targets, and an unrun SIGKILL check. Keeping #258 open for those follow-ups.
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#258
No description provided.