docs/testing/2026-10-27-local-vuh-42-tracker-journal/README.md

Built-in tracker write cost at fleet volume (LOCAL-VUH-42)

What one built-in tracker write costs as the store grows, before and after the ADR 0226 amendment. Measured 2026-10-27 on James's Mac (Node 26.12, APFS), each run inside clankie heavy.

Method

  • Store. flows/generate-store.ts builds a store at N days of fleet volume from a template.
    • The template was a scratch copy of the live ~/.clankie/tracker/tracker.json: 16.7 MB, 966 sync commits, 90 issues, 326 comments, 998 events, 687 receipts.
    • One day is 600 sync commits. Issues, comments, events, receipts and audit keep the template's proportions.
    • The template is repeated with each item's UUIDs remapped and every hash chain rebuilt, so the output passes the tracker's own validation at open.
    • The live store was only ever copied, never opened.
  • Timing. flows/bench-writes.ts copies a store into an empty scratch directory, opens it with createLocalTracker in a fresh process, and reports:
    • Cold open: the first list_issues call (parse, validation, chain checks).
    • Single write: p50 and p95 of 20 save_issue title updates, each keyed, after 3 warm-up writes. Each one covers the lock, load, apply, receipt, audit, sync commit and durable commit.
    • Burst: 17 sequential keyed save_issue creates, the 2026-10-03 burst.
  • HOME was a scratch directory throughout.
node flows/generate-store.ts --template COPY_OF_tracker.json --days 10 --out STORE_DIR
node flows/bench-writes.ts --store STORE_DIR --scratch EMPTY_DIR --writes 20
DaysSync commitsIssuesCommentsEventsReceiptstracker.json
1600562026204278.9 MB
106,0005592,0256,1994,26778 MB

Results

StoreBuildCold openWrite p50 / p9517 createsRSS
1 daybefore (f7845f6d9)49 ms118 / 123 ms2.0 s1.4 GB
1 daycopy-on-write, in-memory reuse55 ms33 / 37 ms0.58 s0.56 GB
10 daysbefore (f7845f6d9)307 ms1,036 / 1,164 ms17.7 s5.5 GB
10 dayscopy-on-write, in-memory reuse352 ms232 / 239 ms3.9 s1.2 GB

Hired-worker path. Production opens a fresh scoped backend for each hired worker's tool call (assertIssueWrite), so each timed write below goes through a new instance (--hire). The last column times the long-lived service instance's next read, which before re-parsed the store after every foreign commit. Every instance in the process now shares one frozen committed snapshot.

StoreBuildHire write p50 / p9517 createsService read after
1 daybefore (fcd07f990)129 / 142 ms2.3 s46 ms
1 dayshared committed store34 / 37 ms0.56 s0.7 ms
10 daysbefore (fcd07f990)1,060 / 1,125 ms18.4 s309 ms
10 daysshared committed store281 / 309 ms4.4 s8.7 ms

Where the old write went (CPU profile of 40 writes, 1-day store):

  • re-reading, parsing and chain-checking the store after the previous write: 37%
  • two whole-store structuredClones: 30%
  • serializing and fsyncing the whole file: 20%
  • diffing every sync model: 16%
  • tool logic: about 7 ms in total

Copy-on-write and in-memory reuse remove the first, second and fourth. What remains is mostly the whole-file write.

Part 2: the journal

The second half of the amendment appends each commit to tracker.journal/ and keeps tracker.json as a checkpoint. The stores below are the generated ones above, plus 30 and 60 days, each moved onto the journal by the real migration path. Two more flows were used:

bench-writes.ts gained --pollers N. It runs N sync subscribe long-polls on the timed issue's group throughout the timed writes, each re-subscribing after every page, as list_changes readers do.

node flows/migrate-store.ts --store STORE_DIR --scratch EMPTY_DIR
node flows/bench-writes.ts --store MIGRATED_DIR --scratch EMPTY_DIR --writes 40 [--hire] [--pollers 10]
node flows/journal-format.ts --segment MIGRATED_DIR/tracker.journal/000000000001.jsonl --scratch EMPTY_DIR

Raw output of every migration, bench and poller run: clankie://evidence/sha256/a43e1c9d3590c4986fce7090b37848d930a879bd41031f0f7af052736fee3b99 (manifest). The rollback recipe is in the work-items README.

Load. The machine is shared with the fleet, and the 1-minute load average was 8 to 22 on 18 cores during these runs. The same store varied up to 2× between runs, so each cell gives the range over every run, with the 60-day ranges over 4 runs per path.

Migration

Every check passed with nothing lost: each top-level collection and field of the checkpoint plus tail, and the sealed history segment, against the original file.

StoreOriginalCheckpointHistory segmentMoveRSSRecords checked
live copy16.7 MB7.9 MB5.3 MB145 ms0.4 GB90 issues, 326 comments, 998 events, 966 audit, 687 receipts, 966 sync commits
1 day8.9 MB5.0 MB3.9 MB103 ms0.3 GB56 issues, 202 comments, 620 events, 600 audit, 427 receipts, 600 sync commits
10 days78 MB45 MB34 MB735 ms1.1 GB559 issues, 2,025 comments, 6,199 events, 6,000 audit, 4,267 receipts, 6,000 sync commits
30 days233 MB134 MB100 MB2.0 s2.7 GB1,677 issues, 6,075 comments, 18,596 events, 18,000 audit, 12,801 receipts, 18,000 sync commits
60 days464 MB267 MB199 MB4.0 s4.0 GB3,354 issues, 12,149 comments, 37,193 events, 36,000 audit, 25,602 receipts, 36,000 sync commits

Writes

Before means origin/main 27f1f5ad0, and copy-on-write means patch 1 (450638515). Both were run on the single-file stores.

StoreBuildCold openWrite p50 / p9517 createsRSS
1 daybefore46 ms113 / 125 ms1.9 s1.4 GB
1 daycopy-on-write51 ms31 / 33 ms0.52 s0.6 GB
1 dayjournal39–45 ms5.0–5.3 / 5.3–11.8 ms83–92 ms0.3 GB
10 daysbefore294 ms1,008 / 1,064 ms17.9 s5.4 GB
10 dayscopy-on-write372 ms220 / 245 ms3.7 s1.2 GB
10 daysjournal184–252 ms5.2–8.8 / 6.1–11.9 ms0.11–0.21 s0.5–0.75 GB
30 daysbefore880 ms3,466 / 3,660 ms55.6 s11.4 GB
30 dayscopy-on-write971 ms746 / 806 ms11.0 s4.1 GB
30 daysjournal616–687 ms10.3–11.2 / 11.4–14.4 ms0.28–0.30 s1.0 GB
60 daysbefore, copy-on-write—first write fails: RangeError: Invalid string length in JSON.stringify——
60 daysjournal1.11–1.53 s11.7–21.7 / 14.3–39.8 ms0.41–1.01 s1.8 GB

The 60-day 39.8 ms p95 and 1.01 s burst came from the one run at load 20. The other three 60-day runs, at load 8 to 10, gave p95 14.3 to 24.4 ms and 0.41 to 0.55 s.

Hired-worker path (--hire: a fresh scoped instance per write, then the service instance's next read):

StoreBuildHire write p50 / p9517 createsService read after
1 dayjournal5.2 / 6.1 ms91 ms0.8 ms
10 daysjournal9.3 / 10.7 ms0.16 s8.2 ms
30 daysjournal12.9 / 15.8 ms0.30 s50 ms
60 daysjournal16.7–23.1 / 21.5–33.5 ms0.37–0.46 s129–145 ms

The service read after a hire write no longer re-parses; at 60 days it is the list_issues call itself, over 3,354 issues.

Acceptance (LOCAL-VUH-42)

Criterion at 1×, 10×, 60×Result
p95 single write ≤ 25 msMet at 1× and 10×. At 60×: reused instance 14.3–24.4 ms at load 8–10 (39.8 ms at load 20); hired-worker path 21.5–33.5 ms.
p95 within 2× of the 1× figureNot met at 60× (about 3–4×). The lead accepted the 25 ms bar; LOCAL-VUH-47 follows up.
17 sequential creates ≤ 1 sMet: 0.09 s, 0.21 s and 0.37–0.55 s (1.01 s in the load-20 run).
Cold open ≤ 2 sMet: 45 ms, 0.25 s and 1.1–1.5 s.

Long-polling subscribers

Ten pollers, 430 wake-ups per run, p50 / p95 over two interleaved rounds:

Store0 pollers10 pollers
10 days6.8–7.3 / 11.7–11.9 ms7.6–7.8 / 8.7–15.8 ms
60 days16.0–16.8 / 19.9–22.7 ms17.8–18.0 / 19.3–21.6 ms

Before subscribers read the current snapshot without the store lock, each re-subscribe queued for the lock ahead of the next write. Ten pollers then raised the p50 from 6.1 to 17.5 ms at 10 days, and from 22 to 43 ms at 60. A wake-up now costs about 0.27 ms of CPU at 60 days, measured by profile, and copies or parses nothing.

Checkpoint growth

The checkpoint holds no sync log. It grows with events, audit and receipts, by about 4.4 MB a day at fleet volume: 5 MB at 1 day, 134 MB at 30 and 267 MB at 60. At 90 days that projects to about 400 MB, with a cold open of about 1.7–1.9 s on a quiet machine, since cold open grew by about 19 ms a day here. Open still parses the checkpoint as one string. At about four months of fleet volume that reaches V8's maximum string length again, so retention or a streamed open has to come before then. That is recorded on LOCAL-VUH-47.

Format: JSONL against node:sqlite

500 commits of real journal records (mean 6.6 KB) from the migrated live copy, each made durable. Two runs:

FormatCommit p50 / p95Replay 500Size
JSONL, write at known end + fsync4.0–5.1 / 5.2–7.9 ms7.5 ms3.30 MB
SQLite WAL, synchronous=FULL, fullfsync5.0–6.9 / 7.0–9.2 ms7.5 ms3.75 MB
SQLite WAL, synchronous=FULL, plain fsync0.07 / 0.11–0.13 ms6.7–7.0 ms3.75 MB

On macOS, Node's fsync is F_FULLFSYNC, a disk cache flush. SQLite matches that only with fullfsync, and at that durability it does not win. The plain-fsync row survives a process crash but not a power loss.

Crash and integrity proofs

These are integration tests on the real store, real processes and real kill -9: tracker-journal.integration.test.ts.

  • Migration: a large store moves with every issue, event, audit entry and receipt intact, and the whole sync history still serves cursor 0.
  • Crash between append and fsync: a torn final line is left out, and the next commit, from another process, cuts it off.
  • Crash between checkpoint and rename: sealed segments, a new live segment, the old checkpoint and a leftover temp file reopen with every write, then commit and checkpoint again.
  • Twenty kill -9s of a writing process mid-write, alternating with this process's own writes. Every acknowledged write is present, at most the in-flight one is added, and a fresh process proves every chain and sealed segment. A killed holder's lock is aged past its 60 s stale window rather than waited out.
  • A checkpoint stopped after starting its new segment, then a restart (review finding B1): the start-up checkpoint runs before any commit, and a write follows. The empty segment stays live, so no sealed segment is empty, and a fresh process opens the store with the write. Without the fix, that reopen refused the store.
  • Replay gives the same store on every open, and a keyed retry after a checkpoint returns the original result.
  • A changed commit hash or sealed-segment byte refuses the open, for a fresh process and for a live one.
  • Ten long-pollers see every commit in order during a burst.
  • Cutover onto a journal-backed store, and switch-back, keep the whole history. The rollback export equals the cutover backup.
  • Teeth: dropping the torn-tail truncation, or the sealed-digest check, makes its test fail.

What remains

Done in LOCAL-VUH-47, with numbers in its measurement record. At the same load, 60-day p95 went to 7.0–7.7 ms plain and 6.7–7.1 ms hired, within 1.5× of one day.

LOCAL-VUH-47 is in Clankie Work's built-in tracker, P3, blocked by LOCAL-VUH-42. At 60 days the remaining per-write cost is spread across passes over whole collections:

  • the journal record's identity diff;
  • settling the snapshot;
  • the sync candidates;
  • receipt and bundle lookups by key;
  • GC.

Element reads on frozen arrays are 5–9× slower in V8 than on plain ones, and slice() of a frozen array is 26× slower than a spread. The copies here use spreads.