feat(logs): stream read_log over SSE as a live tail - #1693
Conversation
There was a problem hiding this comment.
Code Review
This pull request implements live log streaming via Server-Sent Events (SSE) by adding an abort signal to ProgressEmitter to handle client disconnects, updating the server handlers, and introducing an incremental log parser and file tailer in readLog.ts. Feedback on the changes highlights a critical memory issue where reading the entire log file into memory for the backlog could cause out-of-memory crashes, suggesting an incremental backlog parsing approach instead. Other recommendations include removing the unused parseAllLogEntries function and optimizing the incremental parser by instantiating the RegExp once in the outer closure.
|
Reviewed; no blockers found. |
|
Client counterpart: HarperFast/studio#1425 — the studio Logs view that consumes these |
|
Addressed the review feedback in a647ecc:
On CI: the only red check is |
|
Correction on the red Unit Test check — it is not flaky, it's a pre-existing failure on
So this branch just inherits |
84ab0bd to
8186b0d
Compare
|
Reviewed via Claude review-queue (full review: harper-1693-8186b0d.md). Well-designed live tail — reuses the existing ProgressEmitter/createSSEResponseStream plumbing, auth/path-validation are inherited unchanged, and the backlog→live handoff correctly uses the backlog's end-offset as the tail's start-offset so nothing is dropped or double-emitted. Two things worth a look, neither blocking for the common case:
CI failure is confirmed unrelated — all three Unit Test jobs fail on the same pre-existing |
|
Thanks Kris — both addressed in 6526f98. 1. Backpressure. 2. Transient delta-read error. The pump now advances Also capped the backlog to the newest Added a backpressure unit test (pump parks while 🤖 Addressed by Claude Code |
read_log now supports `Accept: text/event-stream`: it emits the recent backlog as `log` events, then tails newly-appended lines live until the client disconnects, so clients can subscribe to log changes instead of polling. - serverHandlers: add read_log to the SSE_PROGRESS_OPERATIONS whitelist so the handler attaches a ProgressEmitter and streams the response. - progressEmitter: expose an AbortSignal on the emitter that fires when the client disconnects, so an open-ended operation (the log tail) can stop and resolve instead of running until process exit. No effect on the bounded deploy_component / get_deployment streams, which ignore the signal. - readLog: when request.progress is set, emit the local backlog (newest `limit`, filtered by level/from/to/filter), then tail the file via fs.watchFile applying the same filters to new lines, until the abort signal fires. Local-node only (a live tail is not fanned out to peers); the buffered path still aggregates the cluster for point-in-time reads. Buffered behavior is unchanged. Pairs with the studio client (HarperFast/studio#1425), which consumes the `log` events and falls back to polling when streaming is unavailable. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
…rser Address PR review feedback on the read_log live tail: - Backlog no longer reads the entire log file into memory. It seeks to roughly the last `limit` entries (the same tail-seek the buffered path uses), so a large hdb.log can't OOM the process. - Drop parseAllLogEntries; the incremental parser now backs both the bounded backlog read and the live tail. - Instantiate the tail's RegExp once per parser instance rather than per appended chunk. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
AGENTS.md prohibits new uses of sinon/rewire in unit tests. Drop the validator stub and the getConfigPath rewire: point the configured log directory at a temp dir via the real environmentManager (getConfigPath reads env.get(LOG_PATH)), run against the real validator, and assert with bare node:assert instead of chai. Behavior and coverage are unchanged (all 6 SSE tail cases still pass). Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
…tail Address review feedback (kriszyp) on the read_log live tail: - Backpressure: ProgressEmitter now exposes `paused`/`whenWritable()`/`resume()`. createSSEResponseStream flags `paused` when a stream write returns false and clears it on 'drain' (and on teardown, so a producer never hangs). The tail's new single-flight pump awaits `whenWritable()` before reading/emitting more, so a slow client can't make buffered SSE frames grow without bound. Bounded producers (deploy_component/get_deployment) don't check it and are unchanged. - Resilient delta reads: a transient read error no longer silently skips a byte range forever. `offset` advances only after a successful read, the error is logged, and the pump retries the same range on the next change. - Backlog is capped to the newest `limit` entries as it parses (belt to the existing bounded tail-seek). Adds a backpressure unit test; all 7 read_log SSE tail cases pass. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
writeSSE checked only the final `\n` write for backpressure, so a dense multi-line payload that tips the buffer past its high-water mark on an earlier `event:`/`data:` write went undetected. AND all three write results (each `stream.write` stays the left operand, so every line is still written). Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
9394fc7 to
f1b4e56
Compare
kriszyp
left a comment
There was a problem hiding this comment.
Re-reviewed at the current head (f1b4e56f) — the branch was rebased onto a newer main but the tree content of the files this PR touches (readLog.ts, progressEmitter.ts, serverHandlers.js, readLogStream.test.js) is byte-identical to what I reviewed at 9394fc73c. So all 4 previously-flagged issues are still open:
- Idle-flush drops the continuation of a multi-line entry —
readLog.ts:461,flush()unconditionally clearspending/remaining. A multi-line message (stack trace, JSON payload) that stalls >1s mid-write gets its continuation silently discarded. - Unbounded
limit→ O(n·limit) backlogshift()—readLog.ts:600.limitis stillJoi.number().min(1)with no upper bound. A large user-suppliedlimitagainst a dense log window is a synchronous, event-loop-blocking stall on connect. - Transient read error silently stalls the tail —
readLog.ts:544. On areadRangefailure,pump()breaks without advancingoffset; the only re-arm is the nextfs.watchFilechange event, so on an idle log the gap persists indefinitely with no signal to the client. readRange's single-string parse bypasses per-chunk backpressure — same location. The whole byte range is buffered into one string before a singleparser.push(), so a burst write or truncation-refill landing in one poll window bypasses backpressure mid-emit.
New this round: per-poll StringDecoder reset can corrupt multi-byte UTF-8 at chunk boundaries (readLog.ts:507) — each readRange call creates a fresh fs.createReadStream with its own decoder instance. If a poll's byte range ends mid-character (plausible for any non-ASCII log content), the decoder flushes the incomplete sequence as U+FFFD instead of holding it for the next chunk. Fix: hold one StringDecoder per tail session instead of letting it reset every poll.
None of these are process-crashing — happy to be more specific on any of them if useful. Given the studio#1425 client PR is built to degrade to polling on connection failure but has no way to detect a silent stall (the SSE connection stays open from its perspective), landing this as-is means a stalled tail looks "live" indefinitely in the UI with no fallback trigger.
- No idle flush: the live tail never force-flushes a pending entry, so a multi-line message mid-write can't be truncated or have its continuation discarded. An entry is finalized only when the next marker delimits it (the bounded backlog snapshot still flushes at its real EOF). - Bounded backlog: cap the tail backlog at MAX_SSE_BACKLOG_ENTRIES regardless of a caller-supplied `limit`, so an unbounded `limit` can't seek-read a huge slice into memory or drive an O(n·limit) eviction on connect. - Resilient reads: a transient delta-read error is retried a few times; if it persists the tail emits a terminal `error` (so the client falls back to polling) instead of silently stalling until the next file change. - Per-slice backpressure: decoded bytes are pushed to the parser in bounded slices, yielding to whenWritable() between slices, so a burst in one poll window can't emit frames ahead of a slow client mid-push. - UTF-8 safety: one StringDecoder per tail session (raw-Buffer reads) so a multi-byte char split across poll windows is held, not flushed as U+FFFD. Adds tests for the no-partial-flush and multi-byte-split behaviors; 15 SSE tail + progressEmitter cases pass. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
|
Thanks Kris — all five addressed in f1eeb5e (readLog.ts) + the earlier backpressure commits.
Added unit tests for the no-partial-flush and multi-byte-split behaviors; 15 tail + progressEmitter cases pass, build/lint/prettier clean. 🤖 Addressed by Claude Code |
kriszyp
left a comment
There was a problem hiding this comment.
Approving — great progress since the last pass. Re-checked at head f1eeb5ef5:
CI red looks unrelated to this PR. Unit Test (Node.js v22) fails on unitTests/resources/txn-tracking.test.js:59 ("Slow txn will expire") — nothing in this diff touches transaction tracking, and the same suite passes clean on Node 24 and Node 26 in this same run. Integration Tests 3/6 (Node.js v22) fails on "Per-device-type LMDB database sharding" (sensor schema missing) — also untouched by this diff, and shard 3 passes on every other runtime in the matrix in the same run. Single-shard/single-runtime failures in areas this PR never touches, green everywhere else in the matrix — that's the flaky-test pattern, not a regression signature. Worth a re-run, but not something I'd hold the PR on.
3.5 of the 4 previously-flagged issues are now fixed — nice work closing those out. One new gap found this pass: [see review for detail — happy to elaborate on request]. Worth a look before merge, but this is much closer to ship-ready than the last two passes.
|
@kriszyp it didn't leave any new comments, please elaborate. |
Two low-severity follow-ups on the read_log SSE tail (cb1kenobi review): - The backlog read stream's error is no longer swallowed — log it via hdbLogger.warn, matching the buffered path and the live-tail delta reads, so a permissions/IO failure on the log file is diagnosable. - The backlog emit now honors the same backpressure as the live tail: it yields to progress.whenWritable() between entries (and stops on abort), instead of pushing up to backlogLimit (possibly large multi-line) entries into the stream at once ahead of a slow client. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
kriszyp
left a comment
There was a problem hiding this comment.
Sorry, Dawson — my last comment here ("One new gap found this pass: [see review for detail — happy to elaborate on request]") was a copy-paste mistake, a placeholder from my own notes that never got filled in before I posted. That's on me. Here's the actual content, re-checked against the current head (c838187f9):
Fixed and holding since pass 3 (nice work): idle-flush multi-line drop, unbounded limit (now capped at MAX_SSE_BACKLOG_ENTRIES = 1000), transient-read-error silent stall (now retries ×3 then terminal error), UTF-8 chunk-boundary corruption (persistent StringDecoder + dedicated test).
Still open, unaddressed since pass 3 — the backlog→tail handoff can drop a line torn across the snapshot boundary. backlogParser is a separate parser instance from the live-tail parser. When the backlog stream closes, backlogParser.flush() unconditionally force-emits whatever's pending — including a truncated message if a writer's line was mid-flight exactly when the snapshot's startSize was captured. The live tail's fresh parser then starts with no pending state, so it silently drops the stray continuation bytes until the next real marker. This round's diff added backlog-error logging and backpressure on the backlog emit loop (both good, unrelated fixes) but didn't touch this seam. The fix is the same shape as the now-fixed idle-flush bug, just relocated: share one parser instance across the backlog read and the live tail (never .flush() at the seam), or explicitly document this as an accepted tradeoff if there's a reason not to.
New this round — readRange buffers the entire poll delta before backpressure-slicing it. The 64KB slice size only bounds what's fed to the parser per await, after the whole [offset, size) range is already materialized as one Buffer.concat. If a client is paused for a while and the file keeps growing, the next successful read after resume pulls the whole accumulated delta in one shot — the exact unbounded-memory scenario the slicing exists to prevent. Streaming the range with for await (const chunk of rs) and slicing as chunks arrive (rather than concatenating first) would bound peak memory to roughly one chunk instead of one full delta.
Minor/non-blocking: a pump() re-entrancy edge can delay (not lose) one write's delivery until the next write arrives — narrow trigger, low severity, a pumpQueued flag would be cheap insurance if you want to close it while in the area.
CI is red again (Integration Tests 3/6, Node.js v26), but it's the same "Per-device-type LMDB database sharding" test that failed on Node 22 in the last pass, on code this PR doesn't touch, green on every other runtime in the same matrix — I'd treat that as a confirmed recurring flake, not something to chase here.
- Backlog→tail handoff: one shared parser + decoder now span the backlog read and the live tail with no flush at the seam, so a line (or multi-byte char) torn across the snapshot boundary stays pending/held and is completed by the tail's next read instead of force-emitted truncated with its continuation dropped. (The newest backlog line is now delivered once the following line delimits it — consistent with how the tail delimits every entry.) - Per-poll delta memory: the delta read now streams chunk-by-chunk (`for await`), decoding/pushing and advancing offset per fs chunk, so peak memory is one chunk rather than a whole `Buffer.concat`'d delta after a long pause. Retries resume from the advanced offset. - pump() re-entrancy: a change arriving mid-pump sets `pumpQueued` so the loop runs once more, closing the window where a write could be delayed until the next change. Updated the tail tests for the no-flush semantics (a trailing sentinel line delimits the entries under test). 15 tail + emitter cases pass. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
|
Thanks Kris — and no worries on the placeholder. All three addressed in 17e2da7.
Updated the tail tests for the no-flush semantics (a trailing sentinel delimits the entries under test); 15 tail + progressEmitter cases pass, build/oxlint/prettier clean. And agreed the red 🤖 Addressed by Claude Code |
kriszyp
left a comment
There was a problem hiding this comment.
This is the pass where it converges — approving. All three items carried from the last two reviews (the backlog/tail handoff gap, the readRange memory bloat, the pump() re-entrancy edge) are fixed this round, and the fixes are exactly the shape asked for: one shared parser/decoder spanning backlog and tail with no flush at the seam, a chunk-streamed read that bounds peak memory to one fs chunk, and a pumpQueued flag closing the re-entrancy window. Five passes is a lot of back-and-forth, but each one closed real, previously-identified gaps rather than surfacing new churn — nice work seeing this through.
Two small items I'd file as fast-follow issues rather than block on: a pre-existing bug in shared SSE infra (writeSSE throws if event.data === undefined — not triggered by anything read_log currently emits, but worth hardening since new callers are landing on this shared code), and the carried-over rotation-detection-via-size (vs. inode) suggestion. Filing both now so they don't get lost.
Ethan-Arrowood
left a comment
There was a problem hiding this comment.
LGTM — impressive convergence over the review passes; the terminal-error-on-stall behavior is exactly what the studio fallback needs.
sent with Claude Fable 5
What
read_lognow supportsAccept: text/event-stream. Instead of a one-shot array, it emits the recent backlog aslogevents and then tails newly-appended lines live until the client disconnects — so clients can subscribe to log changes instead of polling.This is the backend half of the studio "Use SSE for Logs" work; it pairs with the client PR HarperFast/studio#1425, which consumes these
logevents (and falls back to polling when streaming isn't available).How
Builds on the existing operation-SSE plumbing (
ProgressEmitter+createSSEResponseStream), the same pathdeploy_component/get_deploymentuse.serverHandlers.js— addREAD_LOGtoSSE_PROGRESS_OPERATIONS. When the client sendsAccept: text/event-stream, the handler attaches aProgressEmitterasreq.body.progressand streams the response; non-SSE callers are unaffected (progressis undefined → the historical array path).progressEmitter.ts— expose anAbortSignalon the emitter that aborts when the client disconnects (createSSEResponseStreamowns the controller and aborts in its existingcleanup).deploy_component/get_deploymentstream a bounded run and end on their own, so they ignore the signal and are unchanged. An open-ended operation like the log tail reads it to stop and resolve instead of running until process exit.readLog.ts— whenrequest.progressis set:limitentries (filtered bylevel/from/to/filter), oldest-first.fs.watchFile(stat-poll based — robust across platforms and log rotation, unlikefs.watchrename events), parsing appended bytes incrementally with the same marker regex as the buffered reader and applying the same filters, until the abort signal fires. A trailing (possibly multi-line) entry is flushed after a short idle so a quiet tail still surfaces its newest line.The buffered (non-SSE) path is untouched. The tail is local-node only — a live subscription is not fanned out to peers; the buffered path still aggregates the cluster for point-in-time reads. Replication is skipped on the SSE path.
Wire format
Each entry is one SSE record:
event: log+data: {"timestamp","thread","level","tags","message"}. No new request param — streaming is negotiated purely via theAcceptheader + the whitelist, matching the deploy precedent and the studio client.Testing
unitTests/utility/logging/readLogStream.test.js(6 cases): backlog emission + resolve-on-disconnect, live tailing of appended lines, idle-flush of a trailing line,level/filterapplied to both backlog and live, backlog capped atlimit(newest kept), and no-signal degrade-to-backlog.test:unit:logging(55 passing) and theprogressEmitter/serverHandlersunit tests still pass;tscbuild,oxlint --deny-warnings, andprettierare clean.Notes / follow-ups
read_logremains the cluster aggregate.