fix(logs): close race that dropped appends in -f follow mode#79
Conversation
Root cause (proven by the test diagnostics + local reproduction under CPU
saturation): follow mode set its starting byte offset from a SEPARATE
fsPromise.stat() taken AFTER the initial readFile + parse + stdout write:
const existingContent = await readFile(file) // reads N bytes, prints them
...parse/filter/write to stdout... // append can land here
const stat = await stat(file) // size now N+M
let position = stat.size // = N+M, skips the M new bytes
Any append landing between the readFile and the stat is silently dropped: the
new bytes were not in the dumped content, and position jumps past them so the
poll loop (which reads from position) never re-reads them. Under load the window
between the two awaits widens, which is why CI failed intermittently on all
three platforms with the appended line never appearing in stdout.
The follow-trace diagnostics showed position==observedSize==81 (full file
including the append) from the very first poll, with bytesThisCycle=0 forever —
position had already been advanced past the unread append.
Fix: anchor position to Buffer.byteLength of the exact content we just read,
before any further awaits. Anything appended afterwards is at offset >= position
and is picked up by the poll. Verified 20/20 green under 48-process CPU
saturation that previously reproduced the drop within ~2 runs.
Refs #77
📝 WalkthroughWalkthroughThe follow-mode initialization in the logs command now anchors its byte position directly to the already-read content's length instead of issuing a separate stat call, eliminating a race where file appends occurring between the read and stat would be silently skipped. ChangesFollow-mode byte offset race condition fix
Estimated code review effort🎯 2 (Simple) | ⏱️ ~10 minutes Possibly related PRs
Poem
🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
✏️ Tip: You can configure your own custom pre-merge checks in the settings. ✨ Finishing Touches📝 Generate docstrings
🧪 Generate unit tests (beta)
Warning There were issues while running some tools. Please review the errors and either fix the tool's configuration or disable the tool if it's a critical failure. 🔧 ESLint
src/cli/commands/logs.tsOops! Something went wrong! :( ESLint: 8.27.0 Error: ESLint configuration in --config » eslint-config-oclif is invalid:
Referenced from: /.eslintrc Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Caution
Some comments are outside the diff and can’t be posted inline due to platform limitations.
⚠️ Outside diff range comments (1)
src/cli/commands/logs.ts (1)
292-293:⚠️ Potential issue | 🟠 Major | ⚡ Quick winRotation path still has the same read→stat skip race.
After reading and printing
newContent, settingpositionfrom a laterstat.sizecan skip bytes appended between those two awaits. Anchorpositionto bytes actually read (Buffer.byteLength(newContent, "utf-8")) to keep behavior consistent with the fix above.Suggested patch
- const newStat = await fsPromise.stat(currentLogFile); - position = newStat.size; + // Avoid read->stat race on rotated file initialization, same as initial follow setup + position = Buffer.byteLength(newContent, "utf-8");🤖 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 `@src/cli/commands/logs.ts` around lines 292 - 293, After reading and printing newContent, don't reset position using a later fsPromise.stat(currentLogFile).size (which can skip bytes added between the read and stat); instead compute and assign position using the actual number of bytes consumed from the file by setting position += Buffer.byteLength(newContent, "utf-8") (use the same newContent variable and encoding), replacing the current stat-based assignment that references fsPromise.stat and currentLogFile so position reflects bytes read, not file size at a later async point.
🤖 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.
Outside diff comments:
In `@src/cli/commands/logs.ts`:
- Around line 292-293: After reading and printing newContent, don't reset
position using a later fsPromise.stat(currentLogFile).size (which can skip bytes
added between the read and stat); instead compute and assign position using the
actual number of bytes consumed from the file by setting position +=
Buffer.byteLength(newContent, "utf-8") (use the same newContent variable and
encoding), replacing the current stat-based assignment that references
fsPromise.stat and currentLogFile so position reflects bytes read, not file size
at a later async point.
1 participant
Context
Follow-up to #78. That PR merged the test hardening + diagnostics, but the actual root-cause fix was pushed to the branch after #78 had already merged, so it never reached master. This PR carries just that fix.
Root cause (proven, not guessed)
The diagnostics added in #78 fired on the windows CI job and I then reproduced the failure locally under CPU saturation.
bitsocial logs -fset its starting byte offset from a separatefsPromise.stat()taken after the initialreadFile+ parse + stdout write:Any append landing between the
readFileand thestatis silently dropped: those bytes were never in the printed dump, andpositionjumps past them, so the 300ms poll loop never re-reads them. Under load the window between the twoawaits widens — which is why thelogs -ftest failed intermittently on all three platforms. The follow-trace showedposition==observedSize(whole file incl. the append) from the first poll withbytesThisCycle=0forever.This also affected real users: a log line appended during
logs -fstartup could be intermittently missed.Fix
Anchor
positiontoBuffer.byteLength(existingContent)— the exact bytes just read — before any further awaits. Anything appended afterward is at offset >= position and is picked up by the poll. No separatestat, no race window.Verification
logs.test.ts(29 tests) passes.Refs #77
Summary by CodeRabbit