PERF: Photos full rebuild never finishes in a 1M-file Home (whole-Home row scan before any write)

kayg commented

2026-09-30 08:04:39 +00:00

Owner

Problem

In a large Home, a Photos full rebuild does not finish: the timeline stays empty for the whole run. With 20,000 photos next to 1M other files, photos_media still had 0 rows after 30 min (run 1) and after 35 min (run 2) of rebuild requests. With 5,000 photos in an otherwise empty Home, the same rebuild finishes in about 60 s.

Found by the #367 perf round (perf-test VM, 4 vCPU / 7.7 GiB; release 369ab6a2f; apps/web/e2e/photos-perf.mjs --items 20000 --files 1000000 --notes 100000 --analytics-entries 10000). The startup ordering part (Photos never sees offline-written files) is #470; this issue is the rebuild itself.

Measurements

Home	Rebuild requests (`PUT /api/v1/photos/library-roots`)	Photos in timeline
5k photos only (thumbnail profile)	1 at 0.7 s, 1 at 60 s	5,000 at 63 s
20k photos + 1M files + 100k Notes, run 1	every 60 s from 1,334 s to 3,280 s	0
same, run 2	at 740 s, 1,940 s, 2,814 s	0

perf during run 1 (10 s): top Photos frame hashbrown::HashMap<String,…>::insert in calternal_plugin_photos (1.0%), sqlite3VdbeExec 6.3%, substrFunc 1.0%; the rest of the CPU was ONNX embedding and Notes reconcile running at the same time.

Why (to confirm)

refresh_user_if_changed (crates/plugins/photos/src/index.rs ~line 762) streams every files_index row under each root. With the default root "" (whole Home) that is 1.1M rows, each with a LEFT JOIN files_index x ON x.path = f.path || '.xmp', and it inserts every (owner_id, item_id) into a HashSet before filtering by is_photo_path. Only after the whole scan does it write, in one transaction, so no photo appears until the pass ends. Each library-root change queues another full pass behind refresh_lock.

Suggested direction (not decided)

Filter media in SQL (by MIME or extension) before the join, drop the visited set for non-media rows, and commit in bounded batches so the timeline fills while the pass runs. Coalesce queued rebuilds for the same viewer.

Raw: docs/perf/runs/2026-09-29T224501Z-369ab6a2/raw/large-home.uptime.txt; VM profiles profiles/lh-*.top.txt.

## Problem In a large Home, a Photos full rebuild does not finish: the timeline stays empty for the whole run. With 20,000 photos next to 1M other files, `photos_media` still had **0 rows after 30 min (run 1) and after 35 min (run 2)** of rebuild requests. With 5,000 photos in an otherwise empty Home, the same rebuild finishes in about 60 s. Found by the #367 perf round (perf-test VM, 4 vCPU / 7.7 GiB; release `369ab6a2f`; `apps/web/e2e/photos-perf.mjs --items 20000 --files 1000000 --notes 100000 --analytics-entries 10000`). The startup ordering part (Photos never sees offline-written files) is #470; this issue is the rebuild itself. ## Measurements | Home | Rebuild requests (`PUT /api/v1/photos/library-roots`) | Photos in timeline | |---|---|---:| | 5k photos only (thumbnail profile) | 1 at 0.7 s, 1 at 60 s | 5,000 at 63 s | | 20k photos + 1M files + 100k Notes, run 1 | every 60 s from 1,334 s to 3,280 s | 0 | | same, run 2 | at 740 s, 1,940 s, 2,814 s | 0 | `perf` during run 1 (10 s): top Photos frame `hashbrown::HashMap<String,…>::insert` in `calternal_plugin_photos` (1.0%), `sqlite3VdbeExec` 6.3%, `substrFunc` 1.0%; the rest of the CPU was ONNX embedding and Notes reconcile running at the same time. ## Why (to confirm) `refresh_user_if_changed` (`crates/plugins/photos/src/index.rs` ~line 762) streams **every** `files_index` row under each root. With the default root `""` (whole Home) that is 1.1M rows, each with a `LEFT JOIN files_index x ON x.path = f.path || '.xmp'`, and it inserts every `(owner_id, item_id)` into a `HashSet` before filtering by `is_photo_path`. Only after the whole scan does it write, in one transaction, so no photo appears until the pass ends. Each library-root change queues another full pass behind `refresh_lock`. ## Suggested direction (not decided) Filter media in SQL (by MIME or extension) before the join, drop the `visited` set for non-media rows, and commit in bounded batches so the timeline fills while the pass runs. Coalesce queued rebuilds for the same viewer. Raw: `docs/perf/runs/2026-09-29T224501Z-369ab6a2/raw/large-home.uptime.txt`; VM profiles `profiles/lh-*.top.txt`.

kayg referenced this issue

2026-09-30 08:44:27 +00:00

PERF: a 1M-file Home drives the server to 6.65 GB RSS on a 7.7 GiB host (Search maps, two ONNX models, SQLite) #503

kayg referenced this issue

2026-09-30 08:46:05 +00:00

PERF ROUND: benchmark + optimise average and worst-case CPU/memory (after current merges) #367

kayg commented

2026-09-30 20:46:28 +00:00

Author

Owner

Starting #495 on job/perf-495, based on 6c87f5ff94. The issue reports 0 Photos rows after 30 and 35 minutes for 20k Photos in a Home with 1M other files. I am tracing the full rebuild and will add a bounded, resumable regression probe.

Starting #495 on job/perf-495, based on 6c87f5ff9442cd658572139bc536d018fd5222a. The issue reports 0 Photos rows after 30 and 35 minutes for 20k Photos in a Home with 1M other files. I am tracing the full rebuild and will add a bounded, resumable regression probe.

kayg commented

2026-09-30 20:58:01 +00:00

Author

Owner

Confirmed in crates/plugins/photos/src/index.rs::refresh_user_if_changed (current HEAD 15e17aeaf): for each active root, the query joins every files_index row to photos_media and the .xmp Files row; Rust then records each identity in visited before calling is_photo_path. The pass retains full items and records vectors and writes only after the scan completes.

Decision for the part DESIGN does not specify: keep the existing incremental grouping logic and call it per 128-candidate page. Persist the (owner_id, path) cursor plus seen item identities in Photos-owned rebuild tables; after the scan, remove rows not seen. Add narrow partial Files Indexes for image/video MIME and RAW extensions so the candidate scan does not walk non-media rows. A second rebuild request during an active pass will coalesce into one follow-up pass. I will add a regression test for first-page writes and resume, then run the #367 20k Photos + 1M Files profile.

Confirmed in crates/plugins/photos/src/index.rs::refresh_user_if_changed (current HEAD 15e17aeaf): for each active root, the query joins every files_index row to photos_media and the `.xmp` Files row; Rust then records each identity in `visited` before calling `is_photo_path`. The pass retains full `items` and `records` vectors and writes only after the scan completes. Decision for the part DESIGN does not specify: keep the existing incremental grouping logic and call it per 128-candidate page. Persist the `(owner_id, path)` cursor plus seen item identities in Photos-owned rebuild tables; after the scan, remove rows not seen. Add narrow partial Files Indexes for image/video MIME and RAW extensions so the candidate scan does not walk non-media rows. A second rebuild request during an active pass will coalesce into one follow-up pass. I will add a regression test for first-page writes and resume, then run the #367 20k Photos + 1M Files profile.

kayg commented

2026-09-30 21:34:52 +00:00

Author

Owner

The first Files test run completed with 134 passed and 2 failed because migration 0016 changed the current migration-set length: cursor_migration_preserves_retained_positions_and_floors saw version 16 where its historical setup expected the last version to be 15, and internal_temp_repair_cleans_derived_rows_and_compensates_published_paths saw 15 where it expected 14. I updated only the migration-prefix setup to pop versions 16 and 15 before creating the same legacy database states. The assertions on feed retention and temporary-path repair are unchanged.

The first Files test run completed with 134 passed and 2 failed because migration 0016 changed the current migration-set length: `cursor_migration_preserves_retained_positions_and_floors` saw version 16 where its historical setup expected the last version to be 15, and `internal_temp_repair_cleans_derived_rows_and_compensates_published_paths` saw 15 where it expected 14. I updated only the migration-prefix setup to pop versions 16 and 15 before creating the same legacy database states. The assertions on feed retention and temporary-path repair are unchanged.

kayg commented

2026-09-30 21:48:05 +00:00

Author

Owner

Photos Clippy caught two imports left behind by the streaming rewrite and one nested conditional (cargo clippy -p calternal-plugin-photos --all-targets -- -D warnings). I removed the imports and collapsed the conditional; rerunning the Photos gates now.

Photos Clippy caught two imports left behind by the streaming rewrite and one nested conditional (`cargo clippy -p calternal-plugin-photos --all-targets -- -D warnings`). I removed the imports and collapsed the conditional; rerunning the Photos gates now.

kayg commented

2026-09-30 22:58:52 +00:00

Author

Owner

The first locked 1M perf run exposed a rebuild starvation path in the new scanner. The probe requested a Home-root rebuild at 677s, then alternated roots at roughly 60s intervals; after two root changes the timeline still had 0 Photos. refresh_user_if_changed_with_batch_limit re-reads the root signature for every candidate page, and photo_rebuild_cursor clears the durable seen set when that signature changes. The scanner therefore restarts instead of finishing the active pass. I am stopping this run, pinning the root snapshot for each pass, and will rerun the same 1M profile.

The first locked 1M perf run exposed a rebuild starvation path in the new scanner. The probe requested a Home-root rebuild at 677s, then alternated roots at roughly 60s intervals; after two root changes the timeline still had 0 Photos. `refresh_user_if_changed_with_batch_limit` re-reads the root signature for every candidate page, and `photo_rebuild_cursor` clears the durable seen set when that signature changes. The scanner therefore restarts instead of finishing the active pass. I am stopping this run, pinning the root snapshot for each pass, and will rerun the same 1M profile.

kayg commented

2026-09-30 23:07:11 +00:00

Author

Owner

Photos Clippy found four needless borrows after the fixed-root helper was factored out (two calls into current-item lookup and two group-root lookups). I removed those references; cargo clippy -p calternal-plugin-photos --all-targets -- -D warnings passes.

Photos Clippy found four needless borrows after the fixed-root helper was factored out (two calls into current-item lookup and two group-root lookups). I removed those references; `cargo clippy -p calternal-plugin-photos --all-targets -- -D warnings` passes.

kayg commented

2026-09-30 23:12:17 +00:00

Author

Owner

Update to the first locked perf VM run: it seeded the exact 20k Photos + 1M Files + 100k Notes + 10k Analytics workload. After the first Home rebuild request at 677s, Photos reached 768/20,000 at 972s (295s after that request), while the probe continued switching roots every ~60s. I stopped it at 17m57s total to fix the signature reset; uptime inside the lock at stop reported load averages 8.89, 7.24, 5.19. This run is not the before/after result; the corrected fixed-snapshot build will be measured next.

Update to the first locked perf VM run: it seeded the exact 20k Photos + 1M Files + 100k Notes + 10k Analytics workload. After the first Home rebuild request at 677s, Photos reached 768/20,000 at 972s (295s after that request), while the probe continued switching roots every ~60s. I stopped it at 17m57s total to fix the signature reset; `uptime` inside the lock at stop reported load averages 8.89, 7.24, 5.19. This run is not the before/after result; the corrected fixed-snapshot build will be measured next.

kayg commented

2026-09-30 23:15:40 +00:00

Author

Owner

Fixed the root-change starvation in commit 67a654e3e: one rebuild pass pins its roots and timezone, commits bounded pages under that snapshot, and returns to the coalescing worker when the configured signature changes. The worker then processes the latest snapshot. The regression changes Alice's root after page 1 and verifies the cursor advances to page 2 before restart/resume.

Gate results for Photos after the fix: cargo fmt --all -- --check passed; cargo clippy -p calternal-plugin-photos --all-targets -- -D warnings passed; cargo test -p calternal-plugin-photos passed (46 passed, 2 ignored). Rebuilding the release artifact for the corrected 1M run now.

Fixed the root-change starvation in commit `67a654e3e`: one rebuild pass pins its roots and timezone, commits bounded pages under that snapshot, and returns to the coalescing worker when the configured signature changes. The worker then processes the latest snapshot. The regression changes Alice's root after page 1 and verifies the cursor advances to page 2 before restart/resume. Gate results for Photos after the fix: `cargo fmt --all -- --check` passed; `cargo clippy -p calternal-plugin-photos --all-targets -- -D warnings` passed; `cargo test -p calternal-plugin-photos` passed (46 passed, 2 ignored). Rebuilding the release artifact for the corrected 1M run now.

kayg commented

2026-09-30 23:47:13 +00:00

Author

Owner

Corrected 1M profile status on 67a654e3e: at 20m18s the startup API still reports 5,000/5,000 folder items, 100,001/100,001 Notes, and 0/995,000 rest Files, so the Photos rebuild has not been requested. The earlier run adopted Files at about 11m17s. During this locked run the perf VM load average was 7.37, 7.19, 6.07; the profile server used 46m38s CPU and 3.9 GB RSS after 19m19s. I am continuing this single run within its 3,600s startup bound; no code conclusion follows until the Photos phase runs.

Corrected 1M profile status on `67a654e3e`: at 20m18s the startup API still reports 5,000/5,000 folder items, 100,001/100,001 Notes, and 0/995,000 rest Files, so the Photos rebuild has not been requested. The earlier run adopted Files at about 11m17s. During this locked run the perf VM load average was 7.37, 7.19, 6.07; the profile server used 46m38s CPU and 3.9 GB RSS after 19m19s. I am continuing this single run within its 3,600s startup bound; no code conclusion follows until the Photos phase runs.

kayg commented

2026-10-01 00:04:55 +00:00

Author

Owner

I found a readiness gap in the 1M profile. At 34m the Files and Notes counters had reached their expected totals, but the Files Index had 0 image/video candidates while the User's Home contained all 20,000 generated JPG files; files_folder_reconcile still showed Photos at generation 1 / reconciled generation 0. The profile requested its first Photos rebuild at 26m52s, before Files had adopted the Photos tree. I am extending the profile readiness check to wait for those media rows so the 1M timing measures a completed library rebuild. The existing locked run remains active and may start the scan when the Photos rows arrive.

I found a readiness gap in the 1M profile. At 34m the Files and Notes counters had reached their expected totals, but the Files Index had 0 image/video candidates while the User's Home contained all 20,000 generated JPG files; `files_folder_reconcile` still showed `Photos` at generation 1 / reconciled generation 0. The profile requested its first Photos rebuild at 26m52s, before Files had adopted the Photos tree. I am extending the profile readiness check to wait for those media rows so the 1M timing measures a completed library rebuild. The existing locked run remains active and may start the scan when the Photos rows arrive.

kayg commented

2026-10-01 00:51:11 +00:00

Author

Owner

Completed the implementation on job/perf-495. HEAD: 29b261a60bcb97d41a1d0b63f66e38a0450a603a.

Built: Photos rebuilds now read media candidates from matching Files partial indexes in 128-row keyset pages. Each page updates Photos rows and groups before it saves the cursor and seen IDs, so a restart replays at most one page. The scan pins its roots and timezone; root edits coalesce into one follow-up pass and cannot starve the active scan. Stale Photos rows are removed in bounded batches after the candidate scan. Added restart and root-change regression coverage. The large-Home profile now waits for the Files Index to contain every generated image before requesting a rebuild.

Files changed: crates/plugins/photos/src/index.rs, crates/plugins/photos/src/lib.rs, crates/plugins/photos/migrations/0007_resumable_rebuild.sql, crates/plugins/files/src/lib.rs, crates/plugins/files/migrations/0016_photo_media_scan.sql, apps/web/e2e/photos-perf.mjs, bench/run.sh.

Gates:

cargo fmt --all -- --check: passed, exit 0, no output.

cargo clippy -p calternal-plugin-files --all-targets -- -D warnings:

    Checking calternal-plugin-files v0.0.1 (/home/kayg/Developer/calternal-wt/perf-495/crates/plugins/files)
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 28.21s

cargo test -p calternal-plugin-files:

test result: ok. 136 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 168.91s
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

cargo clippy -p calternal-plugin-photos --all-targets -- -D warnings:

    Checking calternal-plugin-photos v0.0.1 (/home/kayg/Developer/calternal-wt/perf-495/crates/plugins/photos)
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 28.86s

cargo test -p calternal-plugin-photos:

test result: ok. 46 passed; 0 failed; 2 ignored; 0 measured; 0 filtered out; finished in 12.21s
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

bun run check:

$ node scripts/check-type-tokens.mjs && node scripts/check-motion-tokens.mjs && svelte-kit sync && svelte-check --tsconfig ./tsconfig.json
Text sizes and UI shape values use shared role tokens.
UI transitions and animation options use shared motion tokens or documented exceptions.
Loading svelte-check in workspace: /home/kayg/Developer/calternal-wt/perf-495/apps/web
Getting Svelte diagnostics...

svelte-check found 0 errors and 0 warnings

bun run test:

 Test Files  140 passed (140)
      Tests  914 passed (914)
   Start at  02:08:40
   Duration  252.51s (transform 50%, environment 20%, import 15%, tests 10%, setup 4%)

node --check apps/web/e2e/photos-perf.mjs: passed, exit 0, no output.
cargo clean:
```
     Removed 17901 files, 7.0GiB total
```

1M measurement: the issue baseline is 0/20,000 timeline Photos after 30 and 35 minutes. The locked run used 20,000 Photos, 1,000,000 Files, 100,000 Notes and 10,000 Analytics Log entries. It reached 5,000 folder items, 995,000 rest Files and 100,001 Notes, but the Files Index still had zero image candidates; the physical Photos fixture existed while its Photos folder reconciliation remained unfinished. At the 60-minute profile limit the run failed with AssertionError: every photo is in the timeline (0/20000), before a Photos rebuild could be measured. VM load average inside the lock was 2.25, 2.17, 2.56 at start and 4.69, 6.59, 6.88 at exit. Thus this run provides no valid before/after Photos rebuild timing. Commit 29b261a60 adds the image-row readiness check, but that corrected profile has not been rerun.

Adversarial round: the real-server runner exited 1. It found that the Search rebuild probe expects HTTP 200 while the route documents and returns HTTP 202; filed #561. The fresh test Users also received HTTP 403 API is disabled in Settings → Apps from Files, Appearance and Tasks probes because their required per-User Plugins were not enabled; filed #562. The Photos-specific hostile-input probe was not reached with an active Photos fixture.

Decisions not specified in DESIGN: use 128 candidate rows per durable batch; pin a root/timezone snapshot and run one coalesced follow-up after a setting change; require all generated image/* rows before starting the performance timing. These choices are recorded in code comments and the benchmark helper.

Known gaps: the 1M Photos completion timing is unproven because Files did not adopt the Photos tree within the profile bound. The broad adversarial pass needs the setup/probe corrections tracked in #561 and #562 before it can validate those APIs. No issue was closed.

Completed the implementation on `job/perf-495`. HEAD: `29b261a60bcb97d41a1d0b63f66e38a0450a603a`. Built: Photos rebuilds now read media candidates from matching Files partial indexes in 128-row keyset pages. Each page updates Photos rows and groups before it saves the cursor and seen IDs, so a restart replays at most one page. The scan pins its roots and timezone; root edits coalesce into one follow-up pass and cannot starve the active scan. Stale Photos rows are removed in bounded batches after the candidate scan. Added restart and root-change regression coverage. The large-Home profile now waits for the Files Index to contain every generated image before requesting a rebuild. Files changed: `crates/plugins/photos/src/index.rs`, `crates/plugins/photos/src/lib.rs`, `crates/plugins/photos/migrations/0007_resumable_rebuild.sql`, `crates/plugins/files/src/lib.rs`, `crates/plugins/files/migrations/0016_photo_media_scan.sql`, `apps/web/e2e/photos-perf.mjs`, `bench/run.sh`. Gates: - `cargo fmt --all -- --check`: passed, exit 0, no output. - `cargo clippy -p calternal-plugin-files --all-targets -- -D warnings`: ``` Checking calternal-plugin-files v0.0.1 (/home/kayg/Developer/calternal-wt/perf-495/crates/plugins/files) Finished `dev` profile [unoptimized + debuginfo] target(s) in 28.21s ``` - `cargo test -p calternal-plugin-files`: ``` test result: ok. 136 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 168.91s test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s ``` - `cargo clippy -p calternal-plugin-photos --all-targets -- -D warnings`: ``` Checking calternal-plugin-photos v0.0.1 (/home/kayg/Developer/calternal-wt/perf-495/crates/plugins/photos) Finished `dev` profile [unoptimized + debuginfo] target(s) in 28.86s ``` - `cargo test -p calternal-plugin-photos`: ``` test result: ok. 46 passed; 0 failed; 2 ignored; 0 measured; 0 filtered out; finished in 12.21s test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s ``` - `bun run check`: ``` $ node scripts/check-type-tokens.mjs && node scripts/check-motion-tokens.mjs && svelte-kit sync && svelte-check --tsconfig ./tsconfig.json Text sizes and UI shape values use shared role tokens. UI transitions and animation options use shared motion tokens or documented exceptions. Loading svelte-check in workspace: /home/kayg/Developer/calternal-wt/perf-495/apps/web Getting Svelte diagnostics... svelte-check found 0 errors and 0 warnings ``` - `bun run test`: ``` Test Files 140 passed (140) Tests 914 passed (914) Start at 02:08:40 Duration 252.51s (transform 50%, environment 20%, import 15%, tests 10%, setup 4%) ``` - `node --check apps/web/e2e/photos-perf.mjs`: passed, exit 0, no output. - `cargo clean`: ``` Removed 17901 files, 7.0GiB total ``` 1M measurement: the issue baseline is 0/20,000 timeline Photos after 30 and 35 minutes. The locked run used 20,000 Photos, 1,000,000 Files, 100,000 Notes and 10,000 Analytics Log entries. It reached 5,000 folder items, 995,000 rest Files and 100,001 Notes, but the Files Index still had zero image candidates; the physical Photos fixture existed while its `Photos` folder reconciliation remained unfinished. At the 60-minute profile limit the run failed with `AssertionError: every photo is in the timeline (0/20000)`, before a Photos rebuild could be measured. VM load average inside the lock was `2.25, 2.17, 2.56` at start and `4.69, 6.59, 6.88` at exit. Thus this run provides no valid before/after Photos rebuild timing. Commit `29b261a60` adds the image-row readiness check, but that corrected profile has not been rerun. Adversarial round: the real-server runner exited 1. It found that the Search rebuild probe expects HTTP 200 while the route documents and returns HTTP 202; filed #561. The fresh test Users also received HTTP 403 `API is disabled in Settings → Apps` from Files, Appearance and Tasks probes because their required per-User Plugins were not enabled; filed #562. The Photos-specific hostile-input probe was not reached with an active Photos fixture. Decisions not specified in DESIGN: use 128 candidate rows per durable batch; pin a root/timezone snapshot and run one coalesced follow-up after a setting change; require all generated `image/*` rows before starting the performance timing. These choices are recorded in code comments and the benchmark helper. Known gaps: the 1M Photos completion timing is unproven because Files did not adopt the Photos tree within the profile bound. The broad adversarial pass needs the setup/probe corrections tracked in #561 and #562 before it can validate those APIs. No issue was closed.

kayg referenced this issue

2026-10-01 02:59:40 +00:00

PERF: verification batch on the perf VM for finished branches (#498 #423 #494 #527 #530) #563

kayg commented

2026-10-01 07:15:12 +00:00

Author

Owner

Round 2 started on branch job/perf-495 at 29b261a607; base is 15e17aeafc (origin/dev SHA 15e17aeafc). I will rerun the locked 1M profile with the Photos-fixture readiness gate and report Files Index adoption, Photos rebuild, peak RSS, and SQLite WAL size separately.

Round 2 started on branch job/perf-495 at 29b261a607acd0bc6798733b489b0486e3df79c2; base is 15e17aeafc8ea160c109e62fba57f6961c39d21f (origin/dev SHA 15e17aeafc8ea160c109e62fba57f6961c39d21f). I will rerun the locked 1M profile with the Photos-fixture readiness gate and report Files Index adoption, Photos rebuild, peak RSS, and SQLite WAL size separately.

kayg commented

2026-10-01 07:53:31 +00:00

Author

Owner

Round 2 checkpoint (2026-10-01, perf VM, lock held): 20 minutes after the server started indexing, the Files API still reports 0/5,000 folder Items, 0/995,000 remaining Files, 0/100,001 Notes, and the Photos readiness query reports 0/20,000 image candidates. A read-only query of .system/index.sqlite shows five files_index rows total (.calternal, Documents, Notes, Photos, Photos/Backgrounds) and two unreconciled folders. The server was alive at about 3.0 GiB RSS; WAL was 4.56 MiB. No Photos rebuild request has been sent because the readiness gate is not satisfied. I will start the one-minute syscall profile only if Files adoption is still incomplete at 30 minutes, then continue the 1M run within its three-hour cap.

Round 2 checkpoint (2026-10-01, perf VM, lock held): 20 minutes after the server started indexing, the Files API still reports 0/5,000 folder Items, 0/995,000 remaining Files, 0/100,001 Notes, and the Photos readiness query reports 0/20,000 image candidates. A read-only query of `.system/index.sqlite` shows five `files_index` rows total (`.calternal`, `Documents`, `Notes`, `Photos`, `Photos/Backgrounds`) and two unreconciled folders. The server was alive at about 3.0 GiB RSS; WAL was 4.56 MiB. No Photos rebuild request has been sent because the readiness gate is not satisfied. I will start the one-minute syscall profile only if Files adoption is still incomplete at 30 minutes, then continue the 1M run within its three-hour cap.

kayg commented

2026-10-01 07:56:54 +00:00

Author

Owner

Round 2 checkpoint (2026-10-01, locked perf VM): at 1,383.3 s after profile server start, the Files API reports all 995,000 Files/Bench/rest entries, but 0/5,000 Files/Bench/5k-folder entries. Notes remain 0/100,001 and the Files Index has 0/20,000 generated image candidates. The profile has not sent a Photos rebuild request because the full readiness condition is not met. This is not yet the completion time for the 1M Files dataset.

Round 2 checkpoint (2026-10-01, locked perf VM): at 1,383.3 s after profile server start, the Files API reports all 995,000 `Files/Bench/rest` entries, but 0/5,000 `Files/Bench/5k-folder` entries. Notes remain 0/100,001 and the Files Index has 0/20,000 generated image candidates. The profile has not sent a Photos rebuild request because the full readiness condition is not met. This is not yet the completion time for the 1M Files dataset.

kayg commented

2026-10-01 07:58:59 +00:00

Author

Owner

Round 2 checkpoint (2026-10-01, locked perf VM): at 1,537.6 s after the monitor started, the direct SQLite count for Files/Bench/5k-folder + Files/Bench/rest reached 1,000,000 rows (the monitor saw 1,000,000 at 07:57:41 UTC; server readiness was later than monitor start). At that point, the profile API still reported 995,000 rest Items and 0/5,000 folder Items; the image candidate count was 0/20,000, so no Photos rebuild had been requested. During the Files write, the observed SQLite WAL reached 2,285,590,632 bytes (2.13 GiB) and process RSS reached 3,606,424 KiB (3.44 GiB). The 1M Files dataset adoption remains below the 30-minute issue threshold; full profile readiness is still pending on other Home folders.

Round 2 checkpoint (2026-10-01, locked perf VM): at 1,537.6 s after the monitor started, the direct SQLite count for `Files/Bench/5k-folder` + `Files/Bench/rest` reached 1,000,000 rows (the monitor saw 1,000,000 at 07:57:41 UTC; server readiness was later than monitor start). At that point, the profile API still reported 995,000 rest Items and 0/5,000 folder Items; the image candidate count was 0/20,000, so no Photos rebuild had been requested. During the Files write, the observed SQLite WAL reached 2,285,590,632 bytes (2.13 GiB) and process RSS reached 3,606,424 KiB (3.44 GiB). The 1M Files dataset adoption remains below the 30-minute issue threshold; full profile readiness is still pending on other Home folders.

kayg referenced this issue

2026-10-01 08:01:26 +00:00

PHOTOS: feature parity with Immich (gap audit, then grill; no build before the grill) #592

kayg commented

2026-10-01 08:09:52 +00:00

Author

Owner

Round 2 checkpoint (2026-10-01, locked perf VM): the Index had all 1,000,000 Files/Bench file rows by 07:57:41 UTC (observer samples every 5 s). The Files API first reported 5,000 folder + 995,000 rest Items at 1,513.7 s after the index server start. At 2,042.5 s (34m02s), it still reported 0/20,000 image candidates and 0 Photos timeline rows, so the readiness gate had not sent a Photos rebuild request.

The observed peak around the 995,000-row folder write was 3,606,424 KiB RSS and 2,285,590,632 bytes (2.13 GiB) in index.sqlite-wal. A 60 s strace -f -c sample at about 31m showed 1,325,577 futex calls (83.55% of aggregate traced syscall time), 318,201 epoll_wait calls (11.28%), 104,944 openat2, 104,965 fstat, 90,808 pwrite64, and 56 fsync calls. Load average inside the held lock was 6.99/7.09/6.28 before and 7.12/7.14/6.35 after the sample. The trace covers the server and its worker threads, not only Files.

Files source inspection: write_records uses 64-row multi-value statements in one transaction for a changed folder; the 995,000-row rest folder therefore uses about 15,547 statements in one transaction. At the trace checkpoint, the durable folder reconcile table had two unreconciled folders (Home and Photos); it does not expose an in-memory watcher queue length. No Files change was made.

Round 2 checkpoint (2026-10-01, locked perf VM): the Index had all 1,000,000 `Files/Bench` file rows by 07:57:41 UTC (observer samples every 5 s). The Files API first reported 5,000 folder + 995,000 rest Items at 1,513.7 s after the index server start. At 2,042.5 s (34m02s), it still reported 0/20,000 image candidates and 0 Photos timeline rows, so the readiness gate had not sent a Photos rebuild request. The observed peak around the 995,000-row folder write was 3,606,424 KiB RSS and 2,285,590,632 bytes (2.13 GiB) in `index.sqlite-wal`. A 60 s `strace -f -c` sample at about 31m showed 1,325,577 `futex` calls (83.55% of aggregate traced syscall time), 318,201 `epoll_wait` calls (11.28%), 104,944 `openat2`, 104,965 `fstat`, 90,808 `pwrite64`, and 56 `fsync` calls. Load average inside the held lock was 6.99/7.09/6.28 before and 7.12/7.14/6.35 after the sample. The trace covers the server and its worker threads, not only Files. Files source inspection: `write_records` uses 64-row multi-value statements in one transaction for a changed folder; the 995,000-row `rest` folder therefore uses about 15,547 statements in one transaction. At the trace checkpoint, the durable folder reconcile table had two unreconciled folders (`Home` and `Photos`); it does not expose an in-memory watcher queue length. No Files change was made.

kayg commented

2026-10-01 08:11:40 +00:00

Author

Owner

Round 2 checkpoint (2026-10-01, locked perf VM): at 2,243.2 s after the index server start, the Files API still reports 5,000/5,000 folder Items, 995,000/995,000 rest Items and 100,001/100,001 Notes. The Files Index media-candidate query remains 0/20,000, and the Photos timeline remains 0/20,000. The image-candidate adoption delay has now passed 37 minutes; the one-minute syscall profile from ~31m is in the prior comment. The 1M Files/Bench dataset itself was API-ready before 30 minutes.

Round 2 checkpoint (2026-10-01, locked perf VM): at 2,243.2 s after the index server start, the Files API still reports 5,000/5,000 folder Items, 995,000/995,000 rest Items and 100,001/100,001 Notes. The Files Index media-candidate query remains 0/20,000, and the Photos timeline remains 0/20,000. The image-candidate adoption delay has now passed 37 minutes; the one-minute syscall profile from ~31m is in the prior comment. The 1M `Files/Bench` dataset itself was API-ready before 30 minutes.

kayg commented

2026-10-01 08:19:09 +00:00

Author

Owner

Round 2 checkpoint (2026-10-01, locked perf VM): at 2,731.9 s after the index server start, Files and Notes API totals remain complete, but the Files Index image-candidate count is still 0/20,000 and Photos timeline is 0/20,000. The monitor reports 3,780,648 KiB RSS, 2,285,714,232 bytes (2.13 GiB) WAL, and two unreconciled folders. The Photos rebuild has not started.

kayg commented

2026-10-01 08:34:04 +00:00

Author

Owner

Round 2 one-hour checkpoint (2026-10-01, locked perf VM): the 1M Files/Bench dataset was first present in the Files API at 1,513.7 s after the index server started (the observer first saw all 1,000,000 direct Index rows at 07:57:41 UTC). This was under 30 minutes. At 3,625.0 s, Files and Notes API totals remain complete, but the Files Index still reports 0/20,000 generated image candidates and the Photos timeline remains 0/20,000. The Photos readiness gate has sent no library-root update, so the rebuild phase has not begun. Latest observed process RSS is about 3.59 GiB and the WAL is about 2.13 GiB. No Files code was changed; the 60 s syscall sample and batch-size evidence are in the prior checkpoint.

Round 2 one-hour checkpoint (2026-10-01, locked perf VM): the 1M `Files/Bench` dataset was first present in the Files API at 1,513.7 s after the index server started (the observer first saw all 1,000,000 direct Index rows at 07:57:41 UTC). This was under 30 minutes. At 3,625.0 s, Files and Notes API totals remain complete, but the Files Index still reports 0/20,000 generated image candidates and the Photos timeline remains 0/20,000. The Photos readiness gate has sent no library-root update, so the rebuild phase has not begun. Latest observed process RSS is about 3.59 GiB and the WAL is about 2.13 GiB. No Files code was changed; the 60 s syscall sample and batch-size evidence are in the prior checkpoint.

kayg referenced this issue

2026-10-01 10:01:33 +00:00

PERF: verification batch on the perf VM for finished branches (#498 #423 #494 #527 #530) #563

kayg commented

2026-10-01 10:50:22 +00:00

Author

Owner

Round 2 — locked 1M profile result

Run: normal SSD, lock held with flock /root/perf.lock; 3-hour timeout. Load average inside the lock was 0.00, 0.46, 0.83 at start and 5.24, 6.52, 6.74 at release. The monitor sampled once per second and wrote 10,393 samples.

Phase	Duration	Peak RSS	Peak SQLite WAL	Result
Files Index adoption	1,424.73 s (23m44.73s), 07:33:35–07:57:20 UTC	4,127,072 KiB	2,284,614,192 bytes	First sampled count of 1,000,000 Files Index rows. The profile has 995,000 entries under `Files/Bench/rest` and 5,000 in the nested folder.
Photos rebuild	Not reached	N/A	N/A	Readiness stayed at 0/20,000 Photo file candidates, 0 `photos_media` rows, and timeline 0/20,000. No rebuild request was sent.
Wait after Files adoption to timeout	2h34m43s	4,664,268 KiB at 10:28:03 UTC	2,285,714,232 bytes at 10:32:03 UTC	Photos candidates remained absent through the 3-hour timeout. These are wait-phase peaks, not Photos rebuild measurements.

The durable folder-reconcile backlog peaked at 3 and was 2 at timeout (Home and Photos). The 1M Files adoption time is below the 30-minute trigger, so I did not file a separate Files PERF issue. The repeated missing Photo-candidate adoption remains the finding on #495. This run did not reach a Photos rebuild, so it does not prove a Photos rebuild defect. The timeout ended with profile_exit=137; the final large-home.json was not produced. Monitor and log artifacts remain in the perf VM run directory target/tmp/perf495-round2-20261001T073203Z/.

Gates (after merging origin/dev once):

cargo fmt --check: exit 0; no output.

cargo clippy -p calternal-plugin-files --all-targets -- -D warnings:

Finished `dev` profile [unoptimized + debuginfo] target(s) in 2m 01s

cargo clippy -p calternal-plugin-photos --all-targets -- -D warnings:

Finished `dev` profile [unoptimized + debuginfo] target(s) in 4m 51s

Initial cargo test -p calternal-plugin-files output:
```
test result: FAILED. 144 passed; 2 failed; 1 ignored; 0 measured; 0 filtered out; finished in 340.61s
```
The migration test expected max version 18, while migration 19 is required because origin/dev uses Files migrations 16–18. I updated that expected version to 19; the focused test then passed:
```
test tests::dev_files_schema_upgrades_through_share_log_and_sidecar_migrations ... ok
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 146 filtered out; finished in 1.36s
```
The other failure was internal_temp_paths_never_enter_index_during_atomic_write_reconcile_storm, which hit its five-minute timeout during concurrent host builds (atomic write 681 failed: entry not found). I did not change that test expectation or rerun the full suite.

cargo test -p calternal-plugin-photos:

test result: ok. 47 passed; 0 failed; 2 ignored; 0 measured; 0 filtered out; finished in 49.83s
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

bun run check:

svelte-check found 0 errors and 0 warnings

bun run test:

 Test Files  148 passed (148)
      Tests  1011 passed (1011)

Files: apps/web/e2e/photos-perf.mjs, bench/run.sh, crates/plugins/files/migrations/0019_photo_media_scan.sql, crates/plugins/files/src/lib.rs, crates/plugins/photos/migrations/0007_resumable_rebuild.sql, crates/plugins/photos/src/index.rs, crates/plugins/photos/src/lib.rs.

Merge and head: merged origin/dev in 0b87d28f3; final HEAD is 618217007bd9fcb518f8342359d607346a46ef6a. The shared origin/dev tracking ref advanced six commits after the merge; I did not merge again, following the one-fetch/one-merge rule.

Decisions: Files migration 19 follows occupied versions 16–18. I kept the branch's resumable Photos rebuild and the incoming paired XMP Sidecar lookup. I made no Photos behavior change because the rebuild never started and no Photos bug was demonstrated.

Round 2 — locked 1M profile result Run: normal SSD, lock held with `flock /root/perf.lock`; 3-hour timeout. Load average inside the lock was `0.00, 0.46, 0.83` at start and `5.24, 6.52, 6.74` at release. The monitor sampled once per second and wrote 10,393 samples. | Phase | Duration | Peak RSS | Peak SQLite WAL | Result | |---|---:|---:|---:|---| | Files Index adoption | 1,424.73 s (23m44.73s), 07:33:35–07:57:20 UTC | 4,127,072 KiB | 2,284,614,192 bytes | First sampled count of 1,000,000 Files Index rows. The profile has 995,000 entries under `Files/Bench/rest` and 5,000 in the nested folder. | | Photos rebuild | Not reached | N/A | N/A | Readiness stayed at 0/20,000 Photo file candidates, 0 `photos_media` rows, and timeline 0/20,000. No rebuild request was sent. | | Wait after Files adoption to timeout | 2h34m43s | 4,664,268 KiB at 10:28:03 UTC | 2,285,714,232 bytes at 10:32:03 UTC | Photos candidates remained absent through the 3-hour timeout. These are wait-phase peaks, not Photos rebuild measurements. | The durable folder-reconcile backlog peaked at 3 and was 2 at timeout (Home and `Photos`). The 1M Files adoption time is below the 30-minute trigger, so I did not file a separate Files PERF issue. The repeated missing Photo-candidate adoption remains the finding on #495. This run did not reach a Photos rebuild, so it does not prove a Photos rebuild defect. The timeout ended with `profile_exit=137`; the final `large-home.json` was not produced. Monitor and log artifacts remain in the perf VM run directory `target/tmp/perf495-round2-20261001T073203Z/`. Gates (after merging `origin/dev` once): - `cargo fmt --check`: exit 0; no output. - `cargo clippy -p calternal-plugin-files --all-targets -- -D warnings`: ```text Finished `dev` profile [unoptimized + debuginfo] target(s) in 2m 01s ``` - `cargo clippy -p calternal-plugin-photos --all-targets -- -D warnings`: ```text Finished `dev` profile [unoptimized + debuginfo] target(s) in 4m 51s ``` - Initial `cargo test -p calternal-plugin-files` output: ```text test result: FAILED. 144 passed; 2 failed; 1 ignored; 0 measured; 0 filtered out; finished in 340.61s ``` The migration test expected max version 18, while migration 19 is required because `origin/dev` uses Files migrations 16–18. I updated that expected version to 19; the focused test then passed: ```text test tests::dev_files_schema_upgrades_through_share_log_and_sidecar_migrations ... ok test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 146 filtered out; finished in 1.36s ``` The other failure was `internal_temp_paths_never_enter_index_during_atomic_write_reconcile_storm`, which hit its five-minute timeout during concurrent host builds (`atomic write 681 failed: entry not found`). I did not change that test expectation or rerun the full suite. - `cargo test -p calternal-plugin-photos`: ```text test result: ok. 47 passed; 0 failed; 2 ignored; 0 measured; 0 filtered out; finished in 49.83s test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s ``` - `bun run check`: ```text svelte-check found 0 errors and 0 warnings ``` - `bun run test`: ```text Test Files 148 passed (148) Tests 1011 passed (1011) ``` Files: `apps/web/e2e/photos-perf.mjs`, `bench/run.sh`, `crates/plugins/files/migrations/0019_photo_media_scan.sql`, `crates/plugins/files/src/lib.rs`, `crates/plugins/photos/migrations/0007_resumable_rebuild.sql`, `crates/plugins/photos/src/index.rs`, `crates/plugins/photos/src/lib.rs`. Merge and head: merged `origin/dev` in `0b87d28f3`; final HEAD is `618217007bd9fcb518f8342359d607346a46ef6a`. The shared `origin/dev` tracking ref advanced six commits after the merge; I did not merge again, following the one-fetch/one-merge rule. Decisions: Files migration 19 follows occupied versions 16–18. I kept the branch's resumable Photos rebuild and the incoming paired XMP Sidecar lookup. I made no Photos behavior change because the rebuild never started and no Photos bug was demonstrated.

kayg referenced this issue

2026-10-03 12:51:31 +00:00

Issue hygiene sweep 2026-10-03 #1008

Rows
Columns

PERF: Photos full rebuild never finishes in a 1M-file Home (whole-Home row scan before any write) #495

Problem

Measurements

Why (to confirm)

Suggested direction (not decided)