Subject: bug#33946: tail -f stops abruptly in AIX when piped.

From: Pádraig Brady <[email-masked]>
Date: Sun, 20 Jan 2019 01:00:27 -0800

On 17/01/19 06:25, Bernhard Voelker wrote:
> On 1/16/19 4:09 AM, Pádraig Brady wrote:
>> On 14/01/19 23:54, Bernhard Voelker wrote:
>>> On 1/13/19 4:31 AM, Pádraig Brady wrote:
>>>> Thanks for testing. Pushed at:
>>>> https://git.sv.gnu.org/gitweb/?p=coreutils.git;a=commitdiff;h=d5ab4cb
>>>
>>>> -timeout 10 tail -f $mode $fastpoll out | sleep .1 || fail=1
>>>> +(returns_ 124 timeout 10 tail -n2 -f $mode $fastpoll out && touch timed_out) |
>>>> + sed 2q > out2
>>>> +test -e timed_out && fail=1
>>>> +compare exp out2 || fail=1
>>>
>>> I see the 'timed_out' file when running the test on openSUSE's build service
>>> for Linux x86_64, and can reproduce when running that in the local 'osc' build
>>> environment (chroot-based).
>>>
>>> I'm not sure what's the problem though, but could this be related to
>>> how we fixed 'tests/misc/seq-epipe.sh' a while ago in v8.25-42-g383e4b2ce?
>>
>> I can't see the problem offhand.
> 
> I also still don't see the problem.  In the log, it's just:
> 
> + returns_ 124 timeout 10 tail -n2 -f ---disable-inotify -s.1 --max-unchanged-stats=1 out
> + sed 2q
> + touch timed_out
> + test -e timed_out
> + fail=1
> 
> Well, under strace:
> 
> In the good case, i.e., without chroot, the process terminates upon the first
> SIGPIPE received:
> 
>   ...
>   inotify_init()                          = 4
>   write(1, "==> standard input <==\nar\n", 26) = 26
>   inotify_add_watch(4, "out", IN_MODIFY)  = 1
>   stat("out", {st_dev=makedev(0x8, 0x20), st_ino=298091, st_mode=S_IFREG|0644, st_nlink=1, st_uid=717, st_gid=1000, ...}) = 0
>   fstat(3, {st_dev=makedev(0x8, 0x20), st_ino=298091, st_mode=S_IFREG|0644, st_nlink=1, st_uid=717, st_gid=1000, ...}) = 0
>   select(5, [1 4], NULL, NULL, NULL)      = 1 (in [1])
>   rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [], 8) = 0
>   getpid()                                = 29422
>   gettid()                                = 29422
>   tgkill(29422, 29422, SIGPIPE)           = 0
>   rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
>   --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_TKILL, si_pid=29422, si_uid=717} ---
>   +++ killed by SIGPIPE +++
> 
> In the bad case, i.e., in the chroot'ed "osc build" environment or on 'build.opensuse.org',
> I see:
> 
>   ...
>   inotify_init()                          = 4
>   write(1, "==> standard input <==\nar\n", 26) = 26
>   inotify_add_watch(4, "out", IN_MODIFY)  = 1
>   stat("out", {st_dev=makedev(0x8, 0x1), st_ino=192286, st_mode=S_IFREG|0644, st_nlink=1, st_uid=399, st_gid=399, ...}) = 0
>   fstat(3, {st_dev=makedev(0x8, 0x1), st_ino=192286, st_mode=S_IFREG|0644, st_nlink=1, st_uid=399, st_gid=399, ...}) = 0
>   select(5, [1 4], NULL, NULL, NULL)      = 1 (in [1])
>   rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [], 8) = 0
>   getpid()                                = 29191
>   gettid()                                = 29191
>   tgkill(29191, 29191, SIGPIPE)           = 0
>   rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
>   --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_TKILL, si_pid=29191, si_uid=399} ---
>   select(5, [1 4], NULL, NULL, NULL)      = 1 (in [1])
>   rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [], 8) = 0
>   getpid()                                = 29191
>   gettid()                                = 29191
>   tgkill(29191, 29191, SIGPIPE)           = 0
>   rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
>   --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_TKILL, si_pid=29191, si_uid=399} ---
>   select(5, [1 4], NULL, NULL, NULL)      = 1 (in [1])
>   rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [], 8) = 0
>   getpid()                                = 29191
>   gettid()                                = 29191
>   tgkill(29191, 29191, SIGPIPE)           = 0
>   rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
>   --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_TKILL, si_pid=29191, si_uid=399} ---
>   [... a.s.o ...]
> 
> and finally gets killed by 'timeout 10':
> 
>   ...
>   --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_TKILL, si_pid=29191, si_uid=399} ---
>   --- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=29187, si_uid=399} ---
>   +++ killed by SIGTERM +++
> 
> Any idea?

Right. So the broken pipe is detected fine which is the main thing.
It's just that the osc system has SIGPIPE ignored
(python2 based systems do this by default, which may be related).

I was looking are setting normal handling with `trap - SIGPIPE` in the test,
but that's only effective if ignored in the same shell.
If the parent/login shell has ignored SIGPIPE,
then resetting it is ineffective.
However...

tail should be exiting irrespective of the handling of SIGPIPE.
In fact it goes into an infinite loop in the edge case of:
inotify + ignored sigpipe + early exit filters.

The attached ensures the tail process exits,
which handles the infinite loop and the test failure.

cheers,
Pádraig.

From cf36c2983a150d5e9a9bf631832a91d4a31259d0 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?P=C3=A1draig=20Brady?= <[email-masked]>
Date: Sun, 20 Jan 2019 00:13:15 -0800
Subject: [PATCH] tail: fix handling of broken pipes with SIGPIPE ignored

* init.cfg (trap_sigpipe_or_skip_): A new function refactored from...
* tests/misc/printf-surprise.sh: ...here.
* tests/misc/seq-epipe.sh. Likewise.
* src/tail.c (die_pipe): Ensure we exit upon sending SIGPIPE.
* tests/tail-2/pipe-f.sh: Ensure we exit even if SIGPIPE is ignored.
* NEWS: Mention the bug fix.
---
 NEWS                          |  4 ++++
 init.cfg                      |  6 ++++++
 src/tail.c                    | 14 +++++++++++---
 tests/misc/printf-surprise.sh |  4 +---
 tests/misc/seq-epipe.sh       |  4 +---
 tests/tail-2/pipe-f.sh        | 17 ++++++++++++-----
 6 files changed, 35 insertions(+), 14 deletions(-)

diff --git a/NEWS b/NEWS
index ca296b0..a6a02d8 100644
--- a/NEWS
+++ b/NEWS
@@ -27,6 +27,10 @@ GNU coreutils NEWS                                    -*- outline -*-
   'tail -f file | filter' no longer exits immediately on AIX.
   [bug introduced in coreutils-8.28]
 
+  'tail -f file | filter' no longer goes into an infinite loop
+  if filter exits and SIGPIPE is ignored.
+  [bug introduced in coreutils-8.28]
+
 ** Changes in behavior
 
   echo now always processes backslash escapes when the POSIXLY_CORRECT
diff --git a/init.cfg b/init.cfg
index d99a0e3..739ba33 100644
--- a/init.cfg
+++ b/init.cfg
@@ -610,6 +610,12 @@ mkfifo_or_skip_()
   fi
 }
 
+trap_sigpipe_or_skip_()
+{
+  (trap '' PIPE && yes | :) 2>&1 | grep -qF 'Broken pipe' ||
+    skip_ 'trapping SIGPIPE is not supported'
+}
+
 # Disable the current test if the working directory seems to have
 # the setgid bit set.
 skip_if_setgid_()
diff --git a/src/tail.c b/src/tail.c
index c63b616..b806485 100644
--- a/src/tail.c
+++ b/src/tail.c
@@ -334,6 +334,14 @@ named file in a way that accommodates renaming, removal and creation.\n\
   exit (status);
 }
 
+/* Ensure exit, either with SIGPIPE or EXIT_FAILURE status.  */
+static void ATTRIBUTE_NORETURN
+die_pipe (void)
+{
+  raise (SIGPIPE);
+  exit (EXIT_FAILURE);
+}
+
 /* If the output has gone away, then terminate
    as we would if we had written to this output.  */
 static void
@@ -349,7 +357,7 @@ check_output_alive (void)
   pfd.events = POLLERR;
 
   if (poll (&pfd, 1, 0) >= 0 && (pfd.revents & POLLERR))
-    raise (SIGPIPE);
+    die_pipe ();
 #else
   struct timeval delay;
   delay.tv_sec = delay.tv_usec = 0;
@@ -361,7 +369,7 @@ check_output_alive (void)
   /* readable event on STDOUT is equivalent to POLLERR,
      and implies an error condition on output like broken pipe.  */
   if (select (STDOUT_FILENO + 1, &rfd, NULL, NULL, &delay) == 1)
-    raise (SIGPIPE);
+    die_pipe ();
 #endif
 }
 
@@ -1659,7 +1667,7 @@ tail_forever_inotify (int wd, struct File_spec *f, size_t n_files,
              {
                /* readable event on STDOUT is equivalent to POLLERR,
                   and implies an error on output like broken pipe.  */
-               raise (SIGPIPE);
+               die_pipe ();
              }
            else
              break;
diff --git a/tests/misc/printf-surprise.sh b/tests/misc/printf-surprise.sh
index 18d48a0..4190c94 100755
--- a/tests/misc/printf-surprise.sh
+++ b/tests/misc/printf-surprise.sh
@@ -49,9 +49,7 @@ vm=$(get_min_ulimit_v_ env $prog %20f 0) \
 # triggering the printf(3) misbehavior -- which, btw, is required by ISO C99.
 
 mkfifo_or_skip_ fifo
-
-(trap '' PIPE && yes | :) 2>&1 | grep -qF 'Broken pipe' ||
-    skip_ 'trapping SIGPIPE is not supported'
+trap_sigpipe_or_skip_
 
 # Disable MALLOC_PERTURB_, to avoid triggering this bug
 # https://bugs.debian.org/481543#77
diff --git a/tests/misc/seq-epipe.sh b/tests/misc/seq-epipe.sh
index be9457e..c2a6164 100755
--- a/tests/misc/seq-epipe.sh
+++ b/tests/misc/seq-epipe.sh
@@ -18,9 +18,7 @@
 
 . "${srcdir=.}/tests/init.sh"; path_prepend_ ./src
 print_ver_ seq
-
-(trap '' PIPE && yes | :) 2>&1 | grep -qF 'Broken pipe' ||
-    skip_ 'trapping SIGPIPE is not supported'
+trap_sigpipe_or_skip_
 
 # upon EPIPE with signals ignored, 'seq' should exit with an error.
 timeout 10 sh -c \
diff --git a/tests/tail-2/pipe-f.sh b/tests/tail-2/pipe-f.sh
index 4a5b444..ae7cbaa 100755
--- a/tests/tail-2/pipe-f.sh
+++ b/tests/tail-2/pipe-f.sh
@@ -18,6 +18,7 @@
 
 . "${srcdir=.}/tests/init.sh"; path_prepend_ ./src
 print_ver_ tail
+trap_sigpipe_or_skip_
 
 # Speedup the non inotify case
 fastpoll='-s.1 --max-unchanged-stats=1'
@@ -36,11 +37,17 @@ echo bar | returns_ 1 \
 compare exp out || fail=1
 
 # This would wait indefinitely before v8.28 due to no EPIPE being
-# generated due to no data written after the first small amount
-(returns_ 124 timeout 10 tail -n2 -f $mode $fastpoll out && touch timed_out) |
- sed 2q > out2
-test -e timed_out && fail=1
-compare exp out2 || fail=1
+# generated due to no data written after the first small amount.
+# Also check tail exits if SIGPIPE is being ignored.
+for disposition in '' '-'; do
+  (trap "$disposition" PIPE;
+   returns_ 124 timeout 10 \
+    tail -n2 -f $mode $fastpoll out && touch timed_out) |
+  sed 2q > out2
+  test -e timed_out && fail=1
+  compare exp out2 || fail=1
+  rm -f timed_out
+done
 
 # This would wait indefinitely before v8.28 (until first write)
 (returns_ 1 timeout 10 tail -f $mode $fastpoll /dev/null >&-) || fail=1
-- 
2.9.3