[Bug] Cold history loading fully materializes large/corrupt logs and can stall the entire Web server #1550
Replies: 8 comments
|
Confirmed against master — and the "server-wide availability" framing is the important part. This is the availability amplifier of the corruption family I've been tracking all day (#1333/#1452 seq gaps, #1473 bad frame, #1497 replayed tail): corruption alone makes one session unreadable, but the full-scan-on-cold-load behavior turns it into a whole-server stall. Source confirmation
So a cold Why this is worse than the corruption aloneThe four-thread family has a consistent theme: one bad log = disproportionate blast radius. Here the blast radius isn't just "session unavailable" — it's
Suggested regression shapeA test that opens a cold session with a large/corrupt artifact and asserts the inspect/history call either (a) returns within a bounded number of decoded frames, or (b) fails fast with a cheap scan error — never full-materializing. Combined with the existing corrupted-log fixtures, this would have caught today's incident. This also feeds the S6/S7 checks in moonquake2004's |
|
The offline side of this is now covered — for anyone who wants to identify which sessions to quarantine without starting dsh:
Thanks for the field numbers — they calibrated the thresholds. |
|
Supplementing with a reproduction that needs no corruption at all — pure scale, and the stall is boot-wide, not only on cold-open. Boot materializes ALL sessions, valid or notWith 15 valid sessions (several 1.8–2.7 MB compressed / ~300k tokens / 5–7k events each) in
Workspace archiving does NOT reduce thisTested on the same session set:
So the materialization surface is the sessions directory, adopted in full at boot, regardless of the workspace archive set and of Verification method: |
|
Verified the cost cascade and one config surprise against master (47f9438) — your field numbers are the per-session amplifier in action, and there are three details the thread doesn't have yet: 1. Why 2. The heap amplification is a decode+clone cascade, not raw log size. 3. On current master I could NOT find a boot sequence that enumerates all persisted sessions. Fix direction this adds: bound |
|
I prepared a tested reference hardening patch in a fork so maintainers (or a coding agent) can inspect or cherry-pick it directly:
Reproduction and evidenceThe observed sequence was:
Source-level root causeThere are three interacting causes:
Fix in the forkThe patch adds:
Validation on Windows/Node 24:
This is intentionally an interim hardening patch, not the complete bounded-window/paginated history design discussed above. It prevents the corruption recurrence demonstrated here and removes the worst repeated-scan/event-loop amplification; a true O(window) Existing corrupt historiesThe runtime patch intentionally does not silently rewrite an already-conflicted log because a backward Until an upstream fix lands, the simplest safe workaround is: never let two DSH processes write the same Session, stop all other DSH instances before resuming it, and back up the persistence root before repairing any existing conflict. |
|
Reviewed the patch (fork branch 1. Cross-process writer lease ( 2. Cached deterministic read failures — kills the repetition of the stall. 3. What the patch does NOT cover (for the maintainer's cherry-pick decision)
Net: this is a solid, well-tested PR-ready hardening that closes the concurrency gap and the repeat-stall gap; the pure-scale materialization and the boot-block paths need the two follow-ups above. Worth opening as a PR when the upstream PR channel reopens. |
|
7889545's scale numbers are directly relevant to the offline side: their 15 sessions (each ~20–40MB decoded) cost ~200MB heap apiece — but that's below our current per-session oversized threshold (decoded >10MB / >10k frames), so our whole-session scan would NOT have flagged the exact profile that stalled their boot. The lesson: the materialization-risk bar belongs on the workspace total, not per-session — boot/heap cost is cumulative across adopted sessions. Done — S11 now carries a total-materialization line: it sums decoded bytes/events across all sessions and flags when the workspace total crosses a bound (150MB decoded). Verified: a synthetic 5-session / ~190MB-total profile now trips it even though each session is individually ordinary; our own live profile (~14MB largest) stays clean. So the 7889545 profile shape is now caught offline, before boot. Also agree with the patch review's remaining-gaps framing: the writer-lease / cached-read-failure / 16ms-yield patch closes the concurrency and repetition gaps; the first-open materialization, #1473 boot-block, and #1497 watermark follow-ups are exactly what S11 surfaces offline (corrupt → quarantine, oversized → warn). |
|
Following up on the offline-side threshold — I re-calibrated S11's materialization-risk metric with real measurements instead of a heuristic, and want to share both the method and the residual uncertainty: Measurement (real, our 0.1.0-rc.6 web session, 420k small events / 15MB decoded):
Recalibrated formula: The max() covers both regimes: small-event sessions (events term) and large-event sessions (bytes term). Scenario matrix (verified with synthetic profiles): events-term triggers / bytes-term triggers / below-line clean / 7889545-scale (176MB decoded) trips the default 1GiB / corrupt → quarantine / plain- Residual uncertainty (worth your input): the clone factor 2-3× is from source analysis, not measured in the harness — a real heap number for a known session set (7889545's 3GB on 15 sessions implies ~6-10× on bytes) would pin the byte coefficient; the exact stall point per RAM/OS is still unmeasured. The per-session threshold (10MB / 10k frames) stays as an independent safety net. Also fixed while auditing: plain |
Uh oh!
There was an error while loading. Please reload this page.
Summary
Opening a cold, very large session calls the persistence inspection path before response pagination is applied. The server therefore decompresses, parses, validates, and materializes the complete event stream on the Node.js main thread even when the client requests only a bounded history page.
In a field incident, one structurally valid large session and one session with a committed
seqrollback madedsh webaccept TCP connections on127.0.0.1:3080while evenGET /timed out. Quarantining only those session trees and restarting restored normal response times.The writer-corruption mechanism is already tracked in #1433, #1452, and #1497. This report is specifically about the server-wide availability and repeated full-scan amplification when the client opens one large or corrupt cold history.
Environment
v24.14.1@deepseek-ai/dsh@0.1.0-rc.6dsh web47f943859bef60e4160492346772ded9b24f765aUser-visible behavior
Startup printed the normal address:
The process was listening, but an HTTP request did not complete:
During the stall:
The corrupt history RPC returned:
Default persistent logs did not capture this failure. The Web stdout log contained only the bound URL and stderr was empty. The error was available only in the browser/RPC response and was later confirmed deterministically from the raw session artifact.
Session evidence
The two private session IDs and raw artifacts are intentionally omitted because they contain user conversation data.
Session A: corrupt committed history
The durable event boundary was:
Independent scanning reports
expected 249442, got 249438. An older backup of the same session contained the sameN -> N-4shape (expected 187372, got 187368). This matches the already reported overlapping/stale-writer family in #1433, #1452, and #1497.Session B: structurally valid but very large
This session has no sequence gap. It reproduces the excessive cold-history/resume work independently of structural corruption.
Source-level cause
For a cold session,
historySourceFor()callssessionPersistence.inspect(sessionId)and receives the full event array:api-proxy.tslines 1533–1538Only after that complete inspection does
historyPage()applypaginate(events, request.maxMessages, ...):api-proxy.tslines 805–818api-proxy.tslines 2242–2259The client requests history immediately when opening a conversation:
session.tslines 614–642The error handler converts an inspection failure into an RPC
internalresponse but does not persist a structured server-side diagnostic:api-proxy.tslines 2260–2269As a result,
maxMessagesbounds the returned payload but does not bound persistence I/O, Zstd decompression, JSON parsing, validation, or event materialization. Reopening or retrying the selected conversation repeats the expensive work. Because this work shares the Web server's Node.js process, unrelated requests can become unresponsive.Reproduction
A safe synthetic repro should use an isolated temporary
DSH_HOME:dsh weband open that cold conversation.GET /latency and event-loop responsiveness.Actual result: history loading repeatedly performs full inspection; the selected history may fail, and unrelated HTTP requests can stall.
Expected result: bounded history reads should do bounded work; one corrupt session should fail in isolation without affecting the rest of the Web server.
Suggested fixes
maxMessageswhile reading rather than after full materialization.$DSH_HOME/logs, including session ID, record/frame position, expected/actual seq, and stack trace.dsh session verify/dsh session quarantinecommands.The correctness fixes proposed in #1433/#1452/#1497 (cross-process writer ownership and durable-tail validation) remain necessary; the measures above limit the blast radius when corruption or unusually large histories still occur.
Workaround verification
The two affected root sessions and their descendants were moved out of the active session root, not deleted. After one clean restart:
Other histories remained available. This A/B result isolates the outage to active history discovery/loading rather than installation, networking, or the static Web bundle.
All reactions