I just hit some unexpected unix-ism (or maybe Linux-ism?) that I'd like to mention here. I found a workaround, but if anybody knows what's actually happening and can enlighten me, please send me an email, and I'll update the post.
OK, so I have a program that does stuff, and outputs its progress to stderr. And I'm invoking this from a shell script that also outputs stuff to stderr. A minimized sample:
echo "Outer print 1111" > /dev/stderr perl -E 'say STDERR ("1111 1111 1111 1111 1111 1111 1111 1111\n")' echo "Outer print 2222" > /dev/stderr perl -E 'say STDERR ("2222 2222 2222 2222 2222 2222 2222 2222\n")'
Let's call this dothing.sh
. This works just fine. Now let's say I want to log
the output to a file. Naturally I do this:
./dothing.sh 2> /tmp/log
Surprisingly, this does not work:
$ bash dothing.sh 2> /tmp/log && cat /tmp/log Outer print 2222 2222 2222 2222 2222 2222 2222 2222 2222 $ bash dothing.sh 2> /tmp/log && xxd /tmp/log 0000000: 4f75 7465 7220 7072 696e 7420 3232 3232 Outer print 2222 0000010: 0a00 0000 0000 0000 0000 0000 0000 0000 ................ 0000020: 0000 0000 0000 0000 0032 3232 3220 3232 .........2222 22 0000030: 3232 2032 3232 3220 3232 3232 2032 3232 22 2222 2222 222 0000040: 3220 3232 3232 2032 3232 3220 3232 3232 2 2222 2222 2222 0000050: 0a0a ..
The 1111
prints are gone, and we now have a block of binary 0 bytes in there
for some reason. I had been assuming that writes to stderr block until they're
finished. So I can, without thinking about it, mix writing to fd 2 and opening,
and then writing to /dev/stderr
. Apparently the right way to do this is to
write to fd 2 in the script directly, instead of opening /dev/stderr
:
echo "Outer print 1111" >&2 perl -E 'say STDERR ("1111 1111 1111 1111 1111 1111 1111 1111\n")' echo "Outer print 2222" >&2 perl -E 'say STDERR ("2222 2222 2222 2222 2222 2222 2222 2222\n")'
Why?
Update
So I poked at it for a bit more, and it turns out that the obvious scapegoat (buffering) is actually not the issue. The problem is this:
$ ls -l /dev/stderr(:A) -rw-r--r-- 1 dima dima 36 May 4 17:02 /tmp/log
:A
is the zsh syntax for recursive link-following. /dev/stderr
is
thus ultimately a link to /tmp/log
. So the file on disk /tmp/log
is
being opened for writing and written-to twice at the same time
- once in the outer
2>/tmp/log
redirection - again in the inner
>/dev/stderr
redirection
Now we know. Thanks to Larry Doolittle for pointers.