sessions: SQLite runtime reads ~2 TB/3 h from sessions.db on a busy profile

[ScriptedAlchemy]

Summary

On the operator daemon (beta.60 541e98e, PID 521340, up 2 h 49 min at 21:56 UTC) the SQLite runtime threads read 2.04 TB through read(2) (tracedecay-rusq threads, 509.6M read syscalls, 8389 CPU-s), plus 587 GB on tokio workers. Syscall sampling of the hot tracedecay-rusq threads shows pread64 on the project's sessions.db (16.4 GB) and user-sessions.db (14 GB) and on deleted /var/tmp/etilqs_* files (SQLite temp B-trees for sorts/GROUP BY). One thread alone was reading ~1 GB/s and writing ~666 MB/s over a 10 s window at 20:33 UTC.

This is separate from #2505: an isolated daemon indexing a full clone of the same repository with an empty session profile shows tracedecay-rusq threads at 0.2 GB read in 42 min, so the traffic is session/observation storage work, not code-graph publication.

Evidence (read-only, supported surfaces)

/proc/521340/io            rchar=2868777543478 wchar=838231194338 syscr=2860184121
per thread group (rchar)   tracedecay-rusq 2040 GB  tokio-rt-worker 587 GB  tracedecay-inde 223 GB
hot rusq fds               39,96,36,42,46 -> projects/proj_a5b3d7e3ebe14ca7/sessions.db
                           25 -> user-sessions.db, 73/18 -> /var/tmp/etilqs_* (deleted)
journal                    "exact SQL reader lane is saturated", "SQLite advance query failed: interrupted",
                           "projection output collided; recording a durable skip disposition" (repeated)

Expected

Measure (Hotpath) which session-store queries do full scans or temp-B-tree sorts over the 16 GB store per ingest/projection pass and fix the mis-sized work (index or batching), rather than per-row rescans. Found while root-causing #2505.

[ScriptedAlchemy]

#2616 (c067b81) landed part of this.

Live attribution (read-only; beta.60 PID 521340, up ~9 h):

• rchar 10.08 TB: tracedecay-rusq 7.37 TB, tokio-rt-worker 1.95 TB, tracedecay-inde 0.69 TB.
• The hot rusq threads read 2.76 and 2.26 GB/min in 4 KB pread64s on projects/proj_a5b3…/sessions.db and proj_8416…/sessions.db, and wrote SQLite temp B-trees to /var/tmp/etilqs_*.

Root cause fixed in #2616: every project-scope host drain ran a Git evidence convergence pass. That pass grouped every session over the whole message activity index before filtering to its frontier, so each drain read O(store). The same PR fixes the full-scan derived-anchor lookup and the all-schema snapshot pin.

On a 2.7 GB reproduction store:

• Git page: 4.2 MB → 94 KB per pass.
• backfill.collect: avg 187 ms → 7.3 ms.
• Derived anchor lookup: 1.14 MB → 13.6 KB per call.

Remaining store-scaled reads on the same path, filed separately: #2597 (pending projection pick), #2606 (refresh discovery groups every observation effect), #2607 (relation refresh re-reads the whole session per message). This issue stays open until those land and the live daemon's rates are re-measured.

[ScriptedAlchemy]

Progress since #2616. The reproduction is the 1,200-transcript isolated profile: project sessions.db 1.65 GB, user-sessions.db 1.80 GB, 8 live transcripts at one message per 0.5 s.

• perf(sessions): scale discovery and pending picks with new work #2639 (fd451f3) fixes sessions: external-source pending pick scans and sorts all pending rows per item #2597 (pending pick index) and sessions: refresh discovery groups every observation effect per pass #2606 (refresh discovery resumes from an effect cursor; the repair sweep no longer restarts each wake). It also indexes sessions(session_id, …) lookups.
  • Bytes per streamed message: 17.5–20.2 MB → 6.4–6.7 MB, from two A/B runs each.
  • session_temporal.query.pending_refresh: avg 48.35 ms / p95 163 ms → 4.08 ms / 4.82 ms.
  • Through the public ingest path, one streamed message on an 8× larger store reads 1.34× (2,607,012 → 3,528,462 bytes; 2.85× on master). A 16× larger pending backlog reads 1.55× per message (3.17× on master).
• perf(sessions): keep retention scans out of write transactions #2646 (9606347) moves every store-sized retention scan out of the write transactions. That was the cause of SQLite transaction lease expired.
  • Retention writer VM steps on an 8× store: 1.00× (6.4× on master).
  • sessions.lcm.gc.apply transaction: avg 4.88 s → 1.74 ms.
  • sessions.lcm.retention: 2.57 s → 86 ms.

Still open, so this issue stays open:

• sessions: relation refresh rereads the whole session per appended message #2607. Every refresh copies, rebuilds, and re-digests the whole session generation. Bytes per streamed message now grow with session length: 3.2 → 7.2 MB/msg of generation-path reads between two consecutive windows as the live sessions grew. It is 43–50% of stream reads. It needs a generation-model change (details on sessions: relation refresh rereads the whole session per appended message #2607).
• retention: payload GC closure and observation selection read the store every tick #2647. Retention still reads the store per tick on the reader: the GC reference closure and the observation candidate selection. No longer inside the lease.
• sessions: authority audit checkpoint aggregates whole projection tables per chunk #2641. The authority audit checkpoint aggregates whole projection tables per validated chunk: 7.9k runs and 226 s of reader-lane time per 5-minute stream window.

The live daemon's rates have not been re-measured; that needs a release build to be installed.

[ScriptedAlchemy]

#2761 (9d91e64) removes the projection's share of the growth: refresh generations now extend their base instead of copying it, and per-message projection work is flat.

• Public-ingest growth test, live session N → 8N: master 877,992 → 4,869,410 read bytes per streamed message (5.55x); after the fix 511,397 → 579,899 (1.13x).
• perf(sessions): bound git convergence reads to new activity #2616/perf(sessions): scale discovery and pending picks with new work #2639 reproduction, per streamed message: coverage bytes 559 KB → 22.8 KB, rows hashed 197 → 18, parent-resolver bytes 116 KB → 4.1 KB.
• Whole-daemon reads per streamed message across two stream windows: master 9,599 → 11,166 KB (still growing); fix 6,674 → 6,307 KB (flat).

I'm leaving this issue open. The remaining ~6.5 MB of daemon reads per message comes from the capture path re-reading external-source state (#2658), and that still scales with store size rather than with the message.

[ScriptedAlchemy]

Status after #2761 (relation refresh) and #2777 (capture reads only the objects it names). The remaining large whole-daemon read source is #2774. After any project open, the temporal-refresh history pass retries ingest_pass_backpressured every 250 ms. Each retry is a full project ingest that re-scans every unchanged transcript.

On an isolated 17k-message profile, Hotpath counts 530 such passes in 248 s idle. They read about 1.1 GB of scan payload plus 378 MB of prefix validation, and the daemon reads 11–15 MB/s with no new messages. Leaving this open until #2774 is fixed and the whole-daemon bytes per streamed message can be measured flat.

[ScriptedAlchemy]

Re-measured after #2779 and #2786 (isolated hotpath daemon; 120 streamed messages per window, 183 ingested):

Store	Raw bytes per message	Net bytes per message
Base (about 7.6k messages)	2.48 MB / 2.05 MB	2.18 MB / 1.81 MB
8× (about 60.6k messages), before #2786	32.4 MB / 19.3 MB	32.0 MB / 19.05 MB
8× (about 60.6k messages), after #2786	5.05 MB / 3.11 MB	window 2: 2.82 MB

Whole-file Codex rereads and per-rollout git matcher spawns were the store-scaled cost, not index depth. #2786 removed them: scan_prior went from 17,600 calls to 0, and matcher_new from 17,693 calls to 0.

What remains is about 1.5× growth. Hot B-trees are 2–5 levels deep at the base store and gain at most one level at 8×, which would allow up to (d+1)/d, i.e. 1.25–1.5×. Two things keep me from attributing all of it to depth:

• page attribution in an in-crate probe showed WAL reads and external_source_retained_receipts_v1 growing faster than their depth;
• the Codex session_meta head is still re-read once per unchanged rollout per pass (Codex history pass re-reads session_meta of every unchanged rollout #2787).

I am not closing this issue, because remaining growth is not yet shown to be only index depth.

[ScriptedAlchemy]

Idle measurement on master 4d02e1b (release production build, isolated daemon under a 6 GiB scope). The profile is tiny: 2 projects, 13 session messages in total (5 synthetic Claude/Codex/Cursor transcripts). Nothing was changing.

/proc/<pid>/io over 120 s idle: rchar +8.63 MB, syscr +20,858, read_bytes +762 KB, CPU 1.1 s.

strace -f -y -e trace=read,pread64,openat for 60 s, idle, bytes by file:

2,637,824  projects/proj_…/sessions.db        (4 KB pread64s)
  786,432  projects/proj_…/sessions.db-wal
  110,592  user-sessions.db-wal
   90,112  user-sessions.db
   72,082  projects/proj_…/dashboard/automation_runs.jsonl   (253 read calls/min)
   41,754  projects/proj_…/dashboard/automation_effects/<id>.json

strace -e trace=execve, 60 s idle: 22 git spawns per minute. Ten are git -C <root> rev-parse --show-toplevel --git-dir --git-common-dir, six are git rev-parse --verify --quiet --end-of-options main^{commit}, and six are git log main --pretty=%H %ct --max-age=….

So about 2.6 MB/min of sessions.db page reads continue on a 13-message store with no new activity. The separate replaced-transcript re-read loop is filed on its own.

[ScriptedAlchemy]

#2948 (f0df9bc) sizes the writer page cache from the schema: 2,276 pages for the registered sessions.db, up from about 500. That removes interior-page re-reads on grown stores; per-message ingest reads on an 8× store dropped from 2.48× to 1.24× the base. It has not been checked against operator-scale read volume, and #2658 (whole-binding external-source reads) and #2939 (9 WAL commits per message) are still open, so this stays open until it is re-measured on a busy profile.