PERF: Calendar range p95 6.25 ms in Journal publication profile (baseline 4 ms) #706

Open
opened 2026-10-02 05:57:53 +00:00 by kayg · 1 comment
Owner

Found while measuring #653, release source 9b06f0491, on perf-test under exclusive /root/perf.lock. Average phase: 200 sequential single/batch write→read pairs on a growing Daily note (0→200 Logs). Every acknowledged write was visible in Journal, Calendar range/year and API Note reads.

Calendar range p50/p95: 2.95/6.25 ms. docs/perf/baseline.json records 1.7/4.0 ms; p95 is 56.25% above that reference and exceeds the 10% route threshold in bench/compare.py. The fixtures differ, so this is a follow-up measurement finding, not proof that #653 caused the whole difference.

Other phase numbers: write p50/p95 151.84/411.38 ms; Journal GET 2.37/6.67 ms; server CPU 87.660 s, 229.35% of wall time; RSS mean 488.20 MiB, peak 511.80 MiB, before/after 281.60/511.79 MiB. Load inside the lock: before 0.075/0.325/0.879; after 1.541/0.664/0.971. There is no paired Journal write/read or RSS baseline for this workload.

Profile: bench/journal-read-your-writes.py. Trace average and worst phases with the same dataset before changing publication. Keep #653 read-your-writes and #549 held-reconcile latency tests green. Performance does not block #653. Worst-phase numbers will be added when its one run finishes.

Found while measuring #653, release source `9b06f0491`, on perf-test under exclusive `/root/perf.lock`. Average phase: 200 sequential single/batch write→read pairs on a growing Daily note (0→200 Logs). Every acknowledged write was visible in Journal, Calendar range/year and API Note reads. Calendar range p50/p95: 2.95/6.25 ms. `docs/perf/baseline.json` records 1.7/4.0 ms; p95 is 56.25% above that reference and exceeds the 10% route threshold in `bench/compare.py`. The fixtures differ, so this is a follow-up measurement finding, not proof that #653 caused the whole difference. Other phase numbers: write p50/p95 151.84/411.38 ms; Journal GET 2.37/6.67 ms; server CPU 87.660 s, 229.35% of wall time; RSS mean 488.20 MiB, peak 511.80 MiB, before/after 281.60/511.79 MiB. Load inside the lock: before 0.075/0.325/0.879; after 1.541/0.664/0.971. There is no paired Journal write/read or RSS baseline for this workload. Profile: `bench/journal-read-your-writes.py`. Trace average and worst phases with the same dataset before changing publication. Keep #653 read-your-writes and #549 held-reconcile latency tests green. Performance does not block #653. Worst-phase numbers will be added when its one run finishes.
Author
Owner

The one worst-case run is complete, with the lock released between phases. On a Daily note with 10,000 existing Logs, eight concurrent write→read pairs all passed. Write p50/p95: 25,376.83/34,233.28 ms. Journal GET: 139.32/195.77 ms. Calendar range: 111.70/209.92 ms. Server CPU: 105.050 s, 304.46% of wall time. RSS mean/peak: 654.77/700.54 MiB; before/after: 604.95/700.54 MiB. Load inside the lock before/after: 2.309/1.014/1.042 → 3.273/1.382/1.165.

The 34.23 s write p95 is a user-facing limit to investigate. Profile per-User lock wait, the synchronous Note/Calendar/DAV transaction, the queued Task repair and Files watcher adoption on the same dataset. Keep publication before ACK and the held-reconcile read tests green. This is a performance follow-up; no missed acknowledged write, 5xx or crash occurred. Results: docs/perf/runs/2026-10-02-journal-read-your-writes-653.json.

The one worst-case run is complete, with the lock released between phases. On a Daily note with 10,000 existing Logs, eight concurrent write→read pairs all passed. Write p50/p95: 25,376.83/34,233.28 ms. Journal GET: 139.32/195.77 ms. Calendar range: 111.70/209.92 ms. Server CPU: 105.050 s, 304.46% of wall time. RSS mean/peak: 654.77/700.54 MiB; before/after: 604.95/700.54 MiB. Load inside the lock before/after: 2.309/1.014/1.042 → 3.273/1.382/1.165. The 34.23 s write p95 is a user-facing limit to investigate. Profile per-User lock wait, the synchronous Note/Calendar/DAV transaction, the queued Task repair and Files watcher adoption on the same dataset. Keep publication before ACK and the held-reconcile read tests green. This is a performance follow-up; no missed acknowledged write, 5xx or crash occurred. Results: `docs/perf/runs/2026-10-02-journal-read-your-writes-653.json`.
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#706
No description provided.