This is anecdote about roundabout ways to get stuff done. Pierre mentioned in the comments below that a proper way to solve this is to use unbuffer (though it does _not_ produce the exact same order as the terminal!). But if you want to read the improper way to do this, read on! :)
Due to buffering, the terminal messes with the order of stdout and stderr of a program when redirecting to a file or another program. It prints the outputs of both descriptors in correct order relative to each other when printing straight to the terminal:
] ./my_program stdout line 1 stdout line 2 stderr line 1 stdout line 3 stderr line 2 stderr line 3
This doesn’t change the order:
] ./my_program 2>&1 stdout line 1 stdout line 2 stderr line 1 stdout line 3 stderr line 2 stderr line 3
but it changes the order when saving to a file or redirecting to any program:
] ./my_program 2>&1 | cat stderr line 1 stderr line 2 stderr line 3 stdout line 1 stdout line 2 stdout line 3
This behavior is the same in three shells I tested (bash, zsh, dash).
A weird “solution”
I wanted to save the log while preserving the order of events. So I ended up with this evil hack:
] strace -ewrite -o trace.txt -s 2048 ./my_program; sed 's,^[^"]*"\(.*\)"[^"]*$,\1,g;s,\\n,,g;' trace.txt > mytrace.txt ] cat mytrace.txt stdout line 1 stdout line 2 stderr line 1 stdout line 3 stderr line 2 stderr line 3 +++ exited with 0 +++
It turns out that strace does log each write in the correct order, so I’m catching the write syscall.
Note the limitations: it truncates lines to 2048 characters (good enough for my logs) and I was simply cutting off n and not cleaning up any other escape characters. But it worked well enough so I could read my ordered logs in a text editor!
Fill out the form below to add your own comments.