fix: Log Finalize Awaits Terminal Stream State - #177
Conversation
LogWriteStreamRegistry.finalize decided success/failure by reading entry.error at whatever moment its finally completed, instead of after the stream's terminal close state. That produced two wrong outcomes: a fully-flushed log with a stale non-destroying recorded error rejected (contradicting the file's own contract), and a close-time error arriving after the check silently missed. finalize now awaits the stream's terminal 'close' state before deciding, and the success predicate is state-based: resolve iff writableFinished && stream.errored === null (warn-and-resolve over a stale recorded error), else reject with entry.error ?? stream.errored. Supersedes the PR #173 decision to document rather than fix the unconditional recorded-error rejection, reopened on two independent reviewers converging (operator-side should-fix; CodeRabbit MAJOR / data integrity).
|
Caution Review failedThe pull request is closed. ℹ️ Recent review info⚙️ Run configurationConfiguration used: Path: .coderabbit.yaml Review profile: CHILL Plan: Pro Plus Run ID: 📒 Files selected for processing (4)
📝 WalkthroughWalkthroughLog finalization now waits for terminal stream closure before evaluating success. Cleanly finished streams can ignore stale non-destroying errors, while terminal failures reject with first-error precedence. Tests and documentation cover close-time failures, cleanup, quiet finalization, and provider behavior. ChangesTerminal log stream finalization
Estimated code review effort: 3 (Moderate) | ~25 minutes Sequence Diagram(s)sequenceDiagram
participant CaptureProvider
participant LogWriteStreamRegistry
participant LogWriteStream
participant Logger
CaptureProvider->>LogWriteStreamRegistry: finalize capture
LogWriteStreamRegistry->>LogWriteStream: end and await close
LogWriteStream-->>LogWriteStreamRegistry: report terminal state
LogWriteStreamRegistry->>Logger: warn on stale recorded error
LogWriteStreamRegistry-->>CaptureProvider: resolve or reject
Possibly related PRs
Suggested labels: Suggested reviewers: 🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
✨ Finishing Touches🧪 Generate unit tests (beta)
Comment |
There was a problem hiding this comment.
Actionable comments posted: 2
🧹 Nitpick comments (3)
fab/changes/260731-vojm-log-finalize-terminal-state/plan.md (1)
164-164: 🩺 Stability & Availability | 🔵 Trivial | ⚡ Quick winAdd coverage for a throwing stale-error warning sink.
Line 164 states that no test drives a throwing sink through
Logger.w. Add a test that records a stale non-destroying error, makes the warning sink throw, and asserts thatfinalizestill resolves and cleans up the registry entry.🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@fab/changes/260731-vojm-log-finalize-terminal-state/plan.md` at line 164, Add a test covering the stale non-destroying error path in Logger.w where the warning sink throws, and assert that finalize still resolves while removing the corresponding registry entry. Update the A-011 plan claim to reflect the new test coverage.packages/device-node/src/device/logWriteStream.ts (2)
179-200: 📐 Maintainability & Code Quality | 🔵 Trivial | ⚡ Quick winConsider extracting the repeated guarded-log pattern.
The
try { Logger.X(...) } catch { /* deliberately empty */ }pattern now appears three times in this file: theopen()error listener (Line 112-117), the stale-error warning infinalize(Line 190-197), andfinalizeQuietly's catch block (Line 250-259). Each copy repeats the same rationale in its comment. Extract a small helper, for example_safeLog(fn: () => void): void, to remove the duplication and keep the guard's contract in one place.♻️ Proposed refactor
+ private _safeLog(fn: () => void): void { + try { + fn(); + } catch { + // Deliberately empty: a logger that just failed is not where a failing + // logger gets reported. + } + } + open(outputFilePath: string): fs.WriteStream { ... stream.on('error', (error) => { entry.error ??= error; - try { - Logger.e(`LogWriteStreamRegistry: log write stream failed: ${outputFilePath}`, error); - } catch { - // Deliberately empty: ... - } + this._safeLog(() => + Logger.e(`LogWriteStreamRegistry: log write stream failed: ${outputFilePath}`, error), + ); }); ... }Also applies to: 250-259, 112-117
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@packages/device-node/src/device/logWriteStream.ts` around lines 179 - 200, Extract the repeated guarded Logger.X invocation into a private helper such as _safeLog(fn: () => void): void, preserving the existing try/catch behavior and intentionally swallowing logger errors. Replace the duplicated guarded logging blocks in the open() error listener, finalize’s stale-error warning, and finalizeQuietly’s catch block with this helper without changing their messages or outcome handling.
289-320: 🩺 Stability & Availability | 🔵 Trivial | 💤 Low valueConsider bounding the wait for
'close'.
_endAndFlushwaits for'close'with no timeout, unlike_drain, which bounds its wait withLOG_DRAIN_TIMEOUT_MS. This relies entirely onfs.WriteStreamalways emitting'close'(the documentedemitClose: truedefault). The comment at Line 297-303 explains this reasoning well, so the design is deliberate. As a defensive measure against an unexpected Node or filesystem edge case, consider adding a bounded fallback similar to_drain's, so a stuckclosecannot hangfinalize(and thusstopLogCapture) indefinitely.🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@packages/device-node/src/device/logWriteStream.ts` around lines 289 - 320, Bound the close wait in _endAndFlush so finalize cannot hang indefinitely if the stream never emits 'close'. Reuse the existing LOG_DRAIN_TIMEOUT_MS timeout pattern from _drain, while preserving the current end/destroy behavior and resolving normally when 'close' arrives first.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@docs/memory/device-node/log-capture.md`:
- Around line 77-80: Correct the malformed sentence in the finalize
documentation by replacing “stream something already ended or destroyed” with “a
stream that has already ended or been destroyed,” leaving the surrounding
content unchanged.
In `@fab/changes/260731-vojm-log-finalize-terminal-state/intake.md`:
- Around line 8-10: Correct the provenance statement in intake.md to accurately
describe the contents of .history.jsonl: either ensure the complete raw request
is persisted there, or state that the file records only condensed/operative
command arguments. Keep the quoted request and its surrounding context unchanged
unless required to make the provenance claim accurate.
---
Nitpick comments:
In `@fab/changes/260731-vojm-log-finalize-terminal-state/plan.md`:
- Line 164: Add a test covering the stale non-destroying error path in Logger.w
where the warning sink throws, and assert that finalize still resolves while
removing the corresponding registry entry. Update the A-011 plan claim to
reflect the new test coverage.
In `@packages/device-node/src/device/logWriteStream.ts`:
- Around line 179-200: Extract the repeated guarded Logger.X invocation into a
private helper such as _safeLog(fn: () => void): void, preserving the existing
try/catch behavior and intentionally swallowing logger errors. Replace the
duplicated guarded logging blocks in the open() error listener, finalize’s
stale-error warning, and finalizeQuietly’s catch block with this helper without
changing their messages or outcome handling.
- Around line 289-320: Bound the close wait in _endAndFlush so finalize cannot
hang indefinitely if the stream never emits 'close'. Reuse the existing
LOG_DRAIN_TIMEOUT_MS timeout pattern from _drain, while preserving the current
end/destroy behavior and resolving normally when 'close' arrives first.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Path: .coderabbit.yaml
Review profile: CHILL
Plan: Pro Plus
Run ID: bc27f1c1-c166-4798-a177-8341b95034eb
📒 Files selected for processing (8)
docs/memory/device-node/index.mddocs/memory/device-node/log-capture.mdfab/changes/260731-vojm-log-finalize-terminal-state/.history.jsonlfab/changes/260731-vojm-log-finalize-terminal-state/.status.yamlfab/changes/260731-vojm-log-finalize-terminal-state/intake.mdfab/changes/260731-vojm-log-finalize-terminal-state/plan.mdpackages/device-node/src/device/logWriteStream.tspackages/device-node/src/device/test/logCaptureProviders.test.ts
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Meta
vojmgenerated by fab-kit v2.16.8
Pipeline: intake ✓ → apply ✓ → review ✓ → hydrate ✓ → ship → review-pr
Summary
LogWriteStreamRegistry.finalizedecided success/failure fromentry.errorat whatever moment itsfinallycompleted, instead of after the stream's terminal close state — rejecting a fully-flushed log over a stale non-destroying error, and silently missing a close-time error that landed after the check.finalizenow awaits the stream's terminal'close'state before deciding, with a state-based success predicate: resolve iffwritableFinished && stream.errored === null(warn-and-resolve over a stale recorded error), else reject deterministically withentry.error ?? stream.errored.This change supersedes the decision CodeRabbit recorded as a learning on PR #173 — that "finalize deliberately re-throws any recorded
entry.errorwithout awritableFinishedguard" is intentional. PR #173 chose to document that behavior rather than change it. This is reopened on two-reviewer convergence: an operator-side adversarial review independently rated the same issue should-fix, and CodeRabbit independently rated it MAJOR (data integrity) on PR #173. Future bot reviews should treat this PR as the superseding decision, not as a contradiction of the stored learning.Test Integrity position: the rework of
'LogWriteStreamRegistry records only the first error a stream emits'is spec-conformance test updating, not test-weakening. Coverage is moved, not dropped — first-error-wins is re-pinned on a genuinely failing stream (two emits followed bystream.destroy), and the assertion it displaced (rejection despite a clean flush) is re-pinned deterministically as the new close-time-error regression test, the only production-reachable flushed-then-errored shape.Changes
finalizeawaits the terminal stream state before deciding (packages/device-node/src/device/logWriteStream.ts)finalizeQuietly-before-finalizeconsumption — decided: keep once-consumed semantics, pin the safety invariant with testsSummary by CodeRabbit
Bug Fixes
Documentation