Don't hang (and lose the result) when the output consumer stalls - #122
Open
fcostaoliveira wants to merge 3 commits into
Open
Don't hang (and lose the result) when the output consumer stalls#122fcostaoliveira wants to merge 3 commits into
fcostaoliveira wants to merge 3 commits into
Conversation
…#121) If stdout/stderr is a pipe whose consumer stops draining (a wedged terminal, an SSH / run-remote stream stall, a full CI log buffer), ftsb wedged inside a blocking log.Printf: the unbounded progress reporter, or summary() (which logs before it writes the --json-out-file result), blocked forever -- the process never exited and no result file was written. Operationally worst case in the on-the-fly-EC2 model: a hung run yields no result AND keeps the bench-server billing until manually destroyed. Route all console logging through a non-blocking best-effort writer: log lines are buffered and dropped (whole lines only) rather than blocking the benchmark when the consumer stalls; a detached drain goroutine does the actual (possibly blocking) writes and is reaped at exit. The --log-file, if any, is written directly (a regular file does not stall) so it stays complete. Normal runs are unaffected (the drain keeps up, nothing drops). Validated: with a never-drained os.Pipe consumer, master HANGS with no result; this branch COMPLETES and writes the JSON. Adds a unit test (Write never blocks on a stalled underlying writer; delivers everything when drained) and an integration test (ftsb completes + writes the result under a stalled pipe).
The initial #121 fix routed console logging through a fire-and-forget writer whose drain goroutine wrote asynchronously. On a clean run RunBenchmark returns normally (no os.Exit), so the process could exit before the goroutine flushed the final buffered lines -- dropping the "Issued ..."/Summary output. This broke TestFTSBWithDuration and TestFTSBWithBatchSize, which assert the summary reaches stderr. Add nonBlockingWriter.Close(timeout): it stops accepting lines and waits for the drain goroutine to flush the buffer, bounded by a timeout so a genuinely stalled consumer still can't wedge shutdown. main defers Close(2s) after RunBenchmark, so a healthy consumer gets the complete summary while the stalled-consumer guarantee is preserved. A small mutex makes Write/Close race-free and makes post-Close writes drop instead of panicking on a closed channel. Tests: TestNonBlockingWriterCloseFlushesBufferedLines (healthy -> tail delivered), TestNonBlockingWriterCloseReturnsDespiteStall (stalled -> returns within timeout), TestNonBlockingWriterWriteAfterCloseIsSafe. The two integration tests and TestFTSBCompletesWithStalledOutputConsumer all pass.
…'t lost (#121) Adversarial review found the async fire-and-forget writer dropped log.Fatal diagnostics: on the default (no --log-file) path, log.SetOutput(console) routed fatal messages through the buffered channel, and log.Fatalf enqueues then calls os.Exit(1) -- which bypasses the deferred console.Close AND the detached drain goroutine, so the process exited before the message reached stderr. A missing --input or an unwritable --json-out-file exited 1 with no reason (a regression: pre-#121 log defaulted to synchronous os.Stderr). The same weakness left the Close-flush test racy (it could pass against a Close that never flushed). os.Stderr is in blocking mode, so its write can't be bounded with a deadline. Instead the blocking write stays on the drain goroutine, but Write now WAITS for its line to be written, bounded by writeTimeout. On a healthy consumer delivery is synchronous, so the summary and any pre-os.Exit fatal line reach stderr before exit; on a stalled consumer Write returns after writeTimeout (then drops once the buffer fills), so the run still completes and writes its result. This removes the Close/flush machinery (and its racy test) entirely. Tests: DeliversBeforeReturnOnHealthy (line on the writer by the time Write returns -> fatal-safe), DeliversAllWhenDrained (nothing dropped when keeping up), DoesNotBlockOnStall (bounded under a wedged writer). Verified E2E: `--input missing.csv` now prints "cannot open file for read ..." to stderr and exits 1. The two integration tests that caught the original drop (TestFTSBWithDuration, TestFTSBWithBatchSize) and the stalled-consumer test all pass under -race.
|
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Closes #121.
Problem
If stdout/stderr is a pipe whose consumer stops draining — a wedged terminal, an SSH /
run-remotestream stall, a full CI log buffer —ftsb_redisearchwedges inside a blockinglog.Printf:--reporting-period), andsummary()logs the human-readable summary before it writes the--json-out-fileresult.Either blocks forever on a full pipe → the process never exits and no result file is written. Worst case in the on-the-fly-EC2 model: a hung run yields no result and keeps the bench-server EC2 billing until manually destroyed.
Fix
Route all console logging through a non-blocking best-effort writer (
nonBlockingWriter): each fully-formatted log line is buffered and, if the buffer is full (consumer stalled), dropped whole rather than blocking the benchmark. A detached drain goroutine performs the actual (possibly blocking) writes and is reaped at process exit. The--log-file, if any, is written directly — a regular file doesn't stall, so it stays complete.Normal runs are unaffected: the drain keeps up and nothing is dropped.
Validation
os.Pipe,--duration 3s --reporting-period 1ms): master HANGS with no result; this branch COMPLETES and writes the JSON.TestNonBlockingWriterNeverBlocks—Writereturns promptly even when the underlying writer is permanently blocked;TestNonBlockingWriterDeliversWhenDrained— nothing is dropped when the consumer keeps up.TestFTSBCompletesWithStalledOutputConsumer— integration test: ftsb completes and writes its result under a never-drained pipe consumer (times out pre-fix).cmd/...+benchmark_runnersuites green (-racewhere applicable); timeout/log-file tests unaffected.Composes with #116's bounded reporter-shutdown wait (the reporter's log is now non-blocking, so it always observes
stopReportpromptly).