PERF: Money import preview of a 15 MB / 25k-transaction Actual export takes 30–45 s #1124

Open
opened 2026-10-05 08:22:29 +00:00 by kayg · 35 comments
Owner

From #1121: a realistic synthetic Actual export (15.3 MB ZIP, 25,000 transactions) took 33–45 s end to end through the real UI on a local server with no network limit (59–69 s at 1 MiB/s). Upload is a small part of that; preview parsing and validation dominate. Profile the preview path (unzip, SQLite read of the Actual DB, mapping, identity checks) and make a 25k-transaction import preview finish in a few seconds on this hardware, with streaming progress per stage. Add the case to bench/.

From #1121: a realistic synthetic Actual export (15.3 MB ZIP, 25,000 transactions) took 33–45 s end to end through the real UI on a local server with no network limit (59–69 s at 1 MiB/s). Upload is a small part of that; preview parsing and validation dominate. Profile the preview path (unzip, SQLite read of the Actual DB, mapping, identity checks) and make a 25k-transaction import preview finish in a few seconds on this hardware, with streaming progress per stage. Add the case to bench/.
Author
Owner

Starting #1124 on branch job/perf-1124 from base d0061ec3df. I will profile the Actual preview path on the locked perf VM, run the requested Home and route workloads where the existing tooling supports them, and keep measured results and code changes on this branch.

Starting #1124 on branch job/perf-1124 from base d0061ec3df127d81c86729d07d899b0bf2b6de91. I will profile the Actual preview path on the locked perf VM, run the requested Home and route workloads where the existing tooling supports them, and keep measured results and code changes on this branch.
Author
Owner

Finding: the existing 25,000-row Actual fixture generated by bench/money-import-actual-fixture.py is 676,152 bytes, while #1124 reports a 15.3 MB ZIP. The current fixture is too small to reproduce the reported preview latency. I am extending that generator with deterministic synthetic transaction memos and adding observed stage spans to the existing benchmark. This is a benchmark-only decision; it preserves existing fixture defaults and uses no real export data.

Finding: the existing 25,000-row Actual fixture generated by bench/money-import-actual-fixture.py is 676,152 bytes, while #1124 reports a 15.3 MB ZIP. The current fixture is too small to reproduce the reported preview latency. I am extending that generator with deterministic synthetic transaction memos and adding observed stage spans to the existing benchmark. This is a benchmark-only decision; it preserves existing fixture defaults and uses no real export data.
Author
Owner

Fixture/profile update: bench/money-import-actual-462.mjs --transactions=25000 --transaction-note-bytes=748 now creates a deterministic 15,373,905-byte Actual ZIP and records each preview sample plus observed progress-stage spans. Two generated archives had the same size and SHA-256. I will keep an importer change only if interleaved before/after runs improve p50 by at least 10% with no p95 regression, as requested; the first preview after server start is reported separately from same-process repeats.

Fixture/profile update: `bench/money-import-actual-462.mjs --transactions=25000 --transaction-note-bytes=748` now creates a deterministic 15,373,905-byte Actual ZIP and records each preview sample plus observed progress-stage spans. Two generated archives had the same size and SHA-256. I will keep an importer change only if interleaved before/after runs improve p50 by at least 10% with no p95 regression, as requested; the first preview after server start is reported separately from same-process repeats.
Author
Owner

Before measurement on the locked perf VM (native HDD-like root disk): the deterministic 15,373,903-byte Actual ZIP with 25,000 transactions completed with p50 3,915.65 ms and p95 4,188.14 ms over five samples. Average server CPU was 2.724 s; peak server RSS was 295,079,936 bytes. The binary was built from origin/dev d0061ec3. This current synthetic run is much faster than the issue-reported 30–45 s, so I am profiling the remaining CPU path before changing importer behavior; the generated source has one Account and one Category and may not cover every production export shape.

Before measurement on the locked perf VM (native HDD-like root disk): the deterministic 15,373,903-byte Actual ZIP with 25,000 transactions completed with p50 3,915.65 ms and p95 4,188.14 ms over five samples. Average server CPU was 2.724 s; peak server RSS was 295,079,936 bytes. The binary was built from origin/dev `d0061ec3`. This current synthetic run is much faster than the issue-reported 30–45 s, so I am profiling the remaining CPU path before changing importer behavior; the generated source has one Account and one Category and may not cover every production export shape.
Author
Owner

Finding: a locked perf record -F 99 --call-graph dwarf of the first 25k-row preview sampled calternal_plugin_money::import::ActualStreamProjection::finish_month / advance_to, calternal_money::codec::Document::parse_with_check, and ImportStreamRenderer::validate_generated_file. The streamed month currently parses its Markdown for Ledger projection and parses it again for byte-stable validation. The profile is available at /root/perf-1124/target/tmp/money-before.perf.data on the perf VM; this suggests one candidate, not yet a measured win. Before changing it, I will keep the candidate only if interleaved p50 improves at least 10% with no p95 regression.

Finding: a locked `perf record -F 99 --call-graph dwarf` of the first 25k-row preview sampled `calternal_plugin_money::import::ActualStreamProjection::finish_month` / `advance_to`, `calternal_money::codec::Document::parse_with_check`, and `ImportStreamRenderer::validate_generated_file`. The streamed month currently parses its Markdown for Ledger projection and parses it again for byte-stable validation. The profile is available at `/root/perf-1124/target/tmp/money-before.perf.data` on the perf VM; this suggests one candidate, not yet a measured win. Before changing it, I will keep the candidate only if interleaved p50 improves at least 10% with no p95 regression.
Author
Owner

Finding: five interleaved before/after pairs on the locked perf VM used identical 15,373,903-byte ZIPs (25,000 transactions, fixture SHA256 16b9ad6292c852968a453d9796f59cea6c2fb87145cee44ac709e9e6b22167c8), with one first-preview and one warm repeat per server. The baseline p50/p95 were 3,711.33/4,898.15 ms; the parse-reuse candidate was 3,427.41/3,705.91 ms. Aggregate p50 improved 7.65%; p95 did not regress. Cold p50 improved 8.27%, warm p50 7.65%. Server CPU p50 moved 2.56 to 2.31 seconds. Since p50 did not meet the pre-stated 10% threshold, commit 943e97ca5c163bb79623f6386766024dfcc0e23e was reverted in b8b91527c; the optimization is not retained. The VM 1-minute load values ranged from 0.14 to 1.53 during samples, recorded in each raw profile.

Finding: five interleaved before/after pairs on the locked perf VM used identical 15,373,903-byte ZIPs (25,000 transactions, fixture SHA256 `16b9ad6292c852968a453d9796f59cea6c2fb87145cee44ac709e9e6b22167c8`), with one first-preview and one warm repeat per server. The baseline p50/p95 were 3,711.33/4,898.15 ms; the parse-reuse candidate was 3,427.41/3,705.91 ms. Aggregate p50 improved 7.65%; p95 did not regress. Cold p50 improved 8.27%, warm p50 7.65%. Server CPU p50 moved 2.56 to 2.31 seconds. Since p50 did not meet the pre-stated 10% threshold, commit `943e97ca5c163bb79623f6386766024dfcc0e23e` was reverted in `b8b91527c`; the optimization is not retained. The VM 1-minute load values ranged from 0.14 to 1.53 during samples, recorded in each raw profile.
Author
Owner

The first route profile stopped before navigation timing, during Photos fixture setup. Playwright reported that the page/context closed at the upload page.evaluate call. The fixture is 194,576 bytes, and the harness had copied its Base64 body into all 1,000 entries in one Playwright argument (about 260 MB). I changed the seed to send the shared bytes once and the per-photo metadata list once, in commit a7476187c. The full route profile is retrying under the perf VM lock. This is a benchmark-fixture failure; it produced no user-facing timing results.

The first route profile stopped before navigation timing, during Photos fixture setup. Playwright reported that the page/context closed at the upload `page.evaluate` call. The fixture is 194,576 bytes, and the harness had copied its Base64 body into all 1,000 entries in one Playwright argument (about 260 MB). I changed the seed to send the shared bytes once and the per-photo metadata list once, in commit `a7476187c`. The full route profile is retrying under the perf VM lock. This is a benchmark-fixture failure; it produced no user-facing timing results.
Author
Owner

The route profile retry passed the Photos seed but stopped before measurements while creating its Money fixture: POST /api/v1/money/budgets returned HTTP 404 because the per-User Money plug-in was not enabled. I added the real Money enable call before creating the Budget in 7efb93459. The first retry took 15m 28s to reach that assertion and produced no route timings. The next run keeps the 5k disk-backed Files folder and year of Journal entries, with smaller supplementary API Files/Notes/Photos counts; the separate Photos/Home profiles cover the large corpus.

The route profile retry passed the Photos seed but stopped before measurements while creating its Money fixture: `POST /api/v1/money/budgets` returned HTTP 404 because the per-User Money plug-in was not enabled. I added the real Money enable call before creating the Budget in `7efb93459`. The first retry took 15m 28s to reach that assertion and produced no route timings. The next run keeps the 5k disk-backed Files folder and year of Journal entries, with smaller supplementary API Files/Notes/Photos counts; the separate Photos/Home profiles cover the large corpus.
Author
Owner

The route profile source also read apiRouteRepetitions before its const initialization and called the API sample function twice (the second call dropped the Note-link route). That would fail or overwrite the intended table after the navigation phase. Commit f6a9014fb moves the declaration before one API pass and adds the seeded Money month endpoint. I stopped the active run at the second navigation pass because its loaded module still had the defect; no timing JSON was written, and the VM lock is released.

The route profile source also read `apiRouteRepetitions` before its `const` initialization and called the API sample function twice (the second call dropped the Note-link route). That would fail or overwrite the intended table after the navigation phase. Commit `f6a9014fb` moves the declaration before one API pass and adds the seeded Money month endpoint. I stopped the active run at the second navigation pass because its loaded module still had the defect; no timing JSON was written, and the VM lock is released.
Author
Owner

The route inventory review showed that route-perf.mjs omitted the Notes primary Tab. Commit 89685c8b9 adds Notes and a PERF_ROUTE_IDS selector so the first-load path can run independently. The active full-route run was started before this change and will not include Notes; I will record a focused Notes route profile separately.

The route inventory review showed that `route-perf.mjs` omitted the Notes primary Tab. Commit `89685c8b9` adds Notes and a `PERF_ROUTE_IDS` selector so the first-load path can run independently. The active full-route run was started before this change and will not include Notes; I will record a focused Notes route profile separately.
Author
Owner

The route profile's third attempt completed cold and hard-refresh samples at 390 px/light, then failed while priming the warm Files source: its Photos ready selector timed out while the URL was still the 5k Files deep link. The run did not save timing JSON. I changed warm-source setup to open the stable Photos root directly; the measured destination switch still uses the real Tab. Fix: e14551692. I will run a focused Files route profile before the full retry.

The route profile's third attempt completed cold and hard-refresh samples at 390 px/light, then failed while priming the warm Files source: its Photos ready selector timed out while the URL was still the 5k Files deep link. The run did not save timing JSON. I changed warm-source setup to open the stable Photos root directly; the measured destination switch still uses the real Tab. Fix: `e14551692`. I will run a focused Files route profile before the full retry.
Author
Owner

The focused Files profile confirmed that a synthetic Photos root link also failed during warm-source setup: the browser remained at the Files deep link and the Photos readiness marker timed out. This is setup, before the measured Files switch. I changed the setup to use a committed full navigation to /photos, while the measured destination switch still clicks its Tab. Fix: 36f2f9b3e; retrying the focused route now.

The focused Files profile confirmed that a synthetic Photos root link also failed during warm-source setup: the browser remained at the Files deep link and the Photos readiness marker timed out. This is setup, before the measured Files switch. I changed the setup to use a committed full navigation to `/photos`, while the measured destination switch still clicks its Tab. Fix: `36f2f9b3e`; retrying the focused route now.
Author
Owner

The focused Files profile now reaches the warm navigation, but the sample had no start time. The timer waited for a hard-coded #tab-files selector; the route became ready but the selector did not fire the timer. Commit 7c02eaec1 arms the capture listener for the next click (or popstate) immediately before the profile triggers that one navigation. This fixes the harness timing trigger, not application navigation.

The focused Files profile now reaches the warm navigation, but the sample had no start time. The timer waited for a hard-coded `#tab-files` selector; the route became ready but the selector did not fire the timer. Commit `7c02eaec1` arms the capture listener for the next click (or `popstate`) immediately before the profile triggers that one navigation. This fixes the harness timing trigger, not application navigation.
Author
Owner

After the click listener change, the warm Files path reached its ready marker but still reported a null timing. The observer had a fixed 121-frame limit (about two seconds), shorter than the configured 60-second route-ready timeout for the 5k Files view. Commit f0881eeca keeps sampling until the same route-ready deadline. This is benchmark instrumentation; no UI code changed.

After the click listener change, the warm Files path reached its ready marker but still reported a null timing. The observer had a fixed 121-frame limit (about two seconds), shorter than the configured 60-second route-ready timeout for the 5k Files view. Commit `f0881eeca` keeps sampling until the same route-ready deadline. This is benchmark instrumentation; no UI code changed.
Author
Owner

The warm sample still failed after the Files ready marker appeared. The browser can replace the document during the Tab navigation, which clears the in-page timing object. Commit 2fdc6f71a stores the action start in same-tab session storage and uses the real ready-and-painted time as a fallback after a document load. The report labels this timing source and leaves frame counts null when the in-page frame observer is unavailable. I will verify the focused Files run before the full rerun.

The warm sample still failed after the Files ready marker appeared. The browser can replace the document during the Tab navigation, which clears the in-page timing object. Commit `2fdc6f71a` stores the action start in same-tab session storage and uses the real ready-and-painted time as a fallback after a document load. The report labels this timing source and leaves frame counts null when the in-page frame observer is unavailable. I will verify the focused Files run before the full rerun.
Author
Owner

The session-storage timing fallback was not the remaining failure: the next Files profile still timed out waiting for the Photos source while the page URL remained on the Files deep link. Commit 8b703f1a0 makes both Files and Photos source setup use a full URL navigation and explicitly waits for the expected route and its real ready marker before timing the destination Tab. The next focused run verifies this path.

The session-storage timing fallback was not the remaining failure: the next Files profile still timed out waiting for the Photos source while the page URL remained on the Files deep link. Commit `8b703f1a0` makes both Files and Photos source setup use a full URL navigation and explicitly waits for the expected route and its real ready marker before timing the destination Tab. The next focused run verifies this path.
Author
Owner

Finding: the 5k Files route profile did not complete its warm-cache setup. On the perf VM at 390 px/light, cold and hard-refresh setup messages appeared, then the profile remained before its first warm sample for over 15 minutes. During the final check, the Chromium renderer had accumulated 13:06 elapsed time at 83.5% CPU; the profile still held the VM lock. I stopped the run and it exited 1 without a JSON result. This does not establish a first-paint latency, but it is evidence that this profile cannot reach the measured tab switch for the 5k folder within a practical window. I will isolate the 5k cold paint from warm navigation and continue with other workloads.

Finding: the 5k Files route profile did not complete its warm-cache setup. On the perf VM at 390 px/light, cold and hard-refresh setup messages appeared, then the profile remained before its first warm sample for over 15 minutes. During the final check, the Chromium renderer had accumulated 13:06 elapsed time at 83.5% CPU; the profile still held the VM lock. I stopped the run and it exited 1 without a JSON result. This does not establish a first-paint latency, but it is evidence that this profile cannot reach the measured tab switch for the 5k folder within a practical window. I will isolate the 5k cold paint from warm navigation and continue with other workloads.
Author
Owner

The isolated 5k Files cold profile completed on the perf VM (load at lock entry: 0.01, 0.58, 1.36). On a 4× CPU throttle, first meaningful paint ranged from 2,282 ms (820 px/light) to 3,044 ms (1440 px/light); all six width/theme samples were under the 5,000 ms budget. Each cell has one sample. The matching warm-navigation run still did not reach its first warm sample after 15 minutes, so it has no valid warm-tab timing.

The same Home indexed 5,000 Files entries. Ten-request API p50/p95 were: calendar.range 42.0/74.2 ms, Analytics 40.9/70.3 ms, Files.recent 30.1/53.7 ms, and Files.quota 19.4/24.6 ms. Server idle RSS was 1,080,198,758 B and idle CPU 0.2%; the 24-client/12-second burst returned 84,077/84,077 HTTP 200 responses with p50/p95 3.1/6.1 ms, peak RSS 1,080,651,776 B, and mean CPU 326.99%. These route results are in docs/perf/runs/2026-10-06-1124-files-route-cold.json. They are initial baselines, not A/B changes.

The isolated 5k Files cold profile completed on the perf VM (load at lock entry: 0.01, 0.58, 1.36). On a 4× CPU throttle, first meaningful paint ranged from 2,282 ms (820 px/light) to 3,044 ms (1440 px/light); all six width/theme samples were under the 5,000 ms budget. Each cell has one sample. The matching warm-navigation run still did not reach its first warm sample after 15 minutes, so it has no valid warm-tab timing. The same Home indexed 5,000 Files entries. Ten-request API p50/p95 were: calendar.range 42.0/74.2 ms, Analytics 40.9/70.3 ms, Files.recent 30.1/53.7 ms, and Files.quota 19.4/24.6 ms. Server idle RSS was 1,080,198,758 B and idle CPU 0.2%; the 24-client/12-second burst returned 84,077/84,077 HTTP 200 responses with p50/p95 3.1/6.1 ms, peak RSS 1,080,651,776 B, and mean CPU 326.99%. These route results are in docs/perf/runs/2026-10-06-1124-files-route-cold.json. They are initial baselines, not A/B changes.
Author
Owner

The full Home profile indexed 5,001 Photos rows, 20,000 Files rows, 1,001 Notes, and 365 Journal entries in 141,614 ms. It found 17 visible Photos tiles, but neither the first nor all visible decoded thumbnails appeared within either 120-second sample (cold tiles: 1,088 ms; warm tiles: 483 ms). The run then failed before writing JSON because its Analytics readiness selector matched both the visible dialog and its background copy. Its three scroll probes also reported zero movement: the profile still scrolled Window, while Photos now scrolls #route-content. I’m fixing the benchmark selectors and will rerun before treating scroll or Analytics results as valid. The thumbnail delay remains a product-path finding to profile.

The full Home profile indexed 5,001 Photos rows, 20,000 Files rows, 1,001 Notes, and 365 Journal entries in 141,614 ms. It found 17 visible Photos tiles, but neither the first nor all visible decoded thumbnails appeared within either 120-second sample (cold tiles: 1,088 ms; warm tiles: 483 ms). The run then failed before writing JSON because its Analytics readiness selector matched both the visible dialog and its background copy. Its three scroll probes also reported zero movement: the profile still scrolled Window, while Photos now scrolls #route-content. I’m fixing the benchmark selectors and will rerun before treating scroll or Analytics results as valid. The thumbnail delay remains a product-path finding to profile.
Author
Owner

A repeat large-Home run indexed the full fixture, then the existing Photos key-photo profile saw a valid set request return 200 and its following Undo return 404 (expected 204 at apps/web/e2e/photos-perf.mjs:535). The first profile attempt completed the key-photo subprofile, so this may depend on background indexing/timing. I kept the expectation unchanged and filed the focused follow-up as #1193. I will skip only this separate mutation subprofile for the Photos grid rerun; its result remains an unresolved correctness finding.

A repeat large-Home run indexed the full fixture, then the existing Photos key-photo profile saw a valid set request return 200 and its following Undo return 404 (expected 204 at `apps/web/e2e/photos-perf.mjs:535`). The first profile attempt completed the key-photo subprofile, so this may depend on background indexing/timing. I kept the expectation unchanged and filed the focused follow-up as #1193. I will skip only this separate mutation subprofile for the Photos grid rerun; its result remains an unresolved correctness finding.
Author
Owner

Photos large-Home findings on the perf VM (release server, lock held; 5,000 photos, 20,000 Files, 1,000 Notes + 1 MiB Note, 365 Journal Log entries): startup indexed 5,001 Photos in 131.0 s. The Photos API was responsive: bucket p50/p95 5.2/8.7 ms; 60-day page 20.2/48.5 ms; middle page 14.9/34.7 ms. The first 17 visible tiles appeared in 694 ms, while no visible thumbnail decoded during either 120 s cold or warm window. At 4× CPU throttle, the scroll profile reports 72 DOM tiles at most, 14.7 fps for the 400 px/frame fling, and 293.7 ms/s total main-thread task time; removing backdrop blur returned the steady scroll to 59.8 fps. I am collecting the remaining Home-view samples before ranking this path and will profile the trace before deciding whether there is a qualifying fix.

Photos large-Home findings on the perf VM (release server, lock held; 5,000 photos, 20,000 Files, 1,000 Notes + 1 MiB Note, 365 Journal Log entries): startup indexed 5,001 Photos in 131.0 s. The Photos API was responsive: bucket p50/p95 5.2/8.7 ms; 60-day page 20.2/48.5 ms; middle page 14.9/34.7 ms. The first 17 visible tiles appeared in 694 ms, while no visible thumbnail decoded during either 120 s cold or warm window. At 4× CPU throttle, the scroll profile reports 72 DOM tiles at most, 14.7 fps for the 400 px/frame fling, and 293.7 ms/s total main-thread task time; removing backdrop blur returned the steady scroll to 59.8 fps. I am collecting the remaining Home-view samples before ranking this path and will profile the trace before deciding whether there is a qualifying fix.
Author
Owner

The first Photos rerun exposed a probe interaction: its temporary no-backdrop-blur CSS remained active for the later Analytics material assertion, so the profile stopped before writing JSON. I kept the material assertion unchanged, remove the style immediately after its scroll sample, and committed the probe fix as 9be024d8a. The corrected full-Home profile is running again.

The first Photos rerun exposed a probe interaction: its temporary no-backdrop-blur CSS remained active for the later Analytics material assertion, so the profile stopped before writing JSON. I kept the material assertion unchanged, remove the style immediately after its scroll sample, and committed the probe fix as 9be024d8a. The corrected full-Home profile is running again.
Author
Owner

A locked diagnostic probe found why the Photos profile stopped in its extra Analytics overlay scenario: the shared Analytics cards compute blur(16px) saturate(1.8) brightness(1.05), while the existing #504 profile assertion requires the older saturate(1.5) value. The probe also confirmed the temporary no-blur stylesheet was absent and reduced transparency was not active. I left the existing expectation unchanged per the test rule. The Photos profile now has an explicit opt-out for this separate overlay subprofile; route-perf still measures the Analytics Tab, and the Calendar profile measures Week/Month with Events.

A locked diagnostic probe found why the Photos profile stopped in its extra Analytics overlay scenario: the shared Analytics cards compute `blur(16px) saturate(1.8) brightness(1.05)`, while the existing #504 profile assertion requires the older `saturate(1.5)` value. The probe also confirmed the temporary no-blur stylesheet was absent and reduced transparency was not active. I left the existing expectation unchanged per the test rule. The Photos profile now has an explicit opt-out for this separate overlay subprofile; route-perf still measures the Analytics Tab, and the Calendar profile measures Week/Month with Events.
Author
Owner

Photos full Home baseline is recorded in docs/perf/2026-10-06-1124.md and docs/perf/runs/2026-10-06-1124-photos-home.json at commit 741f2f145. The perf VM indexed 5,000 Photos, 20,000 Files, 1,000 Notes and 365 Log entries in 131.4 s. Photos first tiles painted in 575 ms cold / 556 ms warm, but no visible thumbnail decoded in either bounded 120 s wait. Steady scroll was 15.4 fps (frame p50/p95 66.7/83.3 ms); fling was 14.8 fps (66.7/83.4 ms). The 1 MiB Note painted in 2.427/3.007 s p50/p95 and the 5k Files Home render in 14.912/15.358 s under 4x CPU throttle. Fixture and output are committed; Photos scroll material A/B and remaining requested profiles are still running. The VM load at lock entry was 0.92/2.21/2.67.

Photos full Home baseline is recorded in `docs/perf/2026-10-06-1124.md` and `docs/perf/runs/2026-10-06-1124-photos-home.json` at commit `741f2f145`. The perf VM indexed 5,000 Photos, 20,000 Files, 1,000 Notes and 365 Log entries in 131.4 s. Photos first tiles painted in 575 ms cold / 556 ms warm, but no visible thumbnail decoded in either bounded 120 s wait. Steady scroll was 15.4 fps (frame p50/p95 66.7/83.3 ms); fling was 14.8 fps (66.7/83.4 ms). The 1 MiB Note painted in 2.427/3.007 s p50/p95 and the 5k Files Home render in 14.912/15.358 s under 4x CPU throttle. Fixture and output are committed; Photos scroll material A/B and remaining requested profiles are still running. The VM load at lock entry was 0.92/2.21/2.67.
Author
Owner

The Photos scroll A/B is complete and recorded at 0c3f468ed / 07f6009c9. Three baseline and three candidate 8-second scrolls alternated on the same 5k-photo Home. With the predeclared keep rule (frame p50 improves at least 10%, p95 does not regress), baseline was 66.7/100.1 ms p50/p95 and 13.7 fps; static shared-filter paint during scroll was 33.3/50.1 ms and 27.1 fps. That is 50.1% p50 improvement with p95 improvement. Separate Chrome traces are committed. They show no long tasks and similar layout object counts; the controlled filter change points to shared backdrop filters as the frame-time cause. I am keeping the candidate and applying it through the existing Photos native-scroll lifecycle, with overlays excluded.

The Photos scroll A/B is complete and recorded at `0c3f468ed` / `07f6009c9`. Three baseline and three candidate 8-second scrolls alternated on the same 5k-photo Home. With the predeclared keep rule (frame p50 improves at least 10%, p95 does not regress), baseline was 66.7/100.1 ms p50/p95 and 13.7 fps; static shared-filter paint during scroll was 33.3/50.1 ms and 27.1 fps. That is 50.1% p50 improvement with p95 improvement. Separate Chrome traces are committed. They show no long tasks and similar layout object counts; the controlled filter change points to shared backdrop filters as the frame-time cause. I am keeping the candidate and applying it through the existing Photos native-scroll lifecycle, with overlays excluded.
Author
Owner

The Calendar measurement harness did not reach its Month timing because its readiness probe filtered /api/v1/calendar/events rows by a kind field that the provider-only CalendarEventsResponse does not define. The probe counted 0/121 rows after the forced refresh. I updated it to count that response's Event views directly, checked the script with node --check, and restarted the run under /root/perf.lock at e4544c534bfd.

The Calendar measurement harness did not reach its Month timing because its readiness probe filtered `/api/v1/calendar/events` rows by a `kind` field that the provider-only `CalendarEventsResponse` does not define. The probe counted 0/121 rows after the forced refresh. I updated it to count that response's Event views directly, checked the script with `node --check`, and restarted the run under `/root/perf.lock` at `e4544c534bfd`.
Author
Owner

The second Calendar profile reached Week rendering with the provider fixture loaded, but gridReady then timed out waiting for offscreen .activity img elements to finish. Its failure state showed .tg.ready, 11 populated columns and 48 Calendar blocks; Activity thumbnails load lazily and are not required for the Event grid to be ready. I removed that offscreen-image gate from the performance harness and retained the populated-column check. The harness now also reports Activity image counts if grid readiness itself fails. Script syntax and whitespace checks pass; retrying on the perf VM.

The second Calendar profile reached Week rendering with the provider fixture loaded, but `gridReady` then timed out waiting for offscreen `.activity img` elements to finish. Its failure state showed `.tg.ready`, 11 populated columns and 48 Calendar blocks; Activity thumbnails load lazily and are not required for the Event grid to be ready. I removed that offscreen-image gate from the performance harness and retained the populated-column check. The harness now also reports Activity image counts if grid readiness itself fails. Script syntax and whitespace checks pass; retrying on the perf VM.
Author
Owner

The Calendar profile completed with 121 provider Events (120 timed fixtures plus the adjacent-day Event) on October 2026's 42-cell Month grid. Month route-ready p50/p95 was 2,483/2,510 ms at 1440 px, 1,639/1,984 ms at 820 px, and 2,451/2,834 ms at 390 px; each cell has three samples on a 4× CPU throttle (6× at 390 px). On the 1440 px Week, trackpad zoom measured 100.1/216.7 ms frame p50/p95 with 42 long tasks (236 ms longest); horizontal fling measured 83.3/166.6 ms with 11 long tasks (167 ms longest). The captured Chrome trace reports 2,594.5 ms in FunctionCall slices and 1,060.5 ms in UpdateLayoutTree over the interaction trace. I have saved the full metrics and desktop Week/Month traces for root-cause review.

The Calendar profile completed with 121 provider Events (120 timed fixtures plus the adjacent-day Event) on October 2026's 42-cell Month grid. Month route-ready p50/p95 was 2,483/2,510 ms at 1440 px, 1,639/1,984 ms at 820 px, and 2,451/2,834 ms at 390 px; each cell has three samples on a 4× CPU throttle (6× at 390 px). On the 1440 px Week, trackpad zoom measured 100.1/216.7 ms frame p50/p95 with 42 long tasks (236 ms longest); horizontal fling measured 83.3/166.6 ms with 11 long tasks (167 ms longest). The captured Chrome trace reports 2,594.5 ms in FunctionCall slices and 1,060.5 ms in UpdateLayoutTree over the interaction trace. I have saved the full metrics and desktop Week/Month traces for root-cause review.
Author
Owner

The reduced-seed warm-route rerun reproduced the Photos readiness failure. It reached the warm Files pass, then route-perf.mjs waited for Photos content while the browser URL still pointed at /files?path=Files%2FBench%2F5k-folder; the marker timed out after 60 seconds. The runner returned no JSON, so it provides no valid cold/warm timings. I am recording warm route switching as a measurement gap and continuing with focused profiles.

The reduced-seed warm-route rerun reproduced the Photos readiness failure. It reached the warm Files pass, then `route-perf.mjs` waited for Photos content while the browser URL still pointed at `/files?path=Files%2FBench%2F5k-folder`; the marker timed out after 60 seconds. The runner returned no JSON, so it provides no valid cold/warm timings. I am recording warm route switching as a measurement gap and continuing with focused profiles.
Author
Owner

The perf VM is single-tenant and its lock is still held by another isolated run, so the queued Money profile has not started. I have prepared the remaining route and startup profiles locally. I will resume the VM measurements when the lock is released; no overlapping measurements are running.

The perf VM is single-tenant and its lock is still held by another isolated run, so the queued Money profile has not started. I have prepared the remaining route and startup profiles locally. I will resume the VM measurements when the lock is released; no overlapping measurements are running.
Author
Owner

Correction to the reduced-seed warm-profile note: the runner logged measuring warm Files, then failed while trying to prepare Photos as the source for that target. It did not complete a warm Files sample. Only the Calendar and Notes warm samples completed before the failure, and no JSON was written.

Correction to the reduced-seed warm-profile note: the runner logged `measuring warm Files`, then failed while trying to prepare Photos as the source for that target. It did not complete a warm Files sample. Only the Calendar and Notes warm samples completed before the failure, and no JSON was written.
Author
Owner

Correction to the measurement scope: the first #1124 profiles used /root/perf-1124/target/tmp, which is on native /dev/sda1; those numbers are diagnostic and are not HDD-emulated results. I recorded this in docs/perf/2026-10-06-1124.md at head c2eafe427.

The corrected profiles place server state under /srv/hdd-emu and run under the existing 8 ms / 200 IOPS I/O limit. The Money profile also records its in-lock load and rechecks the emulator with direct-I/O fio. The perf lock is currently held by another job, so these reruns have not started.

Correction to the measurement scope: the first #1124 profiles used `/root/perf-1124/target/tmp`, which is on native `/dev/sda1`; those numbers are diagnostic and are not HDD-emulated results. I recorded this in `docs/perf/2026-10-06-1124.md` at head `c2eafe427`. The corrected profiles place server state under `/srv/hdd-emu` and run under the existing 8 ms / 200 IOPS I/O limit. The Money profile also records its in-lock load and rechecks the emulator with direct-I/O fio. The perf lock is currently held by another job, so these reruns have not started.
Author
Owner

The corrected Money run is now inside /root/perf.lock with state under /srv/hdd-emu. Its direct-I/O QD1 qualification measured 86.1 IOPS, p50 11.21 ms and p99 31.06 ms; the lock-entry load average was 6.00 / 6.60 / 5.88. The emulator is configured for 8 ms / 200 IOPS, but this loaded result is slower than the prior qualification. I am recording the observed qualification and load with the profile; QD16 and the Money samples are still running.

The corrected Money run is now inside `/root/perf.lock` with state under `/srv/hdd-emu`. Its direct-I/O QD1 qualification measured 86.1 IOPS, p50 11.21 ms and p99 31.06 ms; the lock-entry load average was 6.00 / 6.60 / 5.88. The emulator is configured for 8 ms / 200 IOPS, but this loaded result is slower than the prior qualification. I am recording the observed qualification and load with the profile; QD16 and the Money samples are still running.
Author
Owner

The qualified-HDD Actual and Money Budget profile completed under /root/perf.lock at head 21194cd30. The 25,000-row fidelity ZIP was 15,389,723 bytes; five preview samples measured 5,955.02 / 6,118.53 ms p50/p95, 4.268 s average server CPU and 335,618,048 bytes peak RSS. The issue-reported 30–45 s did not reproduce. The two-request burst admitted one preview (200) and returned 429 for the concurrent request. This is synthetic and is not a direct comparison with the simpler native-filesystem profile.

The imported 2025-12 Budget month, fully painted (three cold and three warm samples per cell):

Width Theme Cold p50/p95 (ms) Warm p50/p95 (ms)
390 light 1,127.8 / 1,227.8 1,399.5 / 2,047.2
390 dark 878.9 / 2,109.6 1,166.8 / 1,444.3
820 light 660.1 / 1,703 1,363.4 / 1,597.3
820 dark 1,040.1 / 2,340.9 1,466.7 / 1,638.9
1,440 light 1,020.7 / 2,901.7 1,574.4 / 1,594.3
1,440 dark 1,225.6 / 2,139.9 1,509.7 / 1,764.3

Fio qualification in the same lock measured QD1 125.0 IOPS at 7.96/8.29 ms p50/p99 and QD16 200.9 IOPS at 100.14/104.33 ms. See docs/perf/2026-10-06-1124.md and its linked raw artifacts. The earlier 400 responses were benchmark setup failures: the fidelity export needs an Account-kind selection/re-preview, and the server expects no JSON body when no opening-balance acknowledgement is needed. The benchmark now mirrors both UI steps (#462, #1130).

The qualified-HDD Actual and Money Budget profile completed under `/root/perf.lock` at head `21194cd30`. The 25,000-row fidelity ZIP was 15,389,723 bytes; five preview samples measured 5,955.02 / 6,118.53 ms p50/p95, 4.268 s average server CPU and 335,618,048 bytes peak RSS. The issue-reported 30–45 s did not reproduce. The two-request burst admitted one preview (200) and returned 429 for the concurrent request. This is synthetic and is not a direct comparison with the simpler native-filesystem profile. The imported 2025-12 Budget month, fully painted (three cold and three warm samples per cell): | Width | Theme | Cold p50/p95 (ms) | Warm p50/p95 (ms) | | ---: | --- | ---: | ---: | | 390 | light | 1,127.8 / 1,227.8 | 1,399.5 / 2,047.2 | | 390 | dark | 878.9 / 2,109.6 | 1,166.8 / 1,444.3 | | 820 | light | 660.1 / 1,703 | 1,363.4 / 1,597.3 | | 820 | dark | 1,040.1 / 2,340.9 | 1,466.7 / 1,638.9 | | 1,440 | light | 1,020.7 / 2,901.7 | 1,574.4 / 1,594.3 | | 1,440 | dark | 1,225.6 / 2,139.9 | 1,509.7 / 1,764.3 | Fio qualification in the same lock measured QD1 125.0 IOPS at 7.96/8.29 ms p50/p99 and QD16 200.9 IOPS at 100.14/104.33 ms. See `docs/perf/2026-10-06-1124.md` and its linked raw artifacts. The earlier 400 responses were benchmark setup failures: the fidelity export needs an Account-kind selection/re-preview, and the server expects no JSON body when no opening-balance acknowledgement is needed. The benchmark now mirrors both UI steps (#462, #1130).
Author
Owner

#1124 performance review report — head c0c3bf2331d044ed7709e3c526023ddbefc77a60 (branch job/perf-1124; no push).

The measured runs, environment qualification, raw profiles, and traces are in docs/perf/2026-10-06-1124.md and docs/perf/runs/2026-10-06-1124-*.

Ranked paths and changes

Path Before After / disposition
Large Home Files render, 5,000 entries 14,912 / 15,358 ms p50/p95 at 4× CPU throttle; 27 virtual DOM rows, 13,442 ms renderer marker No code change. A 5k warm-route attempt hit its 12-minute setup limit before a sample; derived-view cost is a likely cause, but no Chrome trace isolated it.
Calendar Week zoom 8.5 fps; 100.1 / 216.7 ms frame p50/p95; 42 long tasks, 236 ms max No code change. Trace recorded 1,060.5 ms UpdateLayoutTree and 530.1 ms Layout; per-frame --hour grid-height updates are a likely layout cause.
Photos feed scroll 13.7 fps; 66.7 / 100.1 ms frame p50/p95 Kept 685b1105f: 27.1 fps; 33.3 / 50.1 ms, 50.1% p50 improvement and lower p95. The controlled A/B points to shared backdrop filters as the main cost.
Actual import, parsed-document reuse candidate Baseline aggregate p50/p95 3,711.33 / 4,898.15 ms Candidate 3,427.41 / 3,705.91 ms; p50 improved 7.65%, below the pre-set 10% keep rule, so the candidate was reverted.

Files, Calendar and Photos A/B profiles ran on the VM's native filesystem and are diagnostic, not HDD results. The synthetic HDD Actual preview used a 25,000-transaction, 15,389,723-byte archive and measured 5,955.02 / 6,118.53 ms p50/p95 over five samples. It did not reproduce the reported 30–45 seconds and is not comparable to the simpler native fixture.

The HDD emulator passed qualification (QD1 125.0 IOPS, 7.96/8.29 ms p50/p99; QD16 200.9 IOPS, 100.14/104.33 ms). The populated Budget month fully-painted ready p50/p95, cold / warm, was: 390 light 1,127.8/1,227.8 / 1,399.5/2,047.2 ms; 390 dark 878.9/2,109.6 / 1,166.8/1,444.3; 820 light 660.1/1,703 / 1,363.4/1,597.3; 820 dark 1,040.1/2,340.9 / 1,466.7/1,638.9; 1440 light 1,020.7/2,901.7 / 1,574.4/1,594.3; 1440 dark 1,225.6/2,139.9 / 1,509.7/1,764.3.

The common-route sample covered 24 routes. The slowest p50/p95 were Calendar range 42.0/74.2 ms, Analytics 40.9/70.3 ms, Files recent 30.1/53.7 ms and Files quota 19.4/24.6 ms. Idle RSS was 1,080,198,758 bytes and CPU 0.2%. A 12-second, concurrency-24 burst completed 84,077 requests with all 200 responses and 3.1/6.1 ms response p50/p95.

Built and committed

  • Scroll-scoped shared-filter suppression with one root Photos scroll marker and scrollend / 140 ms fallback: apps/web/src/lib/photos/PhotoTimeline.svelte, packages/ui/src/tokens.css.
  • Production-route Photos A/B, state verification and Mac-platform screenshot capture harness: apps/web/e2e/photos-perf.mjs.
  • Money import benchmark follows Account-kind review, discard/re-preview and inferred-opening-balance confirmation: bench/money-import-actual-462.mjs.
  • Profile report, JSON and Chrome trace artifacts under docs/perf/; exact perf-lint pins refreshed after merging origin/dev.

Commits: 685b1105f, 95b98a770, 21194cd30, merge 3c3881845, and report c0c3bf233. Decisions: keep the Photos change because it passed the 10% p50 rule without p95 regression; revert document reuse because it did not. No DESIGN decision was needed.

Gates (verbatim summaries)

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

cd apps/web && bun run check:

perf-lint: PASS; 0 violations; 22359 scoped exceptions
svelte-check found 0 errors and 2 warnings in 2 files

The two warnings are empty CSS rulesets in packages/ui/src/components/calendar/AttachmentDeck.svelte:1055 and AgendaList.svelte:1277. No Rust source changed, so per-crate clippy/test gates did not apply.

cd apps/web && bun run test:

Test Files  274 passed (274)
     Tests  1907 passed (1907)
  Duration  444.10s (transform 32%, environment 25%, import 22%, tests 17%, setup 5%)

bun run build passed after the merge. cargo clean removed 15,539 files / 6.3 GiB; apps/web/build was deleted after verification.

Known gaps and UX gaps

  • The post-change Photos A/B on HDD and six Mac-platform screenshots (390/820/1440, light/dark) did not run: the perf VM lock remained held by another job until the four-hour time limit. The checked-in harness can capture them; no screenshots are attached.
  • Warm Tab switching, Search typing, and startup time after a migration remain unmeasured. The top-20 route set was not collected; 24 routes were sampled, with the slowest four listed above.
  • Files and Calendar causes remain likely diagnoses, not fixes. Photos A/B is native-filesystem evidence only. The money fixture is synthetic and does not reproduce the reported latency.
  • Existing follow-ups: Files/Calendar #549, Actual import #462, Search #258, startup #1161. The Paths #549 and #462 have this review's measurements in their comments.
  • UX gap closed: the Photos optimization applies to scroll input through the shared feed event and clears on scrollend or a short fallback; it adds no input-specific motion branch. UX gap left: required Mac-rendered screenshot review is pending because the locked VM run did not start.

For the merge round: capture the pending Photos screenshots and HDD A/B under /root/perf.lock; measure warm Tabs, Search typing and startup after migration. No API route or Rust contract changed in this job.

#1124 performance review report — head `c0c3bf2331d044ed7709e3c526023ddbefc77a60` (branch `job/perf-1124`; no push). The measured runs, environment qualification, raw profiles, and traces are in `docs/perf/2026-10-06-1124.md` and `docs/perf/runs/2026-10-06-1124-*`. ## Ranked paths and changes | Path | Before | After / disposition | | --- | --- | --- | | Large Home Files render, 5,000 entries | 14,912 / 15,358 ms p50/p95 at 4× CPU throttle; 27 virtual DOM rows, 13,442 ms renderer marker | No code change. A 5k warm-route attempt hit its 12-minute setup limit before a sample; derived-view cost is a likely cause, but no Chrome trace isolated it. | | Calendar Week zoom | 8.5 fps; 100.1 / 216.7 ms frame p50/p95; 42 long tasks, 236 ms max | No code change. Trace recorded 1,060.5 ms `UpdateLayoutTree` and 530.1 ms `Layout`; per-frame `--hour` grid-height updates are a likely layout cause. | | Photos feed scroll | 13.7 fps; 66.7 / 100.1 ms frame p50/p95 | Kept `685b1105f`: 27.1 fps; 33.3 / 50.1 ms, 50.1% p50 improvement and lower p95. The controlled A/B points to shared backdrop filters as the main cost. | | Actual import, parsed-document reuse candidate | Baseline aggregate p50/p95 3,711.33 / 4,898.15 ms | Candidate 3,427.41 / 3,705.91 ms; p50 improved 7.65%, below the pre-set 10% keep rule, so the candidate was reverted. | Files, Calendar and Photos A/B profiles ran on the VM's native filesystem and are diagnostic, not HDD results. The synthetic HDD Actual preview used a 25,000-transaction, 15,389,723-byte archive and measured 5,955.02 / 6,118.53 ms p50/p95 over five samples. It did not reproduce the reported 30–45 seconds and is not comparable to the simpler native fixture. The HDD emulator passed qualification (QD1 125.0 IOPS, 7.96/8.29 ms p50/p99; QD16 200.9 IOPS, 100.14/104.33 ms). The populated Budget month fully-painted ready p50/p95, cold / warm, was: 390 light 1,127.8/1,227.8 / 1,399.5/2,047.2 ms; 390 dark 878.9/2,109.6 / 1,166.8/1,444.3; 820 light 660.1/1,703 / 1,363.4/1,597.3; 820 dark 1,040.1/2,340.9 / 1,466.7/1,638.9; 1440 light 1,020.7/2,901.7 / 1,574.4/1,594.3; 1440 dark 1,225.6/2,139.9 / 1,509.7/1,764.3. The common-route sample covered 24 routes. The slowest p50/p95 were Calendar range 42.0/74.2 ms, Analytics 40.9/70.3 ms, Files recent 30.1/53.7 ms and Files quota 19.4/24.6 ms. Idle RSS was 1,080,198,758 bytes and CPU 0.2%. A 12-second, concurrency-24 burst completed 84,077 requests with all 200 responses and 3.1/6.1 ms response p50/p95. ## Built and committed - Scroll-scoped shared-filter suppression with one root Photos scroll marker and `scrollend` / 140 ms fallback: `apps/web/src/lib/photos/PhotoTimeline.svelte`, `packages/ui/src/tokens.css`. - Production-route Photos A/B, state verification and Mac-platform screenshot capture harness: `apps/web/e2e/photos-perf.mjs`. - Money import benchmark follows Account-kind review, discard/re-preview and inferred-opening-balance confirmation: `bench/money-import-actual-462.mjs`. - Profile report, JSON and Chrome trace artifacts under `docs/perf/`; exact perf-lint pins refreshed after merging `origin/dev`. Commits: `685b1105f`, `95b98a770`, `21194cd30`, merge `3c3881845`, and report `c0c3bf233`. Decisions: keep the Photos change because it passed the 10% p50 rule without p95 regression; revert document reuse because it did not. No DESIGN decision was needed. ## Gates (verbatim summaries) `cargo fmt --check`: exit 0, no output. `cd apps/web && bun run check`: ``` perf-lint: PASS; 0 violations; 22359 scoped exceptions svelte-check found 0 errors and 2 warnings in 2 files ``` The two warnings are empty CSS rulesets in `packages/ui/src/components/calendar/AttachmentDeck.svelte:1055` and `AgendaList.svelte:1277`. No Rust source changed, so per-crate clippy/test gates did not apply. `cd apps/web && bun run test`: ``` Test Files 274 passed (274) Tests 1907 passed (1907) Duration 444.10s (transform 32%, environment 25%, import 22%, tests 17%, setup 5%) ``` `bun run build` passed after the merge. `cargo clean` removed 15,539 files / 6.3 GiB; `apps/web/build` was deleted after verification. ## Known gaps and UX gaps - The post-change Photos A/B on HDD and six Mac-platform screenshots (390/820/1440, light/dark) did not run: the perf VM lock remained held by another job until the four-hour time limit. The checked-in harness can capture them; no screenshots are attached. - Warm Tab switching, Search typing, and startup time after a migration remain unmeasured. The top-20 route set was not collected; 24 routes were sampled, with the slowest four listed above. - Files and Calendar causes remain likely diagnoses, not fixes. Photos A/B is native-filesystem evidence only. The money fixture is synthetic and does not reproduce the reported latency. - Existing follow-ups: Files/Calendar #549, Actual import #462, Search #258, startup #1161. The Paths #549 and #462 have this review's measurements in their comments. - UX gap closed: the Photos optimization applies to scroll input through the shared feed event and clears on scrollend or a short fallback; it adds no input-specific motion branch. UX gap left: required Mac-rendered screenshot review is pending because the locked VM run did not start. For the merge round: capture the pending Photos screenshots and HDD A/B under `/root/perf.lock`; measure warm Tabs, Search typing and startup after migration. No API route or Rust contract changed in this job.
Sign in to join this conversation.
No labels
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
kayg/calternal#1124
No description provided.