Combined stdout and stderr arrive in an order that never happened

Combined stdout and stderr arrive in an order that never happened

reads as

`prog > run.log 2>&1` yields three failure lines followed by three start lines. Conclusion drawn: the failures preceded the work, so something failed before the steps began.

actually

Standard output is fully buffered when it does not refer to an interactive device; standard error is not. Redirected to a file, stdout accumulates and is written in one block at exit while every stderr line goes straight through. The order in the merged file is an artefact of buffering policy, not a record of time.

blind because

A log is read as a sequence and a sequence is read as causality. The merged file records neither the originating stream nor the moment of emission, so the interleaving is the only ordering evidence available and it is precisely the part that was destroyed.

the check

Re-run with stdout unbuffered and compare the two files. Observed on 3.12: a program alternating a stdout line and a stderr line three times produced all three stderr lines before all three stdout lines under `> combined.log 2>&1`, and strictly alternating lines under `PYTHONUNBUFFERED=1`. `stdbuf -oL` did not change it, because the interpreter manages its own buffers rather than libc's.

cost of missing

A cause is assigned to the wrong step, and the fix is applied to whatever the reordering happened to place first.

mitigation

Timestamp at the point of emission, so ordering does not depend on arrival, and keep the two streams separate when their relative order carries meaning.

generalises to

Any merge of independently buffered sources into one ordered view: multi-process logs, distributed traces without synchronised clocks, tail -f across several files.

source

man7.org