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.
>From 12b6c3bf70dde23c2c1bf5db7650a959f327b04f Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?P=C3=A1draig=20Brady?= <[email protected]>
Date: Mon, 3 Jun 2013 01:29:17 +0100
Subject: [PATCH] tests: avoid a race in tail --retry testing
Prompted by the continuous integration build failure at:
http://hydra.nixos.org/build/5221053
* tests/tail-2/retry.sh: Ensure the 'out' file is not present
as it's used to arbitrate the run order of commands.
Relying on the truncation in the background tail command,
is racy because the truncation can occur after the fork
of the background shell and thus the 'missing' file could
be created by the time tail(1) looks for it.
---
tests/tail-2/retry.sh | 11 ++++++-----
1 files changed, 6 insertions(+), 5 deletions(-)
diff --git a/tests/tail-2/retry.sh b/tests/tail-2/retry.sh
index d56d4c1..070e4fd 100644
--- a/tests/tail-2/retry.sh
+++ b/tests/tail-2/retry.sh
@@ -44,9 +44,10 @@ 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'.
+echo "X" > missing || fail=1
retry_delay_ wait4lines_ .1 6 3 || fail=1 # Wait for the expected output.
kill $pid
wait $pid
@@ -55,14 +56,14 @@ wait $pid
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
+rm -f missing out || framework_failure_
# === Test:
# Ensure that "tail --retry --follow=descriptor" waits for the file to appear.
# tail-8.21 failed at this (since the implementation of the inotify support).
timeout 10 tail -s.1 --follow=descriptor --retry missing >out 2>&1 & pid=$!
retry_delay_ wait4lines_ .1 6 2 || fail=1 # Wait for "cannot open" error.
-echo "X" > missing || fail=1 # Write "X" into 'missing'.
+echo "X" > missing || fail=1
retry_delay_ wait4lines_ .1 6 4 || fail=1 # Wait for the expected output.
kill $pid
wait $pid
@@ -73,7 +74,7 @@ grep -F 'retry only effective for the initial open' out \
grep -F 'cannot open' out || { fail=1; cat out; }
grep -F 'has appeared' out || { fail=1; cat out; }
grep '^X$' out || { fail=1; cat out; }
-rm -f missing out || fail=1
+rm -f missing out || framework_failure_
# === Test:
# Ensure that tail --follow=descriptor --retry exits when the file appears
@@ -91,7 +92,7 @@ grep -F 'cannot open' out || { fail=1; cat out; }
grep -F 'replaced with an untailable file' out || { fail=1; cat out; }
grep -F 'no files remaining' out || { fail=1; cat out; }
[ $rc = 1 ] || { fail=1; cat out; }
-rm -fd missing out || fail=1
+rm -fd missing out || framework_failure_
# === Test:
# Ensure that --follow=descriptor (without --retry) does *not wait* for the
--
1.7.7.6
