Re: t5401-update-hooks test failure

On Tue, 9 Feb 2010, Shawn O. Pearce wrote:

Junio C Hamano [off-list ref] wrote:

quoted

$ while sh t5401-*.sh -i; do :; done
... wait for a while ...
* FAIL 12: send-pack stderr contains hook messages

                grep ^remote: send.err | sed "s/ *\$//" >actual &&
                test_cmp - actual <expect

$ t/(364643e...); cat trash\ directory.t5401-update-hooks/actual 
remote: STDOUT pre-receive
remote: STDERR pre-receive
remote: STDOUT update refs/heads/master
remote: STDERR update refs/heads/master
remote: STDOUT update refs/heads/tofail
remote: STDOUT post-receive
remote: STDERR post-receive
remote: STDOUT post-update
remote: STDERR post-update
$ t/(364643e...); cat trash\ directory.t5401-update-hooks/expect 
remote: STDOUT pre-receive
remote: STDERR pre-receive
remote: STDOUT update refs/heads/master
remote: STDERR update refs/heads/master
remote: STDOUT update refs/heads/tofail
remote: STDERR update refs/heads/tofail
remote: STDOUT post-receive
remote: STDERR post-receive
remote: STDOUT post-update
remote: STDERR post-update

A quick visual inspection shows that only the STDERR tofail message
is missing here.  That sounds to me like a race condition in the
recv_sideband decoder.  Or, a race condition in the hook code in
builtin-receive-pack.c.

I doubt its in receive-pack. run_update_hook() directly calls the
copy_to_sideband() function, and that reads until EOF on the hook's
stderr stream before it returns and waits for the hook's exit status.
So we should be pulling everything and dumping it into the sideband.

builtin-send-pack.c clearly isn't stopping early while processing
the stream, since we see later messages from the post-receive and
post-update hooks just fine.

So I think the only code that is in question is the case 2 arm of
recv_sideband().  But to be honest, I can't find any fault with it.

Note that strict order of messages passed through the sideband can't be 
relied upon.  Often you have sideband 1 connected to stdin and sideband 
2 connected to stderr, and they are linked with pipes, and various 
factors such as stdio buffering or even printf implementation in the C 
lib, pipe buffers in the OS, random scheduling between the processes 
involved, and other factors such as disk or network speed vs CPU speed, 
are all adding to a certain degree of randomness affecting how the data 
end up in various channels wrt each other.

See my efforts to reduce that issue so far with those commits:

6b59f51b312f06d9420d34c09fa408c658aac6d2

6b9c42b4daabe3d0471d9f90d2ae472c9d994e1c

d048a96ee9bec968be0bdc9c43ffce61169545be

ebe8fa738dcf6911fe520adce0cfa0cb26dee5e2


Nicolas