PERF: Analytics GET waits for derived cache writes and recomputes cold history #782

Open
opened 2026-10-02 13:10:37 +00:00 by kayg · 4 comments
Owner

Found in the read-mostly server architecture audit #663. Applies DESIGN §58 rules 1, 2 and 8 from queued job/instant-663. Source base origin/dev = c4a61e8cf090170f35b1bed3350d9de20c83ecd5; pending origin/job/merge-round-7a = 2f4482ded066d9c5d9c59130377907f7fd2916c9. This is structural evidence, not a measured latency or confirmed security blocker.

Context: GET /api/v1/analytics is a normal Analytics Tab read. Calendar range #679 covers a different endpoint; #504 is visual work; #438 concerns physical Index separation.

Evidence:

  • crates/plugins/analytics/src/routes.rs:252–268: every report requests the current range, comparison range and streak lookback before the response.
  • cache.rs:59–128: misses call compute_span, then summaries awaits store before returning. A failed write is described as optional, but the read still waits for writer acquisition/transaction completion.
  • cache.rs:164–197: compute_span calls Calendar own_days plus Task counts and reduces detailed Log projections.
  • cache.rs:225: store begins on the single writer pool; it serializes payloads and inserts chunks within the transaction. Db checkout can wait 30 s (calternal-db/src/db.rs:59). This is a configured upper wait, not a measured duration.
  • cache.rs:74 deliberately stores only finished days; today's summary is recomputed on each request. Concurrent misses have no per-key coalescing here.
  • These functions retain the same behavior on round 7a.

Reasoned impact: a report with a cache miss waits behind unrelated durable writes even after its answer has been computed. Simultaneous first opens duplicate history projection/reduction; today's repeated reads also repeat work. There is no latency measurement in this finding.

Concrete fix: preserve the existing epoch fence and summary format. Return the complete calculated answer without awaiting cache persistence. Schedule bounded/coalesced persistence; precompute summaries after ingest and use a revision-keyed current-day summary. Keep reads on reader_pool, coalesce concurrent misses, and move expensive reduction off runtime workers or process bounded batches that yield. Keep accurate current/comparison/streak values; do not show stale totals as current. Reuse Calendar projections from #677 and cache helpers from #665.

Regression tests: hold writer_pool's only connection, seed cold summary inputs, and prove GET returns the correct report before writer release. Repeat concurrent misses and count one computation per User/timezone/revision. After an epoch change, stale work must neither persist nor overwrite the new answer. Test restart, current-day invalidation, timezone changes and User isolation.

Validation for the fix: preserve existing assertions and protocol status codes. Run per-crate fmt/clippy/test, plus calternal-server if the route or provider contract changes. Extend an existing bench profile with warm/cold latency, CPU, RSS and a realistic large-data burst. Measure ≥5 samples on the perf VM under /root/perf.lock with load recorded inside the lock and HDD emulation; compare only a matching baseline. The audit itself did not run a server or benchmark. No product edit is requested from the audit branch.

Found in the read-mostly server architecture audit #663. Applies DESIGN §58 rules 1, 2 and 8 from queued `job/instant-663`. Source base `origin/dev` = `c4a61e8cf090170f35b1bed3350d9de20c83ecd5`; pending `origin/job/merge-round-7a` = `2f4482ded066d9c5d9c59130377907f7fd2916c9`. This is structural evidence, not a measured latency or confirmed security blocker. Context: `GET /api/v1/analytics` is a normal Analytics Tab read. Calendar range #679 covers a different endpoint; #504 is visual work; #438 concerns physical Index separation. Evidence: - `crates/plugins/analytics/src/routes.rs:252–268`: every report requests the current range, comparison range and streak lookback before the response. - `cache.rs:59–128`: misses call compute_span, then summaries awaits store before returning. A failed write is described as optional, but the read still waits for writer acquisition/transaction completion. - `cache.rs:164–197`: compute_span calls Calendar own_days plus Task counts and reduces detailed Log projections. - `cache.rs:225`: store begins on the single writer pool; it serializes payloads and inserts chunks within the transaction. Db checkout can wait 30 s (`calternal-db/src/db.rs:59`). This is a configured upper wait, not a measured duration. - `cache.rs:74` deliberately stores only finished days; today's summary is recomputed on each request. Concurrent misses have no per-key coalescing here. - These functions retain the same behavior on round 7a. Reasoned impact: a report with a cache miss waits behind unrelated durable writes even after its answer has been computed. Simultaneous first opens duplicate history projection/reduction; today's repeated reads also repeat work. There is no latency measurement in this finding. Concrete fix: preserve the existing epoch fence and summary format. Return the complete calculated answer without awaiting cache persistence. Schedule bounded/coalesced persistence; precompute summaries after ingest and use a revision-keyed current-day summary. Keep reads on reader_pool, coalesce concurrent misses, and move expensive reduction off runtime workers or process bounded batches that yield. Keep accurate current/comparison/streak values; do not show stale totals as current. Reuse Calendar projections from #677 and cache helpers from #665. Regression tests: hold writer_pool's only connection, seed cold summary inputs, and prove GET returns the correct report before writer release. Repeat concurrent misses and count one computation per User/timezone/revision. After an epoch change, stale work must neither persist nor overwrite the new answer. Test restart, current-day invalidation, timezone changes and User isolation. Validation for the fix: preserve existing assertions and protocol status codes. Run per-crate fmt/clippy/test, plus calternal-server if the route or provider contract changes. Extend an existing bench profile with warm/cold latency, CPU, RSS and a realistic large-data burst. Measure ≥5 samples on the perf VM under /root/perf.lock with load recorded inside the lock and HDD emulation; compare only a matching baseline. The audit itself did not run a server or benchmark. No product edit is requested from the audit branch.
Author
Owner

Starting work on job/webperf, based on 2f4482ded066d9c5d9c59130377907f7fd2916c9 (job/merge-round-7a). I am reading the matching audit evidence and will report the concrete finding, regression coverage, measurements, and gate output here when finished.

Starting work on `job/webperf`, based on `2f4482ded066d9c5d9c59130377907f7fd2916c9` (`job/merge-round-7a`). I am reading the matching audit evidence and will report the concrete finding, regression coverage, measurements, and gate output here when finished.
Author
Owner

Finding: concurrent Analytics misses could repeat the same Index projections and wait for the shared Index writer while persisting Derived summaries. Identical misses now share a flight, unique projections are capped at 16, and one best-effort background writer handles summary persistence. Added flight, compute-limit and busy-writer tests, plus a warm-year/24-request burst profile. The profile has not been run yet; Rust gates are still in progress.

Finding: concurrent Analytics misses could repeat the same Index projections and wait for the shared Index writer while persisting Derived summaries. Identical misses now share a flight, unique projections are capped at 16, and one best-effort background writer handles summary persistence. Added flight, compute-limit and busy-writer tests, plus a warm-year/24-request burst profile. The profile has not been run yet; Rust gates are still in progress.
Author
Owner

F6 — P2: Analytics cache tests race the detached writer

Owner: #782. Introduced by f5c216420.
Evidence: crates/plugins/analytics/src/cache.rs:238, :239 and
crates/plugins/analytics/src/tests.rs:303, :688.
Reports now return before the spawned cache transaction commits. Existing tests
immediately make a second report and require warm hit counts. The first
stats.stored value now counts scheduled rows, so it does not establish that
the second report can read them. The tests can fail under a valid scheduler
order or a busy writer, even when report values are correct.

Fix: keep the old hit and total assertions. Give the tests a completion signal
or await the committed cache rows before the second report. Do not put the
writer wait back into the production response path. Change the profile warmup
at apps/web/e2e/analytics.mjs:1147 to establish committed cache readiness too.
Rule: the owner forbids weakening an existing expectation to make a test pass.
Test idea: hold the writer connection, return the first report, then release it
and await cache completion before checking the second report. The first report
must still finish while the writer is held.
Search before reporting: #782 and its comments. Use #782 for this fix.

## F6 — P2: Analytics cache tests race the detached writer Owner: #782. Introduced by `f5c216420`. Evidence: `crates/plugins/analytics/src/cache.rs:238`, `:239` and `crates/plugins/analytics/src/tests.rs:303`, `:688`. Reports now return before the spawned cache transaction commits. Existing tests immediately make a second report and require warm hit counts. The first `stats.stored` value now counts scheduled rows, so it does not establish that the second report can read them. The tests can fail under a valid scheduler order or a busy writer, even when report values are correct. Fix: keep the old hit and total assertions. Give the tests a completion signal or await the committed cache rows before the second report. Do not put the writer wait back into the production response path. Change the profile warmup at `apps/web/e2e/analytics.mjs:1147` to establish committed cache readiness too. Rule: the owner forbids weakening an existing expectation to make a test pass. Test idea: hold the writer connection, return the first report, then release it and await cache completion before checking the second report. The first report must still finish while the writer is held. Search before reporting: #782 and its comments. Use #782 for this fix.
Author
Owner

Finding: Analytics reports return before the detached cache transaction commits. On the first crate test run, files_count_on_their_local_day_across_dst read analytics_days immediately after the report and failed with RowNotFound (33 passed, 1 failed). This was a valid cache-write schedule, not a wrong report value.

Fix: the DST test now waits for the scheduled Berlin cache rows before checking its 23-hour day window. The other warm-cache tests use the same bounded row wait, and the Analytics E2E profile polls server-timing until it sees a committed-cache hit before measuring warm reads. Existing hit assertions remain intact; the production handler still returns without waiting on the writer.

Verification: cargo clippy -p calternal-plugin-analytics --all-targets -- -D warnings passed. Final cargo test -p calternal-plugin-analytics passed: 34 passed, 0 failed; doc tests 0 passed, 0 failed. Fix commit: 4210d4659.

Finding: Analytics reports return before the detached cache transaction commits. On the first crate test run, `files_count_on_their_local_day_across_dst` read `analytics_days` immediately after the report and failed with `RowNotFound` (33 passed, 1 failed). This was a valid cache-write schedule, not a wrong report value. Fix: the DST test now waits for the scheduled Berlin cache rows before checking its 23-hour day window. The other warm-cache tests use the same bounded row wait, and the Analytics E2E profile polls `server-timing` until it sees a committed-cache hit before measuring warm reads. Existing hit assertions remain intact; the production handler still returns without waiting on the writer. Verification: `cargo clippy -p calternal-plugin-analytics --all-targets -- -D warnings` passed. Final `cargo test -p calternal-plugin-analytics` passed: 34 passed, 0 failed; doc tests 0 passed, 0 failed. Fix commit: `4210d4659`.
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#782
No description provided.