Repository navigation
Migrated session logs put the entire history in a single Zstandard frame, so opening one large session allocates ~120 MB at once #9660
Replies: 3 comments
|
Additional evidence, from reading the shipped packages of this release (no host-specific data): 1. The documented layout is "one frame per persisted append batch".
So the number of frames in a file equals the number of persisted batches. A file with 3 frames is therefore a file that was written in 3 batches — which matches what we observe: header frame, one frame holding ~100% of the plaintext, plus a small tail. 2. The batching window is a per-handle scheduling policy, not a configuration option. The same README states that write batching for live events is not configurable: the batching window is a scheduling policy inside each write handle. 3. Conclusion: this looks like an interaction, not a deliberate design. A migration converts the entire history through a single write handle in one burst. Because the batching window is time-based, everything produced during that burst is very likely to be buffered into one batch — and that single batch becomes a single, enormous frame. Slow/streamed appends in normal operation produce many small frames instead, which is why only migrated files show this shape. Possible mitigations (in addition to the ones in the original post):
|
|
Root cause found in the shipped code (0.2.0-rc.2) — the migration streams its input but never forms a batch boundary on output. The migration loop ( async function consumeMigrationBytes(rows, chunks, signal) {
let yieldDeadline = performance.now() + MIGRATION_DECODE_YIELD_INTERVAL_MS; // 500 ms
for (const bytes of chunks) for (let offset = 0; offset < bytes.length; offset += MIGRATION_WORK_CHUNK_BYTES) { // 1 MB
rows.write(bytes.subarray(offset, offset + MIGRATION_WORK_CHUNK_BYTES));
if (performance.now() < yieldDeadline) continue;
await scheduler.yield();
signal?.throwIfAborted();
yieldDeadline = performance.now() + MIGRATION_DECODE_YIELD_INTERVAL_MS;
}
}Relevant constants (same file): const MIGRATION_DECODE_YIELD_INTERVAL_MS = 500;
const MIGRATION_WORK_CHUNK_BYTES = 1024 * 1024; // 1 MB
const MIGRATION_WRITE_CHUNK_BYTES = 4 * 1024 * 1024; // 4 MBThere is no Why that produces one giant frame
This also explains the observed shape exactly: Why it is invisible in normal operation Live appends arrive slowly, so each batching window flushes a small batch and produces a small frame (a 317 KB non-migrated log has 192 frames). Only migration output — a whole history in one burst — becomes a single frame of unbounded size. Downstream impact (why this matters beyond disk size) Because decode is synchronous ( Suggested fix
|
|
Confirmed this is still present in the newest release, Checked Also for the record, the release notes do describe the intent: And So as of Additional observation that may narrow the fix: the migration does bound its working set on the input side ( |
Uh oh!
There was an error while loading. Please reload this page.
Migrated session logs put the entire history in a single Zstandard frame, so opening one large session allocates ~120 MB at once.
Summary
After a session log is migrated to the current generation (
session.v4.jsonl.zstd), the resulting file typically contains only a handful of Zstandard frames, and one frame holds ~100% of the plaintext. Opening such a session therefore performs one very large single allocation (and one very large JSON parse burst) instead of streaming many small frames.The package README documents the intended layout as a concatenation of independent frames — "one checksummed frame containing only the header line, followed by each persisted batch" — so a single frame covering the whole history looks like a migration-side flush behaviour rather than the documented steady state.
On a low-spec host (4 logical cores, 7.5 GB RAM) opening two or three such sessions is enough to saturate the machine: the process sits at roughly 75% of one core continuously and the whole system becomes unresponsive until the session is closed.
Measured evidence
Frame statistics were obtained by scanning frame magic (
0x28 B5 2F FD) and decompressing each frame independently (Node 24zlib.zstdDecompressSyncdecodes only the first frame, so a per-frame scanner is required).Structural scan over all logs present on the host: 159 v4 files / 152.03 MB, and the sum of each file's largest frame is 108.86 MB — i.e. 72% of all v4 bytes sit inside per-file single giant frames. Every v4 file scanned had 3 frames; 16 session directories contain both a v3 and a v4 log, which is consistent with these v4 files being migration output.
Cost of opening the largest one (measured with
process.memoryUsage()around the decode and parse):arrayBuffers~295 MB)JSON.parseof the 28,728 events in that frame: heap 30.6 MB -> 297.4 MB, RSS peak 563.6 MBSuspected cause
packages/session/session-persistence-jsonl/src/generation.ts(decodeCurrentGeneration) reads the whole file into oneBufferand decodes frames from it;src/zstd-private-decoder.tsaccumulates outputs aboveDECODE_CHUNK_SIZE(1 MB) viafullChunks.push(...)+Buffer.concat(...), so a 118 MB frame necessarily becomes one >=119 MB contiguous allocation before JSON parsing starts.Impact
Possible directions
Buffer.concatof an arbitrarily large frame.Environment
0.1.5-alpha.2(its own logs are the many-small-frames v3 shape and are not affected).v4) logs produced by the desktop application on Windows.Published by @deepsleepAquarium
All reactions