[Perf] JSONL backend re-decodes the whole session log on every read after an append (~286 ms at 9 MB), and why skipping the prefix is impossible

[dingminhua]

TL;DR

The JSONL backend re-decodes the entire session log on every read that follows an append, because coldLogMemo is keyed on a stat-derived revision and every append changes it. On a real 9.2 MB / 12 369-event session this costs ~286 ms per read; the identical read with no append in between costs 5.3 ms. The read-after-append read is the one the host performs every turn, so a long session pays it repeatedly.

I traced why the obvious fix does not work, and what does. Short version:

• Reparsing only the appended rows is impossible — the format decoder requires seq to be contiguous from 0, so history must be replayed. A patch that skips the prefix fails with seq gap (expected 0, got 12369).
• Keeping a decoder alive across reads works — it never re-reads history, it just keeps feeding it. A community plugin does exactly this and measures 11.8 ms for the same read (24×).

So the actionable question is not "cache better" but "may a decoder stay resident". That is a policy decision for this package, which is why I am reporting it rather than filing a patch.

---

1. Environment

Item	Value
DSH host	@deepseek-ai/dsh-desktop 0.2.1-rc.1 (installed build)
Backend	@deepseek-ai/dsh-session-persistence-jsonl 0.2.1-rc.1
Source reviewed	master @ 687f282e (release(dsh): 0.2.1-rc.2)
Runtime	Node v25.9.0, macOS Apple Silicon
Corpus	real artifact from ~/.dsh/sessions, 9.2 MB compressed, 12 369 events, seq 0…12368

Medians of 5 reads on the same fixture. Source line numbers are from master.

2. The mechanism

packages/session/session-persistence-jsonl/src/index.ts:

// :60-67
/**
 * Internal handoff-reuse policy, not deployment configuration: a cold
 * observation and the resume that immediately follows it reuse one parsed
 * log, so the memo only needs the sessions in flight between those steps.
 */
const COLD_LOG_MEMO_MAX_ENTRIES = 2

// :200  the revision is stat-derived
function fileRevision(identity: JsonlPhysicalIdentity): PersistenceRevision {
  return SessionPersistenceRevision([
    identity.dev, identity.ino, identity.size, identity.mtimeNs, identity.ctimeNs,
  ].join(':'))
}

revision includes size, mtimeNs and ctimeNs, so any append invalidates the entry. decodeStoredLog then does readFile → decode every frame → JSON.parse every line → validate, over the whole artifact.

The comment is explicit that the memo targets the cold-observation-then-resume case. I am not calling that wrong; I am pointing at the case next to it: a session that grows one batch at a time and is read after each batch.

3. Measurement

Same artifact, same backend, one append then one read:

Read	Median	Notes
Immediately after an append	286.5 ms	memo miss → full re-decode
Again, no append between	5.3 ms	memo hit
Immediately after an append, resident decoder	11.8 ms	no history re-read

The 54× gap between rows 1 and 2 is not I/O and not zstd — the file is in page cache. It is the JSON layer.

I also measured the session-switching case, where the 2-entry bound is usually blamed: with the bound raised to 8, the read after an append was still ~280 ms. Raising the bound does not help, because the append itself is what invalidates the entry. That rules out the cheapest suspected fix.

4. Why the obvious fix fails

I implemented "decode only the frames the append added" against master and measured it. It is correct but not faster (event hashes identical, 1.0×), and the reason is a hard format invariant:

• SessionLogScanner seeds a restore from the header and requires each row's seq to equal the running count (dsh-session-format-v1-to-v2/src/codec.ts:103, released v2 row ${currentRow} has seq gap (expected ${eventCount}, got ${event.seq})).
• Feeding only the appended rows therefore fails immediately: invalid committed event at line 1: released v2 row 0 has seq gap (expected 0, got 12369).
• SessionLogScanner.finish() is single-use and its restore is private, so an existing scanner cannot be cloned or resumed either.

Skipping history is not available at this layer. History must be read once and then kept, which is a different design:

5. What does work

A decoder that stays resident per session and is fed each append, never re-fed history:

1. On the first read, decode the artifact once and keep the reader (restore state, seq counter, committed events).
2. On a later read, if device+inode match, the file only grew, the header record is byte-identical, and every byte past the resident length is a complete independent frame, decode only those frames and feed them to the resident reader.
3. Re-run row admission, stored-event validation and relationship assertions on the new rows.
4. Anything else falls back to a full decode and drops the resident reader.

This keeps seq contiguous because the reader has been watching from row 0 — the invariant is satisfied by construction rather than bypassed.

Open question for the maintainers: residency means holding a parsed log in memory per session. coldLogMemo deliberately bounds this at 2 entries for exactly that reason, so a resident cursor needs its own bound (entries and bytes) and an eviction policy. A community plugin ships this with a configurable byte budget (default 128 MB ≈ 1 GB heap) and 8 entries; that is a reasonable starting point to critique, not a recommendation.

6. Correctness argument for the resident path

Reuse only when all hold, else fall back:

1. same device + inode, same path;
2. the file only grew and the header record bytes are unchanged;
3. every byte past the resident length is a complete, independently decodable frame (torn tail falls back);
4. the new rows pass the same admission/validation/relationship assertions the full path uses;
5. the returned revision is the observed one.

If any check cannot be proven, the read degrades to today's behaviour — never a different answer, at worst the same cost. The fallback is total, so a wrong guess cannot corrupt a read.

7. Prior art

dsh-coldread-cache (topic dsh-plugin) implements the resident-reader approach by patching the backend instance at runtime; the 11.8 ms figure comes from it, and it installs all six of its hooks on 0.2.1-rc.1. I am reporting the mechanism upstream because a plugin has to patch coldLogMemo, readStoredLog and four other members to do this, which is exactly the kind of thing that should not live in a third party if the behaviour is wanted.

If maintaining a resident decoder here is out of scope, a cheaper and still useful outcome would be documenting that read-after-append is inherently a full decode on the current design, so users can understand long-session degradation without profiling it themselves.

8. Reproduce

const real = ctx.get('sessionPersistence')[Symbol.for('cordis.original')]
const w = await real.open(id, 'write')
await w.read()
for (let i = 0; i < 5; i++) {
  await w.append([/* one batch */])
  const t0 = performance.now()
  await w.read()          // <- measured read
  console.log(performance.now() - t0)
}

Remove the append and the same read costs 5.3 ms — that difference is the whole finding.

---

External PRs are not accepted at the moment, so this is a report, not a patch. The incremental-decode experiment described in §4 is available on request if it helps rule that option out.

[PerryLink]

Confirmed, and there is a design reason for it that changes what a fix has to look like.

packages/session/session-persistence-jsonl/src/index.ts:

:199  /** Build the stat-derived best-effort change token shared by full and lightweight reads. */
:200  function fileRevision(identity: JsonlPhysicalIdentity): PersistenceRevision {
:201    return SessionPersistenceRevision([
:202      identity.dev,
:203      identity.ino,
:204      identity.size,
:205      identity.mtimeNs,
:206      identity.ctimeNs,
:207    ].join(':'))
:208  }

and the only cache on the read path, :312 private readonly coldLogMemo = new Map<SessionId, StoredLog>(). An append changes size and mtimeNs, so the stored entry's revision can never match the next read — the decode restarts at offset 0. That is your ~286 ms.

Two things worth adding to the report.

The memo is not a read cache that regressed; it is a two-step handoff. :62-67 says so explicitly:

/**
 * Internal handoff-reuse policy, not deployment configuration: a cold
 * observation and the resume that immediately follows it reuse one parsed
 * log, so the memo only needs the sessions in flight between those steps.
 */
const COLD_LOG_MEMO_MAX_ENTRIES = 2

So raising the constant would not help — the entry is invalidated by the append itself, which is the whole point of putting size/mtimeNs in the revision. If your report implies "make the cache bigger", a maintainer will read the comment and push back.

The revision also carries ctimeNs, so it moves on metadata-only changes too — a chmod or an external touch invalidates the memo just as an append does. That widens what "after an append" means, and it is a one-line addition to your measurements.

What a real fix has to be. Either decode incrementally from a stored tail offset (which needs per-file event-boundary offsets, since a JSONL line can span a read chunk), or split the token into an identity part and a content part so a read can decode only the new tail after matching the identity. Neither is a cache-size change, and both touch SessionPersistenceRevision, which is a branded opaque string — so this is closer to a format decision than to a performance tweak. Saying that up front is what will make the report actionable rather than dismissible.

If you have the numbers per phase (stat vs. decode vs. projection), put them in one table: 286 ms split across three steps is a much stronger argument than 286 ms total, because it tells the maintainer which of the two fix shapes is worth the format cost.

[dingminhua]

Thanks, this is a much sharper framing than mine and I think your two corrections are both right. I re-measured against them rather than just agreeing, and one of my original numbers needed correcting.

Per-phase split (what you asked for)

Fresh backend per trial, real session (~/.dsh/sessions, 9,682,953 bytes, 12,369 events, seq 0…12368), read after appending one four-event batch, median of 5:

Phase	Median	Share
stat	0.15 ms	~0%
readFile	1.9 ms	<1%
decode + project + validate	~280 ms	~100%
total, read after append	281 ms

So it is not distributed: stat is noise and the entire cost is decode plus projection. That supports your "format decision" read and rules out an I/O fix.

For contrast, on the same handle with no append between reads: 0.3 ms. That is not a cold decode at all — it is the handle serving resident state — so it is not a baseline to subtract from the 281 ms. That mistake is exactly what produced the wrong 5.3 ms figure in my first post, and it is worth flagging because the same handle-path shortcut will silently ruin any benchmark of this code: a "fresh backend instance" is not sufficient if a resident handle survives from an earlier open().

One measurement trap worth writing down: my first attempt at the ctime test measured 0.4 ms for a 12,369-event read and looked like a clean "no invalidation" result. It was measuring readPrimed (dsh-session-persistence-jsonl/lib/index.js:63-75), which returns from memory. The ctime effect only became visible once both reads were forced through a cold decode with the memo genuinely cold.

One number in my original report was wrong

I reported ~286 ms and ~5.3 ms as "read after append" vs "read without append". The ~286 ms holds up (~280 ms here). The ~5.3 ms does not generalise: it was a memo hit, and a memo hit is not a cold decode, so subtracting the two does not isolate the JSON layer. The 54× framing was wrong even though the underlying claim (read-after-append re-decodes everything) is correct. Corrected numbers are the table above.

Your ctime point is confirmed

Tested with one backend and two reads, the only variable being file metadata between them:

Between read 1 and read 2	read 2	memo
nothing	10.0 ms	hit
chmod twice (ctime only, content untouched)	305.5 ms	miss

A pure metadata change costs a full re-decode. This matters beyond chmod: anything that touches ctime externally — editors, backup or sync tools, cp-based restores, some security agents — turns an otherwise warm session cold. It widens the trigger from "after an append" to "after any metadata touch", which makes the case somewhat stronger than I originally put it.

On raising COLD_LOG_MEMO_MAX_ENTRIES

Agreed, and I measured it rather than assuming. Raising the bound does not help the append case, because the append changes size/mtimeNs and the entry therefore never matches — the bound only governs how many different sessions stay warm, not whether one session survives its own write. I'll drop that suggestion; it was the cheapest-looking fix and it is a dead end.

On the two real fixes you describe

Both of your sketches require the decode to resume rather than restart, and I hit a hard constraint there worth reporting back:

• SessionLogScanner requires every row's seq to equal the running count (dsh-session-format-v1-to-v2/src/codec.ts:103, released v2 row ${currentRow} has seq gap (expected ${eventCount}, got ${event.seq})).
• I implemented "decode only the newly appended frames" against master and it is correct but not faster: feeding just the appended rows fails immediately with invalid committed event at line 1: released v2 row 0 has seq gap (expected 0, got 12369). Event hashes were identical, speedup 1.0×.
• SessionLogScanner.finish() is single-use and its restore is private, so a scanner cannot be cloned or resumed either.

So "decode incrementally from a stored tail offset" is not reachable by skipping rows — the resume point has to carry the accumulated scanner state, not just a byte offset. That is what makes it a SessionPersistenceRevision / format change rather than a local optimisation, consistent with your conclusion but for a stronger reason than I first gave.

The option that does work is a per-session resident decoder that is fed each append and never re-fed history: seq stays contiguous because it has been watching from row 0. I measured that path at 11.8 ms on the same fixture (24× on the 280 ms). It needs its own entry and byte budget for exactly the reason your comment at :62-67 gives, so it is not free — but it is the only shape I could get to actually pass.

Revised question

Given the constraint above, the decision I'd put to you is narrower than my first post implied:

1. Is a resident decoder acceptable at all in this package, given it must hold parsed state per session with a bounded budget? If yes, the format question mostly disappears — SessionPersistenceRevision can stay as is, and the resident path falls back to today's behaviour whenever identity, header bytes or frame boundaries don't line up.
2. If no, then the honest fix is the revision split you described, and the seq-continuity constraint needs to be relaxed (or scanner state made resumable) before any decoding can skip a prefix.

I'd rather know which of those two doors is open than refine a patch that only fits one of them.

[dingminhua]

Thanks for reading it that closely — both corrections were right and I'm glad you pushed back on the memo-capacity framing before it turned into a wrong-headed patch.

The thing I took most from your reply is the framing itself: that this is a format decision rather than a performance tweak. I'd been circling that without naming it, and it explains why every local fix I tried (bigger memo, skipping the decoded prefix) came out either useless or rejected by the seq-continuity rule. Naming it correctly saves anyone else from repeating that loop.

I've posted the per-phase split and corrected the one number in my original report that didn't hold up, so the thread stands on its own as a record. Beyond that I'll leave the design question with you and the other maintainers — it's your package and your call, and I'd rather the report be accurate than persuasive.

Thanks again for the time.