Stdio Buffering — Line vs Block (Pipes Change Your Program)
Why Your Logs Disappear The Moment You Pipe Them
Developer toolingdeveloper tooling / debugging
The symptom
Your worker prints progress every second. Run it in the terminal: perfect, one line per second.
$ python3 worker.py
processing 1
processing 2 ...
Add a pipe so you can keep a copy:
$ python3 worker.py | tee run.log
…silence. Nothing for two minutes. Then 400 lines land at once. You didn't change a line of code. Same binary, same machine.
Step 1: blame the pipe? No — blame isatty()
When a C program (or Python, Ruby, Perl) first writes to stdout, libc/stdio asks one question: is this fd a terminal?
- TTY → LINE buffered: flush on every \n
- pipe or file → FULLY buffered: flush every ~4–8 KB (glibc BUFSIZ = 8192)
- stderr → unbuffered / line-buffered, always
So piping silently switches your program from "flush per line" to "flush per 8 KB". At ~30 bytes a line that's ~270 lines of latency.
Step 2: prove it in 5 seconds
$ python3 -c 'print("hi"); import time; time.sleep(20)' # prints instantly
$ python3 -c 'print("hi"); import time; time.sleep(20)' | cat # prints after 20s
Same code. The only difference is what fd 1 is attached to.
Step 3: the consequences you've already been bitten by
- Empty
docker logson a running container — the app is buffering, Docker isn't losing anything. - Crash loses the last 200 log lines: SIGKILL kills the process with a full buffer in userspace. It never reached the kernel.
cmd > log 2>&1gives out-of-order logs: stderr is unbuffered so tracebacks land before the stdout lines that preceded them.
Step 4: fixes, in order of preference
- Python:
python3 -u worker.py, or PYTHONUNBUFFERED=1 (set this in every Dockerfile) - Generic libc programs:
stdbuf -oL -eL ./prog | tee run.log - Node: nothing to do — but see the gotcha below
- In your own code: flush=True / setvbuf(stdout, NULL, _IOLBF, 0) / w.Flush()
The gotchas that separate intermediate from beginner
- stdbuf often does NOTHING for Python. It works by LD_PRELOADing a shim over libc stdio; Python's io module does its own buffering in userspace. Use -u.
- Go doesn't use libc stdio at all — os.Stdout writes straight through. But if you wrapped it in bufio.Writer, you own the flush.
- Node's stdout is not block-buffered, but writes to a pipe are asynchronous.
console.log(big); process.exit(0)can truncate output. Exit by letting the event loop drain, not process.exit(). docker run -tallocates a pseudo-TTY, so apps flip to line-buffered and "the bug disappears." That's a disguise, not a fix — prod without -t buffers again.- Logging to a file buffers exactly like a pipe. tail -f on a fully buffered log is just as blind.
Your exercise
Run this and watch the ordering:
$ python3 -c 'import sys; [ (print(f"out {i}"), print(f"err {i}", file=sys.stderr)) for i in range(3) ]' > /tmp/all.log 2>&1
$ cat /tmp/all.log
Question: why do all three "err" lines appear before all three "out" lines, even though your code alternates them? Then re-run with -u and explain what changed.