Re: Failed with output: Hydra job gnu:coreutils-master:build on x86_64-linux

[Pádraig Brady]

On 06/02/2013 08:24 PM, Hydra Build Daemon wrote:
> Hi,
> 
> The status of Hydra job gnu:coreutils-master:build (on x86_64-linux) has 
> changed from "Success" to "Failed with output".  For details, see
> 
>   http://hydra.nixos.org/build/5221053
> 
> Go forth and fix it.

The failing test was:

FAIL: tests/tail-2/retry.sh (exit: 1)
=====================================

 tail: warning: --retry ignored; --retry is useful only when following
 tail: warning: --retry ignored; --retry is useful only when following
 X
 X
 X
 X
 tail: warning: --retry only effective for the initial open
 tail: cannot open 'missing' for reading: No such file or directory
 tail: 'missing' has appeared;  following end of new file
 X
 tail: warning: --retry only effective for the initial open
 tail: cannot open 'missing' for reading: No such file or directory
 tail: 'missing' has been replaced with an untailable file; giving up on this 
name
 tail: no files remaining
 tail: cannot open 'missing' for reading: No such file or directory
 tail: no files remaining
 tail: cannot open 'missing' for reading: No such file or directory
 tail: no files remaining

The interesting part was the first 4 "X"s,
which shouldn't all have appeared, and correspond to this part of the test:

 # === Test:
 # Ensure that "tail --retry --follow=name" waits for the file to appear.
 timeout 10 tail -s.1 --follow=name --retry missing >out 2>&1 & pid=$!
 retry_delay_ wait4lines_ .1 6 1 || fail=1  # Wait for "cannot open" error.
 echo "X" > missing              || fail=1  # Write "X" into 'missing'.
 retry_delay_ wait4lines_ .1 6 3 || fail=1  # Wait for the expected output.
 kill $pid
 wait $pid
 # Expect 3 lines in the output file.
 [ $( wc -l < out ) = 3 ]            || { fail=1; cat out; }
 grep -F 'cannot open' out           || { fail=1; cat out; }
 grep -F 'has become accessible' out || { fail=1; cat out; }
 grep '^X$' out                      || { fail=1; cat out; }
 rm -f missing out                   || fail=1

So there were no errors generated, which suggests that the "missing"
file was already present at the time the test has run.

That surprises me, but suggests the shell doesn't ensure that the "out" file
is truncated before it runs the above tail command in the background.
I'm not sure why I thought that "out" was opened/truncated
in the parent shell _first_ and then inherited by the subshell,
but I think I've confirmed the race by looking at which pids exec() and open() 
in:

  strace -e execve,open -f sh -c '/bin/false > /tmp/pb.out & date'

The attached patch hopefully avoids this issue.
It also incorporates some cleanup, but boils down to:

diff --git a/tests/tail-2/retry.sh b/tests/tail-2/retry.sh
index d56d4c1..a35f72a 100644
--- a/tests/tail-2/retry.sh
+++ b/tests/tail-2/retry.sh
@@ -44,6 +44,7 @@ grep -F 'tail: warning: --retry ignored' out || fail=1

 # === Test:
 # Ensure that "tail --retry --follow=name" waits for the file to appear.
+rm out                          || framework_failure_
 timeout 10 tail -s.1 --follow=name --retry missing >out 2>&1 & pid=$!
 retry_delay_ wait4lines_ .1 6 1 || fail=1  # Wait for "cannot open" error.
 echo "X" > missing              || fail=1  # Write "X" into 'missing'.

thanks,
Pádraig.

p.s. The above was a bit tricky to diagnose because VERBOSE=1 wasn't
set in the tests, which I've requested now independently.

tail-retry-race.patch
Description: Text Data