GNU bug report logs - #23031
reporting write errors and handling SIGPIPE

Previous Next

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 23031 in the body.
You can then email your comments to 23031 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Assaf Gordon <assafgordon <at> gmail.com>
To: bug-grep <at> gnu.org
Subject: reporting write errors and handling SIGPIPE
Date: Wed, 16 Mar 2016 12:14:32 -0400

[Message part 1 (text/plain, inline)]

Hello,

First,
Attached is a patch that adds errno information to 'write error' messages, e.g.:
      $ grep [...] > /dev/full
      grep: write error: No space left on device
I hope it is self-explanatory enough (comments and suggestions are welcomed).


Second,
On one gnu/linux server I'm experiencing a strange behavior (or at least, not understandable to me):
grep does not immediately terminates on SIGPIPE, and instead exits and prints "write error" (for EPIPE).
which is partially why I wrote the above patch, to try understand what's going on.

An example, reproducible on my machine (running on real hardware), though hard to reproduce inside a VM and on other servers:
   seq 100000 > in
   for i in $(seq 100) ; do
      ./src/grep -s --line-buffered -v '^$' < in | head -n1 > /dev/null ;
   done
for some of the runs  (out of 100) I get an error "./src/grep: write error: Broken pipe" .

attached are strace/ltrace logs of such cases. the key lines:

When grep is killed by SIGPIPE:

 == strace ==
   write(1, "1\n", 2)                      = 2
   write(1, "2\n", 2)                      = -1 EPIPE (Broken pipe)
   --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=2960, si_uid=1004} ---
   +++ killed by SIGPIPE +++

 == ltrace ==
   fwrite_unlocked("1\n2\n3\n4\n5\n6\n7\n8\n9\n10\n11\n12\n13\n14"..., 1, 2, 0x7efc5dab9400)     = 2
    __errno_location()                                                                            = 0x7efc5dee46a0
   fflush_unlocked(0x7efc5dab9400, 0x18da000, 10, 4096)                                          = 0
   memchr("2\n3\n4\n5\n6\n7\n8\n9\n10\n11\n12\n13\n14\n1"..., '\n', 32766)                       = 0x18da003
   fwrite_unlocked("2\n3\n4\n5\n6\n7\n8\n9\n10\n11\n12\n13\n14\n1"..., 1, 2, 0x7efc5dab9400)     = 2
   __errno_location()                                                                            = 0x7efc5dee46a0
   fflush_unlocked(0x7efc5dab9400, 0x18da004, 0, 2610 <no return ...>
   --- SIGPIPE (Broken pipe) ---
   +++ killed by SIGPIPE +++


When grep is not killed by SIGPIPE:

 == strace ==
   write(1, "1\n", 2)                      = 2
   write(1, "2\n", 2)                      = -1 EPIPE (Broken pipe)
   --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=2893, si_uid=1004} ---
   write(2, "./src/grep: ", 12)            = 12
   write(2, "write error", 11)             = 11
   write(2, ": Broken pipe", 13)           = 13
   write(2, "\n", 1)                       = 1
   exit_group(2)                           = ?

 == ltrace ==
   fwrite_unlocked("1\n2\n3\n4\n5\n6\n7\n8\n9\n10\n11\n12\n13\n14"..., 1, 2, 0x7f9e62f50400)           = 2
   __errno_location()                                                                                  = 0x7f9e6337b6a0
   fflush_unlocked(0x7f9e62f50400, 0x25af000, 10, 4096)                                                = 0
   memchr("2\n3\n4\n5\n6\n7\n8\n9\n10\n11\n12\n13\n14\n1"..., '\n', 32766)                             = 0x25af003
   fwrite_unlocked("2\n3\n4\n5\n6\n7\n8\n9\n10\n11\n12\n13\n14\n1"..., 1, 2, 0x7f9e62f50400)           = 2
   __errno_location()                                                                                  = 0x7f9e6337b6a0
   fflush_unlocked(0x7f9e62f50400, 0x25af004, 0, 2610 <no return ...>
   --- SIGPIPE (Broken pipe) ---
   <... fflush_unlocked resumed> )                                                                     = 0xffffffff
   __errno_location()                                                                                  = 0x7f9e6337b6a0
   error(2, 32, 0x41caa0, 32 <no return ...>



The server is:
  $ uname -a
  Linux x 3.13.0-77-generic #121-Ubuntu SMP Wed Jan 20 10:50:42 UTC 2016 x86_64 GNU/Linux

  $ gcc -v
  Using built-in specs.
  COLLECT_GCC=gcc
  COLLECT_LTO_WRAPPER=/usr/local/libexec/gcc/x86_64-unknown-linux-gnu/5.2.0/lto-wrapper
  Target: x86_64-unknown-linux-gnu
  Configured with: ../gcc-5.2.0/configure --enable-languages=c,c++
  Thread model: posix
  gcc version 5.2.0 (GCC)


Thanks for any feedback,
regards,
 - assaf

[grep-write-error-msg.patch.xz (application/x-xz, attachment)]

[grep-SIGPIPE-killed.ltrace.log.xz (application/x-xz, attachment)]

[grep-SIGPIPE-killed.strace.log.xz (application/x-xz, attachment)]

[grep-SIGPIPE-not-killed.ltrace.log.xz (application/x-xz, attachment)]

[grep-SIGPIPE-not-killed.strace.log.xz (application/x-xz, attachment)]

Message #8 received at 23031 <at> debbugs.gnu.org (full text, mbox):

From: Paul Eggert <eggert <at> cs.ucla.edu>
To: Assaf Gordon <assafgordon <at> gmail.com>, 23031 <at> debbugs.gnu.org
Subject: Re: bug#23031: reporting write errors and handling SIGPIPE
Date: Wed, 16 Mar 2016 14:23:15 -0700

On 03/16/2016 09:14 AM, Assaf Gordon wrote:
> write(1, "2\n", 2)                      = -1 EPIPE (Broken pipe)
>    --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=2893, 
> si_uid=1004} ---
>    write(2, "./src/grep: ", 12)            = 12 

Although this looks weird and it's not what I would expect, it's not a 
POSIX violation as far as I can see. The system is required to send a 
SIGPIPE signal in this case, but it is not required to deliver the 
SIGPIPE signal before 'write' returns with errno == EPIPE. Arguably it's 
a bug in GNU/Linux anyway.

Your patch is a step in the right direction, but needs a bit of cleanup; 
I plan to look into it more carefully later. Thanks!

Message #11 received at 23031 <at> debbugs.gnu.org (full text, mbox):

From: Paul Eggert <eggert <at> cs.ucla.edu>
To: Assaf Gordon <assafgordon <at> gmail.com>, 23031 <at> debbugs.gnu.org
Subject: Re: bug#23031: reporting write errors and handling SIGPIPE
Date: Thu, 17 Mar 2016 11:49:08 -0700

[Message part 1 (text/plain, inline)]

On 03/16/2016 09:14 AM, Assaf Gordon wrote:
> Attached is a patch that adds errno information to 'write error' messages

Thanks, I installed the attached somewhat-tweaked version of that. Among 
other things I renamed the new static functions to avoid confusion with 
existing "safer" functions.

This doesn't address the SIGPIPE mystery so I'll leave the bug report 
open, but my guess is that this part isn't really a grep bug.

[0001-grep-use-errno-consistently-in-write-diagnostics.patch (application/x-patch, attachment)]

Message #16 received at 23031-done <at> debbugs.gnu.org (full text, mbox):

From: Assaf Gordon <assafgordon <at> gmail.com>
To: Paul Eggert <eggert <at> cs.ucla.edu>, 23031-done <at> debbugs.gnu.org
Subject: Re: bug#23031: reporting write errors and handling SIGPIPE
Date: Fri, 18 Mar 2016 13:30:23 -0400

Hello,

On 03/17/2016 02:49 PM, Paul Eggert wrote:
> On 03/16/2016 09:14 AM, Assaf Gordon wrote:
>> Attached is a patch that adds errno information to 'write error' messages
>
> Thanks, I installed the attached somewhat-tweaked version of that. Among other things I renamed the new static functions to avoid confusion with existing "safer" functions.
>
> This doesn't address the SIGPIPE mystery so I'll leave the bug report open, but my guess is that this part isn't really a grep bug.

Thanks for the inclusion and the additional information.
This is indeed not a bug in grep (and thus closed).

I found that on my weird setup, programs start with SIGPIPE set to SIG_IGN by default (not sure how I got myself into such situation).

regards,
 - assaf

Message #19 received at 23031 <at> debbugs.gnu.org (full text, mbox):

From: Eric Blake <eblake <at> redhat.com>
To: 23031 <at> debbugs.gnu.org, assafgordon <at> gmail.com
Subject: Re: bug#23031: reporting write errors and handling SIGPIPE
Date: Fri, 18 Mar 2016 12:18:05 -0600

[Message part 1 (text/plain, inline)]

On 03/18/2016 11:30 AM, Assaf Gordon wrote:

> I found that on my weird setup, programs start with SIGPIPE set to
> SIG_IGN by default (not sure how I got myself into such situation).

There have been various automated robot testsuite runners (such as
Jenkins at one point in the past, although I don't know if it is still
the case) that do the equivalent of 'trap - PIPE' in their master shell;
then the rules of POSIX say that 'sh' can't do anything to undo that
setting (it's very annoying - inheriting ignored SIGPIPE is impossible
to undo in straight shell, and requires an intermediary C program).

-- 
Eric Blake   eblake redhat com    +1-919-301-3266
Libvirt virtualization library http://libvirt.org

[signature.asc (application/pgp-signature, attachment)]

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.