Server: uploads slow from ~10/s to 0.8/s as a Home grows toward 7,000 files; search indexer burns 30+ CPU-min on 10k small files #122

Closed
opened 2026-09-25 21:00:50 +00:00 by kayg · 8 comments
Owner

Found by job/sync-download (#97) while seeding its benchmark: sequential uploads into one Home slowed from about 10/s to 0.8/s around 7,000 files (something per-upload scales with Home size: listing, reconcile, quota recount or index writes), and the search indexer used over 30 minutes of CPU for 10,000 small text files. Profile both (per-upload work vs Home size; indexer per-document cost and batching) and fix the super-linear parts. Acceptance: upload rate roughly flat to 50k files; indexing 10k small files well under a minute of CPU.

Found by job/sync-download (#97) while seeding its benchmark: sequential uploads into one Home slowed from about 10/s to 0.8/s around 7,000 files (something per-upload scales with Home size: listing, reconcile, quota recount or index writes), and the search indexer used over 30 minutes of CPU for 10,000 small text files. Profile both (per-upload work vs Home size; indexer per-document cost and batching) and fix the super-linear parts. Acceptance: upload rate roughly flat to 50k files; indexing 10k small files well under a minute of CPU.
Author
Owner

Started on branch job/upload-scale at f505a46523, based on dev merge-base 15b1fa63e8. I am reviewing the existing upload and search changes, then I will merge current dev, run the scale benchmark and required gates, and report measured results.

Started on branch job/upload-scale at f505a46523966a211751d043bbb4ed404f6025b2, based on dev merge-base 15b1fa63e8cd7fee362a9067c7fef2e46a8cf1fb. I am reviewing the existing upload and search changes, then I will merge current dev, run the scale benchmark and required gates, and report measured results.
Author
Owner

Merge finding: integrating current dev brought in search's #124 trash/move protections. I kept the upload-scale batching and added current-tree grouping, pre-write revalidation, and live-hit filtering. The first focused compile exposed a duplicate debounce helper and a stale test fixture type after conflict resolution; both are fixed. Focused gate output:

test result: ok. 17 passed; 0 failed; 4 ignored; 0 measured; 0 filtered out; finished in 0.80s
test result: ok. 22 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 1.23s
test result: ok. 14 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 8.88s

Merge finding: integrating current dev brought in search's #124 trash/move protections. I kept the upload-scale batching and added current-tree grouping, pre-write revalidation, and live-hit filtering. The first focused compile exposed a duplicate debounce helper and a stale test fixture type after conflict resolution; both are fixed. Focused gate output: `test result: ok. 17 passed; 0 failed; 4 ignored; 0 measured; 0 filtered out; finished in 0.80s` `test result: ok. 22 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 1.23s` `test result: ok. 14 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 8.88s`
Author
Owner

Baseline finding from the real release server: at 2,032 uploaded files / 4:04 elapsed, calternal-server-before used 53.6% CPU while repeatedly spawning vips thumbnail_source for .txt uploads. Its log reported VipsForeignLoad: source is not in a known format. The semantic queue also reported semantic index queue is full near 1k. These are independent per-upload and indexing-backlog costs; the branch contains text-thumbnail skipping and batched semantic indexing for them. The baseline benchmark is still running for the 5k, 10k and 20k checkpoints.

Baseline finding from the real release server: at 2,032 uploaded files / 4:04 elapsed, `calternal-server-before` used 53.6% CPU while repeatedly spawning `vips thumbnail_source` for `.txt` uploads. Its log reported `VipsForeignLoad: source is not in a known format`. The semantic queue also reported `semantic index queue is full` near 1k. These are independent per-upload and indexing-backlog costs; the branch contains text-thumbnail skipping and batched semantic indexing for them. The baseline benchmark is still running for the 5k, 10k and 20k checkpoints.
Author
Owner

Baseline release measurement on tmpfs, with the exact 16 MiB quota enabled: the final 200 uploads measured 8.58 files/s at 1k (p95 197.19 ms) and 3.62 files/s at 5k (p95 442.47 ms), a 2.37x decline. The server spent 442.2 Tokio worker CPU seconds during the 1k→5k interval. Its log also repeatedly reports that text upload files are not a known image format while invoking thumbnail generation. This supports the observed per-upload costs from media work and growing background indexing, rather than tmpfs write latency.

Baseline release measurement on tmpfs, with the exact 16 MiB quota enabled: the final 200 uploads measured 8.58 files/s at 1k (p95 197.19 ms) and 3.62 files/s at 5k (p95 442.47 ms), a 2.37x decline. The server spent 442.2 Tokio worker CPU seconds during the 1k→5k interval. Its log also repeatedly reports that text upload files are not a known image format while invoking thumbnail generation. This supports the observed per-upload costs from media work and growing background indexing, rather than tmpfs write latency.
Author
Owner

The post-merge release benchmark used the pinned model, tmpfs and the same exact 16 MiB Home quota. It measured 9.89 uploads/s at 1k, then a later upload stalled until the client's 120 s timeout after 4,024 files had landed; the next request was note-004024.txt. The run host had 8 CPUs and load averages of 37.30 / 134.20 / 120.23. Its server log showed SQLite pool acquisition taking 12.37 s, a calendar-account SELECT taking 152.34 s, and semantic vector/LSH inserts taking 39.57 s / 58.48 s. I stopped using this run for scale conclusions because the host was heavily oversubscribed. It did not record 5k/10k/20k checkpoints or a final search probe.

The post-merge release benchmark used the pinned model, tmpfs and the same exact 16 MiB Home quota. It measured 9.89 uploads/s at 1k, then a later upload stalled until the client's 120 s timeout after 4,024 files had landed; the next request was note-004024.txt. The run host had 8 CPUs and load averages of 37.30 / 134.20 / 120.23. Its server log showed SQLite pool acquisition taking 12.37 s, a calendar-account SELECT taking 152.34 s, and semantic vector/LSH inserts taking 39.57 s / 58.48 s. I stopped using this run for scale conclusions because the host was heavily oversubscribed. It did not record 5k/10k/20k checkpoints or a final search probe.
Author
Owner

Source review found three full Home walk_size traversals per quota-backed write: before reading the body, before publication, and again inside install. The final two ran under the same operation mutex and projected the same logical usage; install links replace the upload temp, and a Replace preserves the old bytes as a version. I removed the duplicate final traversal and pass the exact commit-time usage snapshot into install. The existing version quota test now also checks that a rejected replace leaves the exact usage unchanged. This keeps the exact quota check and atomic install path while removing one O(Home size) traversal per upload.

Source review found three full Home `walk_size` traversals per quota-backed write: before reading the body, before publication, and again inside `install`. The final two ran under the same operation mutex and projected the same logical usage; install links replace the upload temp, and a Replace preserves the old bytes as a version. I removed the duplicate final traversal and pass the exact commit-time usage snapshot into `install`. The existing version quota test now also checks that a rejected replace leaves the exact usage unchanged. This keeps the exact quota check and atomic install path while removing one O(Home size) traversal per upload.
Author
Owner

Finished: upload scale

Branch: job/upload-scale
Head: 8784d51cbca7ed035be9c7cabaa21dac71ed2c80 (perf(fs): avoid duplicate quota traversal at install)

Built

  • Reduced Home upload cost as the number of files grows: avoid per-sibling stats, watch only Homes, coalesce filesystem events, ignore read events, and skip unchanged file index updates.
  • Skip thumbnail jobs for text files. Batch and coalesce embedding work; index semantic LSH rows by document and tokenize batches without the prior idle/spin cost.
  • Batch keyword-index updates through one writer, commit at most once per second, and find a subtree by indexed key range.
  • Preserve exact quotas and atomic install. Pass the commit-time usage check into install under the existing operation lock, avoiding a second full tree traversal. A storage regression test checks that a rejected Replace preserves the old file's exact quota usage.
  • Keep partial benchmark checkpoints on disk so a long run retains its latest complete measurement.

Files: crates/calternal-fs/src/{path.rs,write.rs}, crates/calternal-fs/tests/storage.rs, crates/calternal-search/src/{index.rs,indexer.rs}, crates/calternal-search/tests/indexer.rs, crates/calternal-embed/src/{model.rs,store.rs}, crates/calternal-plugin/{Cargo.toml,src/lib.rs}, crates/calternal-server/src/wire.rs, crates/calternal-collab/src/session.rs, crates/plugins/files/src/{index.rs,thumbnails.rs}, tests/perf/upload_scale.py, Cargo.lock.

Benchmark

Rates are files/second; p95 is request latency in milliseconds. All data was on tmpfs. The baseline ran with exact 16 MiB quota and stopped after 5k when throughput had fallen sharply. The completed optimized 20k run used default_quota = 0, before the final dev merge and exact-quota traversal change. These runs are not identical quota conditions.

Files Before: exact quota Optimized complete run: quota disabled Post-merge exact-quota run
1k 8.58/s, p95 197.19 14.71/s, p95 148.26 9.89/s, p95 197.96
5k 3.62/s, p95 442.47 15.77/s, p95 133.39 did not reach checkpoint
10k not measured 10.38/s, p95 203.79 not measured
20k not measured 10.14/s, p95 177.62 not measured

The full optimized run uploaded 20k files in 1,630 seconds, used 742 seconds of server CPU, reached idle, and its final search probe returned HTTP 200 and contained the final file. The keyword search actor used 5.25 CPU seconds over the run. The optimized rate changed from 14.71/s at 1k to 10.14/s at 20k (31% lower). The exact-quota post-merge retry reached 4,024 files before the next request timed out at 120 seconds; the host had 8 CPUs and load averages above 100. A quota-disabled retry also timed out after its 1k checkpoint. I did not treat those loaded-host retries as valid scale measurements.

Baseline evidence at 5k: 7,737 thumbnail errors for text files, 10,285 semantic-queue-full events, and 442.2 seconds of Tokio worker CPU since the 1k checkpoint. The code changes address that background work, repeated per-file/path scanning, and search commit overhead. The final quota change removes one redundant full-tree usage walk while retaining a serialized exact check and atomic publication.

Gates

  • cargo fmt --all --check — exit 0; no output.
  • cargo clippy --all-targets -- -D warnings — exit 0. Verbatim output:
    Finished \dev` profile [unoptimized + debuginfo] target(s) in 3m 20s`
  • cargo test — exit 0; 67 test suites, 1,147 passed, 0 failed, 12 ignored. Verbatim representative output:
    test result: ok. 475 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.13s
    test result: ok. 38 passed; 0 failed; 2 ignored; 0 measured; 0 filtered out; finished in 5.34s
  • tests/adversarial/run.sh — completed on a real local server. Round 1: ==== FINDINGS 0; hostile bytes: ==== HOSTILE BYTES FINDINGS 0; round 2: ==== ROUND 2 FINDINGS 0; restart probe: restart probe: 0 findings.

Decisions and known gaps

  • The design doc did not define a quota-usage handoff between the commit check and install. I reused the existing operation lock: the verified usage remains valid while install replaces the staging entry with the destination, so the check stays exact without another traversal. The regression test covers rejected Replace preservation.
  • The full 20k run had quota disabled. Baseline exact-quota data stops at 5k, and current exact-quota data stops at 4,024 because of shared-host load. A same-condition before/after 20k comparison remains unmeasured.
  • No web source changed, so the web check/test gates were not run; the adversarial script built the production web app.

No push or deploy. The worktree is clean at the reported head.

## Finished: upload scale Branch: `job/upload-scale` Head: `8784d51cbca7ed035be9c7cabaa21dac71ed2c80` (`perf(fs): avoid duplicate quota traversal at install`) ### Built - Reduced Home upload cost as the number of files grows: avoid per-sibling stats, watch only Homes, coalesce filesystem events, ignore read events, and skip unchanged file index updates. - Skip thumbnail jobs for text files. Batch and coalesce embedding work; index semantic LSH rows by document and tokenize batches without the prior idle/spin cost. - Batch keyword-index updates through one writer, commit at most once per second, and find a subtree by indexed key range. - Preserve exact quotas and atomic install. Pass the commit-time usage check into install under the existing operation lock, avoiding a second full tree traversal. A storage regression test checks that a rejected Replace preserves the old file's exact quota usage. - Keep partial benchmark checkpoints on disk so a long run retains its latest complete measurement. Files: `crates/calternal-fs/src/{path.rs,write.rs}`, `crates/calternal-fs/tests/storage.rs`, `crates/calternal-search/src/{index.rs,indexer.rs}`, `crates/calternal-search/tests/indexer.rs`, `crates/calternal-embed/src/{model.rs,store.rs}`, `crates/calternal-plugin/{Cargo.toml,src/lib.rs}`, `crates/calternal-server/src/wire.rs`, `crates/calternal-collab/src/session.rs`, `crates/plugins/files/src/{index.rs,thumbnails.rs}`, `tests/perf/upload_scale.py`, `Cargo.lock`. ### Benchmark Rates are files/second; p95 is request latency in milliseconds. All data was on tmpfs. The baseline ran with exact 16 MiB quota and stopped after 5k when throughput had fallen sharply. The completed optimized 20k run used `default_quota = 0`, before the final dev merge and exact-quota traversal change. These runs are not identical quota conditions. | Files | Before: exact quota | Optimized complete run: quota disabled | Post-merge exact-quota run | |---:|---:|---:|---:| | 1k | 8.58/s, p95 197.19 | 14.71/s, p95 148.26 | 9.89/s, p95 197.96 | | 5k | 3.62/s, p95 442.47 | 15.77/s, p95 133.39 | did not reach checkpoint | | 10k | not measured | 10.38/s, p95 203.79 | not measured | | 20k | not measured | 10.14/s, p95 177.62 | not measured | The full optimized run uploaded 20k files in 1,630 seconds, used 742 seconds of server CPU, reached idle, and its final search probe returned HTTP 200 and contained the final file. The keyword search actor used 5.25 CPU seconds over the run. The optimized rate changed from 14.71/s at 1k to 10.14/s at 20k (31% lower). The exact-quota post-merge retry reached 4,024 files before the next request timed out at 120 seconds; the host had 8 CPUs and load averages above 100. A quota-disabled retry also timed out after its 1k checkpoint. I did not treat those loaded-host retries as valid scale measurements. Baseline evidence at 5k: 7,737 thumbnail errors for text files, 10,285 semantic-queue-full events, and 442.2 seconds of Tokio worker CPU since the 1k checkpoint. The code changes address that background work, repeated per-file/path scanning, and search commit overhead. The final quota change removes one redundant full-tree usage walk while retaining a serialized exact check and atomic publication. ### Gates - `cargo fmt --all --check` — exit 0; no output. - `cargo clippy --all-targets -- -D warnings` — exit 0. Verbatim output: `Finished \`dev\` profile [unoptimized + debuginfo] target(s) in 3m 20s` - `cargo test` — exit 0; 67 test suites, 1,147 passed, 0 failed, 12 ignored. Verbatim representative output: `test result: ok. 475 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.13s` `test result: ok. 38 passed; 0 failed; 2 ignored; 0 measured; 0 filtered out; finished in 5.34s` - `tests/adversarial/run.sh` — completed on a real local server. Round 1: `==== FINDINGS 0`; hostile bytes: `==== HOSTILE BYTES FINDINGS 0`; round 2: `==== ROUND 2 FINDINGS 0`; restart probe: `restart probe: 0 findings`. ### Decisions and known gaps - The design doc did not define a quota-usage handoff between the commit check and install. I reused the existing operation lock: the verified usage remains valid while install replaces the staging entry with the destination, so the check stays exact without another traversal. The regression test covers rejected Replace preservation. - The full 20k run had quota disabled. Baseline exact-quota data stops at 5k, and current exact-quota data stops at 4,024 because of shared-host load. A same-condition before/after 20k comparison remains unmeasured. - No web source changed, so the web check/test gates were not run; the adversarial script built the production web app. No push or deploy. The worktree is clean at the reported head.
kayg referenced this issue from a commit 2026-09-26 13:00:16 +00:00
Author
Owner

Merged into dev (ui-batch 642dfafc / upload-scale b74e772c / tz-days db733d1). Deploy status is tracked on #203.

Merged into dev (ui-batch 642dfafc / upload-scale b74e772c / tz-days db733d1). Deploy status is tracked on #203.
kayg closed this issue 2026-09-26 15:59:54 +00:00
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#122
No description provided.