Redirecting output can result in altered program behavior


Consider a program whose output to the console goes like this. (I've prefixed each line with the output stream.)

stdout: line 1
stderr: err 1
stdout: line 2
stderr: err 2

You want to capture both the normal and error streams, so you run the program and append ">output 2>&1" to capture both streams into a single file. But when you look at the resulting output file, you get this:

line 1
line 2
err 1
err 2

What happened?

Most programs change their output behavior depending on whether the output stream is a file or a device. If the output stream is a device (such as the screen), then buffering is disabled and every print statement goes to the screen immediately. On the other hand, if the output stream is a file, then buffering is enabled and print statements do not go directly into the file but rather into an application-managed memory buffer. When the buffer fills, it is written to the file, and then the buffer is emptied so it can accept more output.

This explains the behavior we see above. The program generates its output to both stdout and stderr, and the results are buffered. When the program exits, the buffers are flushed, first stdout and then stderr. That's why you see all the stdout output grouped together and all the stderr output grouped together.

"But I don't do any of this in my programs; why is it happening anyway?"

If you use the C runtime for your output, then your program does behave this way whether you realize it or not. The default behavior of the C runtimes is to perform unbuffered I/O for devices and buffered I/O for files. You can override this behavior in your own programs by calling setvbuf to force buffering on or off for a file handle.

(A classmate in college became legendary for fixing a bug in one of the programs used in the VLSI class, all of which were notoriously buggy. He patched the binary to disable buffered I/O.)

Comments (15)
  1. Anonymous says:

    And, of course, there is the behaviour of the Unix "ls", which when redirected (or piped) automagically switches from using several columns to a "one file per line" mode.

  2. Stu says:

    On UNIX, well Linux at least, console output is also buffered, the buffer is flushed when a newline is output.

    Makes things interesting when you’re using good old printf debugging if you don’t put "n"’s on all your debugging output.

  3. rolfhub says:

    Well, good to know all that, but what would a user do in the following situation:

    – He wants to have the output (both stdout and stderr) redirected to a file, but in the same order the statements would appear on the console

    – The software is not open source, he doesn’t have the source code, and he is not skilled enough to patch a binary

    What would he do? (When using Unix/Linux vs. when using Windows)

  4. BryanK says:

    Anonymous — that’s because /bin/ls does an "if(isatty(1))" while deciding how to format its output.

    If its stdout (file-handle 1) is a TTY, then it uses several columns.  If not, it uses one.  (This is so you don’t have to remember to "ls -1" every time you need to redirect the output.  You can if you want to, but if stdout is a pipe or a normal file, then it won’t make any difference.)

  5. bramster says:

    Well, good to know all that, but what would a user do in the following situation:

    "- He wants to have the output (both stdout and stderr) redirected to a file, but in the same order the statements would appear on the console

    – The software is not open source, he doesn’t have the source code, and he is not skilled enough to patch a binary

    What would he do? (When using Unix/Linux vs. when using Windows)"

    I’d timestamp each message, combine the files, sort the combined file by timestamp.

  6. Craig Ringer says:

    [sorry if this is repeated. I’m pretty sure the last submit failed, but … who knows.]

    bramster: The same way you do it on an old bourne-compatible shell on UNIX:

       command > output_file 2>&1

    I tested this on cmd.exe on XP SP2 and it works fine. Here’s the test program I used, which produced identical output in the target file and on the console (and worked correctly with redirections of just stdout or just stderr).

    #include <iostream>

    int main() {

    using namespace std;

    cout << "This is on stdout" << endl;

    cerr << "This is on stderr" << endl;

    cout << "This is also on stdout";

    cerr << "this is also on stderr";

    cout << endl;

    cerr << endl;

    return 0;

    }

    I guess the NT POSIX system has some nice legacy lying around. I wonder what I can do with passing file descriptors around etc…

  7. Reading this made me realise why trace output to an output file wasn’t writing… bloody Flush()!

    Thanks Raymond! :)

  8. Pravin Wagh says:

    Craig, I think it worked that way because of your use of ‘endl’ which I believe causes the buffer to be flushed.  If you had used "n" instead, your output might have been subjected to the buffering rules.

  9. When you output your debug statements (stderr and stdout, in Java which is System.err and System.out respectively) to a file, do take I/O buffering into consideration. You may not see your output lines in the sequence you expect if your program is perfor

  10. difference between n and endl says:

    n is buffered.

    endl is not.

  11. Brooks Moses says:

    Rolfhub: I think the only way to reliably do that is to take the axioms as completely true.  If the program behaves differently when redirected than when printing to console, and one wishes to capture what it prints to the console, then one must let it print to the console and capture the result.

    I suggest looking into shell logging features of some sort.

  12. rolfhub says:

    Friday, May 19, 2006 3:00 PM by bramster

    >> Well, good to know all that, but what would a user do in the following

    >> situation:

    >>

    >> – He wants to have the output (both stdout and stderr) redirected to a file,

    >> but in the same order the statements would appear on the console

    >>

    >> – The software is not open source, he doesn’t have the source code, and he is

    >> not skilled enough to patch a binary

    >>

    >> What would he do? (When using Unix/Linux vs. when using Windows)

    >

    > I’d timestamp each message, combine the files, sort the combined file by

    > timestamp.

    >

    >

    >

    > Saturday, May 20, 2006 2:58 PM by Brooks Moses

    > Rolfhub: I think the only way to reliably do that is to take the axioms as

    > completely true.  If the program behaves differently when redirected than when

    > printing to console, and one wishes to capture what it prints to the console,

    > then one must let it print to the console and capture the result.

    >

    > I suggest looking into shell logging features of some sort.

    Well, thank you both, but I thought there were an easy way to do so (since the task at hand sounds real simple), but sometimes the easy sounding tasks end up causing the headache …

    I don’t have (at the moment) a program at hand where the order of redirected output would matter to me, but from time to time it would be so very useful to have an easy way. Maybe Monad could tackle this problem, please?

  13. ReuvenLax says:

    You’re bringing back fun memories of my VLSI class.  We used a wonderfully-outdated design tool called Magic, and ran simulations using P-Spice.  Great for learning how things really work, but a bit removed from how VLSI design is really done these days.

  14. Neil says:

    BSD3-derived Unix variantes provide pseudo ttys that are a cross between a pair of pipes and a tty. It’s how xterm etc. work for instance. There is also a utility called "script" which does just what rolfhub wants. Note that it is not a good idea to use "script" to work out which control codes "vi" uses. Fortunately my Comp. Sci. professor shall remain nameless as I have forgotton.

  15. rolfhub says:

    There is also a utility called "script" which does just what rolfhub wants.

    Well, I’ve read the manpage, and it looks quite useful, especially:

    —[from man script]—

    -c COMMAND

    Run the COMMAND rather than an interactive shell. This makes it easy for a script to capture the output of a program that behaves differently when its stdout is not a tty.

    —[/from man script]—

    > Note that it is not a good idea to use "script" to work out which control codes

    > "vi" uses. Fortunately my Comp. Sci. professor shall remain nameless as I have

    > forgotton.

    The manpage seems to have improved since then ;-)

    —[from man script]—

    Certain interactive commands, such as vi(1), create garbage in the typescript file.

    —[/from man script]—

    Thank you for the info. Now, if anyone knows an equivalent for windows, that would be cool, too.

Comments are closed.