Subject: bug#7274: tail-2/F-vs-missing failure on RHEL 5.5 x86-64 + NetApp filer

From: Paul Eggert <[email-masked]>
Date: Sat, 23 Oct 2010 18:39:11 -0700

I got the following failure when running "make test"
on RHEL 5.5 x86-64 when the build directory is served
from a Network Appliance filer.  I'm no expert in what
"tail" is supposed to do here, but a casual look at the
output makes it appear that it might just be a bug in
the test program.  The filer does suffer from minor
clock skew with respect to the RHEL client.

FAIL: tail-2/F-vs-missing (exit: 1)
===================================

++ initial_cwd_=/u/cs/fac/eggert/src/gnu/cu-tmp/tests
+++ testdir_prefix_
+++ printf gt
++ pfx_=gt
+++ mktempd_ /u/cs/fac/eggert/src/gnu/cu-tmp/tests gt-F-vs-missing.XXXX
+++ case $# in
+++ destdir_=/u/cs/fac/eggert/src/gnu/cu-tmp/tests
+++ template_=gt-F-vs-missing.XXXX
+++ MAX_TRIES_=4
+++ case $destdir_ in
+++ case $template_ in
+++ fail=0
++++ unset TMPDIR
++++ mktemp -d -t -p /u/cs/fac/eggert/src/gnu/cu-tmp/tests gt-F-vs-missing.XXXX
+++ d=/u/cs/fac/eggert/src/gnu/cu-tmp/tests/gt-F-vs-missing.PmAp
+++ case $d in
+++ test -d /u/cs/fac/eggert/src/gnu/cu-tmp/tests/gt-F-vs-missing.PmAp
++++ ls -dgo /u/cs/fac/eggert/src/gnu/cu-tmp/tests/gt-F-vs-missing.PmAp
++++ tr S -
+++ perms='drwx------ 2 4096 Oct 23  2010 /u/cs/fac/eggert/src/gnu/cu-tmp/tests/gt-F-vs-missing.PmAp'
+++ case $perms in
+++ test 0 = 0
+++ echo /u/cs/fac/eggert/src/gnu/cu-tmp/tests/gt-F-vs-missing.PmAp
+++ return
++ test_dir_=/u/cs/fac/eggert/src/gnu/cu-tmp/tests/gt-F-vs-missing.PmAp
++ cd /u/cs/fac/eggert/src/gnu/cu-tmp/tests/gt-F-vs-missing.PmAp
++ for sig_ in 1 2 3 13 15
+++ expr 1 + 128
++ eval 'trap '\''Exit 129'\'' 1'
+++ trap 'Exit 129' 1
++ for sig_ in 1 2 3 13 15
+++ expr 2 + 128
++ eval 'trap '\''Exit 130'\'' 2'
+++ trap 'Exit 130' 2
++ for sig_ in 1 2 3 13 15
+++ expr 3 + 128
++ eval 'trap '\''Exit 131'\'' 3'
+++ trap 'Exit 131' 3
++ for sig_ in 1 2 3 13 15
+++ expr 13 + 128
++ eval 'trap '\''Exit 141'\'' 13'
+++ trap 'Exit 141' 13
++ for sig_ in 1 2 3 13 15
+++ expr 15 + 128
++ eval 'trap '\''Exit 143'\'' 15'
+++ trap 'Exit 143' 15
++ trap remove_tmp_ 0
+ path_prepend_ ../src
+ test 1 '!=' 0
+ path_dir_=../src
+ case $path_dir_ in
++ cd /u/cs/fac/eggert/src/gnu/cu-tmp/tests/../src
++ echo /u/cs/fac/eggert/src/gnu/cu-tmp/src
+ abs_path_dir_=/u/cs/fac/eggert/src/gnu/cu-tmp/src
+ case $abs_path_dir_ in
+ PATH=/u/cs/fac/eggert/src/gnu/cu-tmp/src:/u/cs/fac/eggert/src/gnu/cu-tmp/src:/u/cs/fac/eggert/bin:/usr/local/cs/bin:/usr/local/bin:/usr/local/sbin:/usr/bin:/usr/sbin:/usr/X11R6/bin:/bin:/sbin
+ create_exe_shims_ /u/cs/fac/eggert/src/gnu/cu-tmp/src
+ case $EXEEXT in
+ return 0
+ shift
+ test 0 '!=' 0
+ export PATH
+ test yes = yes
+ tail --version
tail (GNU coreutils) 8.6.9-d5d8-dirty
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>.
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

Written by Paul Rubin, David MacKenzie, Ian Lance Taylor,
and Jim Meyering.
+ debug=---disable-inotify
+ debug=
+ tail -F -s.1 missing/file
+ pid=21936
+ tail_re='cannot open'
+ retry_delay_ check_tail_output .1 7
+ local test_func=check_tail_output
+ local init_delay=.1
+ local max_n_tries=7
+ local attempt=1
+ local num_sleeps=1
+ local time_fail
+ test 1 -le 7
++ gawk -v n=1 -v s=.1 'BEGIN { for (i=0;i<n;i++) t = s" "t; print t }'
+ local 'delay=.1 '
+ check_tail_output '.1 '
+ local 'delay=.1 '
+ grep 'cannot open' out
+ time_fail=0
+ break
+ test 0 = 0
+ mkdir missing
+ cd missing
+ echo x
+ tail_re='has appeared'
+ retry_delay_ check_tail_output .1 7
+ local test_func=check_tail_output
+ local init_delay=.1
+ local max_n_tries=7
+ local attempt=1
+ local num_sleeps=1
+ local time_fail
+ test 1 -le 7
++ gawk -v n=1 -v s=.1 'BEGIN { for (i=0;i<n;i++) t = s" "t; print t }'
+ local 'delay=.1 '
+ check_tail_output '.1 '
+ local 'delay=.1 '
+ grep 'has appeared' out
+ sleep .1
+ return 1
+ time_fail=1
++ expr 1 + 1
+ attempt=2
++ expr 1 '*' 2
+ num_sleeps=2
+ test 2 -le 7
++ gawk -v n=2 -v s=.1 'BEGIN { for (i=0;i<n;i++) t = s" "t; print t }'
+ local 'delay=.1 .1 '
+ check_tail_output '.1 .1 '
+ local 'delay=.1 .1 '
+ grep 'has appeared' out
+ sleep .1 .1
+ return 1
+ time_fail=1
++ expr 2 + 1
+ attempt=3
++ expr 2 '*' 2
+ num_sleeps=4
+ test 3 -le 7
++ gawk -v n=4 -v s=.1 'BEGIN { for (i=0;i<n;i++) t = s" "t; print t }'
+ local 'delay=.1 .1 .1 .1 '
+ check_tail_output '.1 .1 .1 .1 '
+ local 'delay=.1 .1 .1 .1 '
+ grep 'has appeared' out
+ sleep .1 .1 .1 .1
+ return 1
+ time_fail=1
++ expr 3 + 1
+ attempt=4
++ expr 4 '*' 2
+ num_sleeps=8
+ test 4 -le 7
++ gawk -v n=8 -v s=.1 'BEGIN { for (i=0;i<n;i++) t = s" "t; print t }'
+ local 'delay=.1 .1 .1 .1 .1 .1 .1 .1 '
+ check_tail_output '.1 .1 .1 .1 .1 .1 .1 .1 '
+ local 'delay=.1 .1 .1 .1 .1 .1 .1 .1 '
+ grep 'has appeared' out
+ sleep .1 .1 .1 .1 .1 .1 .1 .1
+ return 1
+ time_fail=1
++ expr 4 + 1
+ attempt=5
++ expr 8 '*' 2
+ num_sleeps=16
+ test 5 -le 7
++ gawk -v n=16 -v s=.1 'BEGIN { for (i=0;i<n;i++) t = s" "t; print t }'
+ local 'delay=.1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 '
+ check_tail_output '.1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 '
+ local 'delay=.1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 '
+ grep 'has appeared' out
+ sleep .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1
+ return 1
+ time_fail=1
++ expr 5 + 1
+ attempt=6
++ expr 16 '*' 2
+ num_sleeps=32
+ test 6 -le 7
++ gawk -v n=32 -v s=.1 'BEGIN { for (i=0;i<n;i++) t = s" "t; print t }'
+ local 'delay=.1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 '
+ check_tail_output '.1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 '
+ local 'delay=.1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 '
+ grep 'has appeared' out
+ sleep .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1
+ return 1
+ time_fail=1
++ expr 6 + 1
+ attempt=7
++ expr 32 '*' 2
+ num_sleeps=64
+ test 7 -le 7
++ gawk -v n=64 -v s=.1 'BEGIN { for (i=0;i<n;i++) t = s" "t; print t }'
+ local 'delay=.1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 '
+ check_tail_output '.1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 '
+ local 'delay=.1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 '
+ grep 'has appeared' out
+ sleep .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1 .1
+ return 1
+ time_fail=1
++ expr 7 + 1
+ attempt=8
++ expr 64 '*' 2
+ num_sleeps=128
+ test 8 -le 7
+ test 1 = 0
+ echo './tail-2/F-vs-missing: file: unexpected delay?'
./tail-2/F-vs-missing: file: unexpected delay?
+ cat out
tail: cannot open `missing/file' for reading: No such file or directory
tail: cannot watch parent directory of `missing/file': No such file or directory
tail: inotify cannot be used, reverting to polling
tail: `missing/file' has been replaced with a remote file. giving up on this name
+ fail=1
+ kill -HUP 21936
+ Exit 1
+ set +e
+ exit 1
+ exit 1
+ remove_tmp_
+ __st=1
+ cleanup_
+ :
+ cd /u/cs/fac/eggert/src/gnu/cu-tmp/tests
+ chmod -R u+rwx /u/cs/fac/eggert/src/gnu/cu-tmp/tests/gt-F-vs-missing.PmAp
+ rm -rf /u/cs/fac/eggert/src/gnu/cu-tmp/tests/gt-F-vs-missing.PmAp
+ exit 1