Re: Timing issue in t5570 "daemon log records all attributes"

[Jeff King <peff@peff.net>]

On Tue, Apr 03, 2018 at 09:33:10PM +0200, Jan Palus wrote:

> My understanding of test "daemon log records all attributes" is that daemon
> process is started in background, some git command is executed and daemon's
> output (saved to daemon.log) is compared against expected value. However
> daemon.log is not a straight redirect to file -- it is being piped through fifo,
> read by a loop in test-git-daemon.sh, additional processing is performed and
> finally it makes it to daemon.log. All of this performed concurrently with test
> execution. My question is how do you exactly avoid timing issues here? grep on
> daemon.log is performed immediately after git invocation:
> 
>         >daemon.log &&
>         GIT_OVERRIDE_VIRTUAL_HOST=localhost \
>                 git -c protocol.version=1 \
>                         ls-remote "$GIT_DAEMON_URL/interp.git" &&
>         grep -i extended.attribute daemon.log | cut -d" " -f2- >actual &&
> 
> how can you be sure grep operates on daemon.log that already includes all output
> and not on intermediate state that is just being processed by while loop? Same
> question applies to ">daemon.log" since shell might still be processing output
> of previous test and its content might possibly land in the file after zeroing.

You're right, this is racy. You can see it much more obviously with:

diff --git a/t/lib-git-daemon.sh b/t/lib-git-daemon.sh
index edbea2d986..3c7fea169b 100644
--- a/t/lib-git-daemon.sh
+++ b/t/lib-git-daemon.sh
@@ -62,6 +62,7 @@ start_git_daemon() {
 		(
 			while read -r line <&7
 			do
+				sleep 1
 				printf "%s\n" "$line"
 				printf >&4 "%s\n" "$line"
 			done

I'm not sure of the best solution. Even if we removed the shell-loop
pumping the data from the fifo, it's still possible to race if
git-daemon hangs up the client socket before flushing its log output
(since our only real synchronization is waiting for the client to exit).

Nor could we even wait for an EOF on the fifo, since we won't get one
until the daemon actually exits.

If we want to do it without polling, I think the best we could do is
have the pumping loop key on some particular line in the output as a
synchronization point, and then trigger _another_ fifo that the test
snippet listens on. Yuck.

I'm tempted to say we should just scrap this test. It was added
relatively recently and only shows the fix for a pretty minor bug.
It's probably not worth the contortions to make it race-proof.

-Peff