What does wrapping an slog handler's writer in a bufio.Writer buy, and what does it cost?
answer
- os.Stdout is a file, not a buffer
- one syscall per record, by default
- what you batch, you can lose
- who drains the buffer on the bad path?
basics
~20 sIt buys fewer write system calls, because records are batched instead of written one at a time. It costs you every record still sitting in the buffer when the process ends without a flush, plus delayed visibility while you wait.
solid answer
~40 sA handler constructed over `os.Stdout` writes straight through: `os.Stdout` is an `*os.File` with no user-space buffer, so each record leaves the process in one `write` call the moment `Handle` returns. Putting a `bufio.Writer` in front batches records into a 4096-byte buffer by default and cuts the syscall count, which is measurable on a very chatty hot path. What you give up is that buffered records exist only inside your process: any ending that does not run the flush — `os.Exit`, `log.Fatal`, an uncaught SIGTERM, SIGKILL, a fatal runtime error — discards them, and those are the last records before the failure. You also delay visibility, so tailing a stuck service shows nothing until the buffer fills. For a service the usual answer is not to buffer the log sink at all.
code
go · 7 lines// Unbuffered: one write syscall per record, nothing left inside the process.
logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
// Buffered: fewer syscalls, but records live in memory until Flush.
w := bufio.NewWriter(os.Stdout) // 4096 bytes by default
buffered := slog.New(slog.NewJSONHandler(w, nil))
defer w.Flush() // does not run on os.Exit, log.Fatal or an uncaught signalgo deeper
Know that a handler writing to os.Stdout sends each record out immediately, and that adding a buffer means some records are still inside your program when it stops.
Explain the mechanics: os.Stdout is an *os.File with one write call per record, bufio.Writer batches into 4096 bytes by default, and buffered records are lost on any exit that skips the flush.
Show the operational judgment — name the exit paths that skip a deferred flush, and say why the newest records are the ones you cannot afford to trade for syscalls.
Frame it as a fleet policy question: an unbuffered sink is the default you make easy, and buffering is an exemption granted against a measurement with flushing requirements attached.
## What happens with no buffer at all `os.Stdout` is an `*os.File`. Its `Write` method makes a `write` system call with the bytes you hand it and returns; there is no user-space buffering in between, and no line buffering of the kind C's stdio does. So with ```go logger := slog.New(slog.NewJSONHandler(os.Stdout, nil)) ``` every record is one formatted byte slice and one system call. By the time `logger.Info(...)` returns, those bytes are in the pipe the container runtime is reading. Nothing your process can do afterwards — crashing, exiting, being killed — can take them back. That property is the reason the standard library's default is unbuffered, and it is worth stating explicitly in an interview because most candidates assume some buffer exists. ## What a buffer changes ```go w := bufio.NewWriter(os.Stdout) buffered := slog.New(slog.NewJSONHandler(w, nil)) defer w.Flush() ``` `bufio.NewWriter` gives you a 4096-byte buffer by default. Records are copied into it and only reach the descriptor when the buffer fills or somebody calls `Flush`. The benefit is arithmetic: at, say, 200 bytes a record, one system call now covers about twenty records instead of one. On a service logging tens of thousands of records a second that is a real CPU saving; on a service logging a few hundred a second it is noise, and the formatting and JSON serialisation of the record cost far more than the syscall does anyway. Measure before you assume the syscall is your problem. ## The three costs **1. The loss window.** Everything in the buffer is process memory. It survives only if something drains it. A `defer w.Flush()` in `main` covers the normal return and a panic that unwinds `main`'s own goroutine. It does **not** cover: - `os.Exit` anywhere in the program — it ends the process immediately and runs no deferred functions; - `log.Fatal`/`log.Fatalf`, which are a print followed by `os.Exit(1)`; - SIGTERM with no handler installed, which is how orderly shutdown normally begins; - SIGKILL, which cannot be handled at all; - fatal runtime errors, which run no deferred functions; - a panic on a *different* goroutine, which never unwinds `main`. The records lost are, by construction, the newest ones — the description of whatever just went wrong. **2. Delayed visibility.** A service that logs slowly can hold a record for minutes before the buffer fills. Someone tailing the platform's log view during an incident sees silence and concludes the process is wedged. If you buffer, you need a flush ticker to bound that delay, which erodes the syscall saving you were buying. **3. Extra machinery you now own.** To keep buffering safe you end up adding: flush on every record at error level and above, a periodic flush, a signal handler that flushes on SIGTERM, and a flush at every exit point rather than one `defer`. That is a meaningful amount of code protecting an optimisation you may not need. ## When buffering is still the right call It is defensible when log volume genuinely dominates the workload — a batch job whose whole purpose is to emit millions of records, or a pipeline stage where the log stream *is* the output — and where losing the last few kilobytes on an abnormal exit is acceptable because the outcome is recorded elsewhere. Even then, treat `log.Fatal` as banned in that program, flush on SIGTERM, and prove the tail survives the failure path with a test rather than assuming it. ## The cheaper optimisation If log writes show up in a CPU profile, the usual cause is that you are producing too many records, not that each one costs too much. Cutting per-request info records, or sampling them, removes the formatting cost *and* the syscall, and it takes nothing away from the crash tail. Reach for that before you reach for a buffer. ## Summary Unbuffered is the safe default and the standard library's default: one syscall per record, nothing to lose at exit. A buffer trades the newest records — the ones you most need — for syscalls you probably were not spending much on. Buffer only with a measurement in hand, and only with flushing on error, on a ticker, and on the exit paths.
- How many system calls does a handler writing directly to os.Stdout make per record?One. `os.Stdout` is an `*os.File`, and its `Write` issues the `write` call with the record's bytes; there is no user-space buffer and no line buffering the way C's stdio has. That is exactly why an unbuffered sink loses nothing when the process dies — the bytes are already out.
- If you must buffer, what do you add beyond a single deferred Flush?A flush on every record at error level and above, a periodic flush so visibility does not lag during quiet periods, a SIGTERM handler that flushes on the way out, and an explicit flush at every exit point instead of relying on defer. Plus a test that proves the tail survives the failure path.
- A CPU profile shows log writes costing several percent. Is buffering the first thing to try?No. Look at record volume first. Formatting and serialising a record usually costs more than the syscall that ships it, so cutting or sampling per-request records removes more CPU than batching does — and unlike buffering it takes nothing away from the records written just before a crash.
saying these in an interview costs you the question
- Assumes os.Stdout buffers and flushes on newline
- Adds a buffer without measuring the syscall cost
- Thinks one deferred Flush covers every exit path
- Believes the operating system will flush the buffer at exit
- Buffers a service's log sink for tidiness rather than throughput