Repository navigation
[Bug] Two concurrent owners corrupt one session log, then the whole history fails to load with a misleading "torn JSONL record" error #6500
Replies: 1 comment
Thank you for this report — the level of detail made it directly verifiable. I checked every claim against the source, and the diagnosis is correct in substance. Summary up front:
Root cause — confirmedAt
So: two writers, overlapping seq regions, gapless-chain violated, whole-log refusal on every later load. Confirmed. The misleading message — confirmed (with a nuance)At const complete = scanner.checkpoint()
if (complete.committedBytes !== complete.inputBytes) throw new Error('corrupt Zstandard session log: complete frame contains a torn JSONL record')One nuance on your parenthetical "a torn record can only occur in an incomplete final frame": a complete frame can also end in a JSONL record missing its newline terminator — that is the genuine case the wording names (it is pinned by the test "rejects a complete frame containing a torn JSONL record" in Fix status on master (HEAD
|
Uh oh!
There was an error while loading. Please reload this page.
Summary
A session that is still live in one DSH process can be resumed by a second process. The second
process performs a durable crash repair of the open tail turn (synthetic interrupted-turn closers
appended to the log) while the first process is blocked in a long tool call. When that tool call
returns, the first process appends its real result starting at the same
sequsing its ownin-memory cursor. The log then contains two interleaved, seq-overlapping histories, and every later
load of that session fails — the entire history, not just the tail — reporting:
which is misleading: every Zstandard frame is checksum-valid and every JSONL record parses. The real
defect is a
seqregression, and the exact reason is recorded inSessionLogScanner.issuebutdiscarded by the throw at the end of
readZstdPrefix.Environment
@deepseek-ai/dsh0.1.2-rc.1 (alsodsh-session-persistence0.1.2-rc.1,dsh-session-persistence-jsonl0.1.2-rc.1,dsh-session0.1.2-rc.1)compression: "zstd"Mechanism (what actually happens)
S. It writestool/call(seqN) for a blocking tool(
{job_id, wait: true, timeout_ms: 120000}) and blocks for two minutes. A's in-memory cursor isN+1.turn with a recorded-but-unresolved tool call, and treats it as crash residue:
interruptedTurnClosers()produces synthetic events (an errortool/resultinterrupted-tool-result-<callId>-<seq>,step/end,turn/end{reason:"interrupted"},session/end-seed), and they are written into the same file — sequencesN…N+3. B's cursorbecomes
N+4, and B starts its own new turn.tool/resultat seqN— its own stale cursor —and continues its turn. A never notices, because the live-writer path appends from in-memory
state.cursorwithout re-checking the file revision.its event chain is not monotonic: it reaches some seq
M, then jumps back toN.Evidence (seq-level, from the two real logs)
Log 1 (larger, 2.8 MB, 5,845 frames, 10,122 records, all frames checksum-valid, last byte newline):
N(e.g. 190214)tool/call→ blocking tool{job_id:"<job>", wait:true, timeout_ms:120000}N+1…N+4(same second)interrupted-tool-result-<callId>-<seq>,step/end,turn/end{reason:"interrupted"},session/end-seed— written durably by Btool/resultat seqN+1(same callId, real output), turn continuesseqregionN+1…Mwritten twice,seqN+1appears twice with different payloadsM_committed, then seesN+1→ chain broken at byte 6,955,318 (JSONL line 9853)Log 2 (smaller, 349 KB): same mechanism, only 3 divergent events, which makes it easy to read:
3819: syntheticinterrupted-tool-result-<callId>-3819(process B) vs the realtool/result(process A)3820:step/endin both branches3821:turn/end{reason:"interrupted"}(B) vsstep/start{step:8}(A)24814; B's branch contributed only those 3 synthetic eventsReconstructed event counts using the real backend (
readPrefix): branch that ends at the newestwrite = 193,806 events (log 1) and 24,815 events (log 2); the other branch of log 1 = 193,179 events.
Why the error message is misleading
SessionLogScanner.consumeEventLine()records the real cause inthis.issue(
corrupt session log: unparsable committed event at line Lorcorrupt session log: seq gap in committed region at line L (expected X, got Y)) and only throws itimmediately if a later record in the same scan is a
turn/end. Otherwise the scan ends andreadZstdPrefixthrows the generic byte-count message, discardingissue:committedBytes !== inputBytesis not sufficient for "torn record": a torn record can only occur inan incomplete final frame, and this code path handles complete frames only. That is why the same
defect produced two different messages in two logs — the log whose divergent branch happened to
contain a later
turn/endreported the truthful cause, the other one reported "torn JSONL record".Code locations (0.1.2-rc.1)
packages/session/session-persistence/src/index.ts—prepareCore()(interruptedTurnClosers(storedEvents)),commitPrepared()→backend.commitRepair(...),borrowSession()(read-only observation, no commit),appendCore()→adopt()→prepareCore()+commitPrepared(),appendCore()'sstate.cursor-based seq check.packages/session/session-persistence-jsonl/src/index.ts—commitRepair(),SessionLogScanner(
issue,checkpoint()),readZstdPrefix(),scanZstdFrames().packages/session/session/src/repair.ts—interruptedTurnClosers()(timestamps reuse the last real event).already has a live persistence owner,cannot prepare session "..." while it is live, and the API session controller'shasApiSessionSubagentOwner. There is no cross-process lock or claim on the log file.Suggested fixes
LockFileEx) beforecommitRepair/appendBatch; or verify that the durable revision has notadvanced since the in-memory state was built, and fail loudly instead of interleaving.
borrowSessionalready shows the read-only pattern (repair in memory, no commit); a cold load could do the
same, or write repair artifacts to a side file.
scanner.issueinreadZstdPrefix(and only use the "torn record" wording when arecord really lacks a terminator), including the byte offset of the break.
since
committedBytesis already computed. Please do not auto-truncate: on a seq regressionthe other branch's data would be silently discarded, so the user must choose.
A one-line equivalent of fix 3 that I applied locally to diagnose this:
Workaround for users
dangerous action is resuming/continuing a session id that another process still runs
(a second terminal, a second browser tab/window, GUI + CLI).
job_output{wait:true},long-running shell tools, waiting on approvals).
at the newest write) and preserve the other branch as its own session. Both branches were fully
recoverable in my case.
Recovery data point
Both affected sessions were recovered with the real
readPrefixverifying the rebuilt logs:193,806 events (torn=none),193,179 events (torn=none),24,815 events (torn=none).I can provide a scrubbed minimal reproduction (no user data) or a synthetic log pair on request.
All reactions