skip to content

A Go migration tool writes its report through a bufio.Writer, and on failed CI runs the report is truncated — how do you find the cause?

level: seniorimportance: should knowfreq 42%

answer

  1. Complete on success, cut off on failure
  2. Look at how the failure path leaves
  3. Something ended the process, not the function
  4. Check the file size against the buffer size
  5. Grep for exits outside main

basics

~20 s

Suspect an error path that calls os.Exit or log.Fatal, so the deferred Flush never runs and buffered bytes are dropped. The tell is that successful runs produce a complete report while failing runs stop mid-buffer.

solid answer

~40 s

The pattern — complete on success, truncated on failure — points straight at the failure path ending the process rather than returning. Somewhere a helper calls `log.Fatalf` or `os.Exit(1)`, which runs no deferred call, so the caller's `defer w.Flush()` never fires and everything still in the `bufio.Writer` is discarded. Two cheap confirmations: correlate the truncation with a non-zero exit status, and check the truncated file's size — with small line writes a `bufio.Writer` only hands over full 4096-byte buffers, so a length that is an exact multiple of the buffer size means the tail was never flushed rather than the write failing. Then grep for `os.Exit` and `log.Fatal` outside `main`. The fix is that helpers return errors, and `main` flushes — checking the error `Flush` returns — before it exits with a status.

code

go · 6 lines
go
func writeRow(w *bufio.Writer, row string) {
	if _, err := fmt.Fprintln(w, row); err != nil {
		// log.Fatalf calls os.Exit(1): the caller's defer w.Flush() never runs
		log.Fatalf("write failed: %v", err)
	}
}

go deeper

for a junior

Know the basic cause: os.Exit and log.Fatal stop the process without running deferred calls, so buffered output is lost. Being able to name that as the suspect is what is expected here.

for a middle

Explain the buffering layer precisely: bytes handed to the file survive, bytes still in the bufio.Writer do not, and a size that is a multiple of the 4096-byte buffer says which happened.

for a senior

Demonstrate a method, not a guess: correlate truncation with exit status, inspect where the file stops, then audit exit calls outside main. Then propose the structural fix rather than a bigger buffer.

for a principal

Frame it as a design rule the team can hold to: exits belong in one place, after the output is safe. Say how you would find the existing violations and how you would stop new ones arriving.

## Reading the symptom "Truncated only when the run fails" is a very specific shape, and it rules out most of the boring explanations before you touch the code. A full disk, a broken artifact upload or a killed container would not correlate so neatly with the tool's own failure path. What does correlate is: the failure path exits the process differently from the success path. Start by pinning down two facts from the CI job: 1. **The process exit status.** If truncated runs are the non-zero ones and clean runs are zero, the failure path is doing something the success path does not. 2. **The last line that reached the file.** Does the report stop at a logical boundary — the end of a migration step — or mid-record, mid-line? Mid-line is a strong hint that a fixed-size buffer was handed over and the remainder was lost, rather than the program deciding to stop writing. A third, surprisingly decisive check: the byte length of the truncated file. `bufio.NewWriter` gives you a 4096-byte buffer, and for a stream of short lines it only writes through when that buffer is full — in whole buffers. A truncated file whose size is an exact multiple of 4096 is close to a confession: every complete buffer made it, and whatever was accumulating in the last one never did. ## The mechanism `os.Exit` terminates the process immediately: no stack unwinding, and therefore no deferred calls. `log.Fatal`, `log.Fatalf` and `log.Fatalln` print a line and then call `os.Exit(1)`, so they behave identically. Neither gives a `bufio.Writer` any chance to flush, and the runtime does not flush anything on your behalf. So this shape is broken: ```go func writeRow(w *bufio.Writer, row string) { if _, err := fmt.Fprintln(w, row); err != nil { log.Fatalf("write failed: %v", err) } } ``` The caller may have written `defer w.Flush()` immediately after creating the writer and believe the report is safe. It is safe against a `return`. It is not safe against a helper that ends the process. Worth noting explicitly, because it catches people who have already found the helper: putting the exit in `main` does not fix it either. `defer w.Flush()` at the top of `main` still does not run if `main` itself finishes with `os.Exit(1)`. Deferred calls run on a return, and `os.Exit` is not one. ## Confirming it rather than guessing - Search the repository for `os.Exit` and `log.Fatal` in any package other than `main`. In a tool of any size there are usually several, added one at a time by people handling an error at the point they noticed it. - Reproduce locally by forcing the failure and diffing the report against a successful run. The successful run's report ending where you expect, and the failed one ending mid-buffer, is the confirmation. - If you want certainty about *which* exit fires, run the failing case and look at what the tool printed last on standard error — the `log.Fatalf` message identifies the call site. Note what will not find it: `go vet` has no check for this, and the race detector is irrelevant — nothing here is concurrent. This is a control-flow defect, found by reading exit paths. ## The fix Make the process end in exactly one place, and make that place the last thing that happens after the report is safely out: ```go func main() { w := bufio.NewWriter(f) // f is the open report file if err := migrate(w); err != nil { w.Flush() // salvage what we have before leaving fmt.Fprintln(os.Stderr, "migrate:", err) os.Exit(1) } if err := w.Flush(); err != nil { fmt.Fprintln(os.Stderr, "flush:", err) os.Exit(1) } } ``` Helpers return errors; `main` decides what the process does. Two details are easy to skip and both cost you the tail of the report: - **Check the error from `Flush`.** A flush that fails on a full disk loses exactly the bytes you were trying to save, and ignoring the return value turns that into silence. - **Closing the file does not flush the writer.** `os.File.Close` knows nothing about the `bufio.Writer` wrapping it. Flush first, then close. ## Why this shows up in CI more than locally Locally the run usually succeeds, and the success path flushes. CI is where the failure path actually executes, and the failure path is the one nobody exercised. That is the general lesson worth stating in the interview: the exit paths of a program deserve the same attention as its happy path, because they are the ones that run when you most need the output.

  • Why is defer w.Flush() at the top of main not enough here?
    Because deferred calls run when a function returns, and `main` ending with `os.Exit(1)` is not a return. The defer sits there looking like a guarantee and never fires. Either flush explicitly on every path that exits, or do the work in a function whose return triggers the defer and call `os.Exit` after it has come back.
  • The report is complete but the final record is missing even on a successful run. What else would you check?
    The error returned by `Flush` — if it is ignored, a failed final write is invisible. Also check the ordering of close and flush: `os.File.Close` does not flush a `bufio.Writer` wrapping it, so a deferred `f.Close()` that runs before the flush loses the tail just as effectively.
  • Would runtime.Goexit in that helper have caused the same loss?
    No, and the contrast is instructive. `Goexit` unwinds the goroutine running every pending deferred call, so `defer w.Flush()` would have fired and the report would be intact. What it would do instead is end that goroutine silently while the process keeps going — a different failure, but not a lost buffer.

saying these in an interview costs you the question

  • Blames the filesystem or the CI artifact upload first
  • Says a deferred Close flushes the bufio.Writer
  • Adds a sleep or an os.File.Sync instead of flushing
  • Leaves log.Fatal in helpers and only enlarges the buffer
  • Ignores the error returned by Flush
  • Reaches for the race detector for a single-goroutine tool