From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from localhost (localhost [127.0.0.1]) by arlo.cworth.org (Postfix) with ESMTP id A5F446DE0944 for ; Tue, 21 Jan 2020 02:47:43 -0800 (PST) X-Virus-Scanned: Debian amavisd-new at cworth.org X-Spam-Flag: NO X-Spam-Score: -2.498 X-Spam-Level: X-Spam-Status: No, score=-2.498 tagged_above=-999 required=5 tests=[AWL=-0.446, HEADER_FROM_DIFFERENT_DOMAINS=0.249, RCVD_IN_DNSWL_MED=-2.3, SPF_PASS=-0.001] autolearn=disabled Received: from arlo.cworth.org ([127.0.0.1]) by localhost (arlo.cworth.org [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id fCQAh0YBgDGu for ; Tue, 21 Jan 2020 02:47:39 -0800 (PST) Received: from esa2.mentor.iphmx.com (esa2.mentor.iphmx.com [68.232.141.98]) by arlo.cworth.org (Postfix) with ESMTPS id 292356DE0203 for ; Tue, 21 Jan 2020 02:47:39 -0800 (PST) IronPort-SDR: o5GLmiRUNrugJiv5qljJhBX3oTKPp8n0MIc8jiaWzANUIoQtGWTHsRbnbRiAL2TB61mDR/NA6s Rtva2LeMq3vNhjqH1PBVSVW4D/Q1XswZHFMeBgTgWU+RMMWierjicwnPZSX0zS7Nmr8Etnz85v d/334ZE8kRF4yd7z1fSq6RggNk8kgmTBklPz+3lBb320WTTMWv4QFr/ryiTrim14Y0AG0iU1l7 cmEZ6BU05RBNw3/MwO6wHAxAAXujhXQbOqaG7IPvxWT5VQedvDJzHIxXotJS6R3HIQzvfcaJG7 fzo= X-IronPort-AV: E=Sophos;i="5.70,345,1574150400"; d="asc'?scan'208";a="44981295" Received: from orw-gwy-01-in.mentorg.com ([192.94.38.165]) by esa2.mentor.iphmx.com with ESMTP; 21 Jan 2020 02:47:35 -0800 IronPort-SDR: gSLivuOBjSXAj0D3C5ROCBdMVBlRxGkvPlFtfdzXbFBczFe34xOTTmtdtw4YlEx0wfjpVGIgok 6TajgrOVJoNw== From: Thomas Schwinge To: Subject: Re: notmuch vs. SIGPIPE In-Reply-To: <87ftg93gcc.fsf@euler.schwinge.homeip.net> References: <87h80qgx5b.fsf@euler.schwinge.homeip.net> <87ftg93gcc.fsf@euler.schwinge.homeip.net> User-Agent: Notmuch/0.29.1+93~g67ed7df (https://notmuchmail.org) Emacs/26.1 (x86_64-pc-linux-gnu) Date: Tue, 21 Jan 2020 11:47:19 +0100 Message-ID: <87eevtgk7c.fsf@euler.schwinge.homeip.net> MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" X-BeenThere: notmuch@notmuchmail.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: "Use and development of the notmuch mail system." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 21 Jan 2020 10:47:43 -0000 --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Hi! On 2020-01-20T23:36:51+0100, I wrote: > On 2020-01-20T12:55:28+0100, I wrote: >> While looking a bit into the item raised in >> id:87muamgspy.fsf@euler.schwinge.homeip.net I noticed the following >> (mis?)behavior by notmuch. >> >> To set the stage: >> >> $ yes | head -n 1 >> y >> $ echo "${PIPESTATUS[@]}" >> 141 0 >> >> As expected, the 'yes' process exits with SIGPIPE right after the 'head' >> process terminated. > > See also , for example. > >> However: >> >> $ notmuch search \* | head -n 1 & sleep 22; jobs; ps -f >> [1] 622009 >> thread:0000000000032bb2 the future [1/1] Jenna Moss; Steve Burbon,= Washington (hurd list spam) >> [1]+ Running notmuch search \* | head -n 1 & >> UID PID PPID C STIME TTY TIME CMD >> thomas 621851 4297 0 12:38 pts/38 00:00:00 /bin/bash >> thomas 622008 621851 99 12:48 pts/38 00:00:22 /home/thomas/com= mand/notmuch.real search \* >> thomas 622013 621851 0 12:48 pts/38 00:00:00 ps -f >> >> Even after its "pipe-consumer" 'head' process has terminated, the >> 'notmuch' process still keeps running, and running, and running... > So, libgpgme via libgmime initialization is doing something with signals. > Here, 'sig=3D13' is SIGPIPE > Breakpoint 1, __GI___sigaction (sig=3D13, act=3D0x7fffffffd4e0, oact= =3D0x0) at ../nptl/sigaction.c:24 > (gdb) print *act > $3 =3D {__sigaction_handler =3D {sa_handler =3D 0x1, sa_sigaction =3D= 0x1}, sa_mask =3D {__val =3D {0 }}, sa_flags =3D 0, sa_r= estorer =3D 0x0} > > A '0x1' '__sigaction_handler' means 'SIG_IGN', ignore any such signals. > This is unexpected (to me, at least), not what I'd expect with notmuch? > > According to a (very quick) check/survey, this has apparently been the > case "forever", and is documented on > , > together with some rationale. Aha, aha, OK, I see. > > So, assuming we want to keep it that way (given the gpgme rationale), is > the problem then that we fail to handle appropriately in notmuch any > EPIPE that we may be getting from 'write' etc.? This remains to be > explored another day. Indeed. Using a FIFO to simulate a pipe: $ mkfifo f $ head -n 1 < f & [1] 775394 (This will trigger SIGPIPE/EPIPE after one line.) $ gdb -q notmuch Reading symbols from notmuch... (gdb) break write Breakpoint 1 at 0xd420 (gdb) run dump > f Starting program: [...]/notmuch dump > f [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.= 1". =20=20=20=20 Breakpoint 1, __GI___libc_write (fd=3D8, buf=3D0x555555683710, nbytes= =3D8192) at ../sysdeps/unix/sysv/linux/write.c:26 26 ../sysdeps/unix/sysv/linux/write.c: No such file or directory. (gdb) bt #0 0x00007ffff789a8f0 in __GI___libc_write (fd=3D8, buf=3D0x5555556837= 10, nbytes=3D8192) at ../sysdeps/unix/sysv/linux/write.c:26 #1 0x00007ffff7d8ff99 in gz_comp (state=3Dstate@entry=3D0x555555683620= , flush=3D0) at gzwrite.c:89 #2 0x00007ffff7d909ff in gzvprintf (file=3D0x555555683620, format=3D, va=3Dva@entry=3D0x7fffffffd190) at gzwrite.c:442 #3 0x00007ffff7d90ad4 in gzprintf (file=3Dfile@entry=3D0x555555683620,= format=3Dformat@entry=3D0x55555558f54e " -- %s\n") at gzwrite.c:457 #4 0x000055555556964e in dump_tags_message (size_p=3D0x7fffffffd2d0, b= uffer_p=3D0x7fffffffd2c8, output=3D0x555555683620, output_format=3D1, messa= ge=3D0x5555556884e0, ctx=3D0x5555555d01b0) at notmuch-dump.c:203 #5 0x000055555556964e in database_dump_file (include=3D= , output_format=3D1, query_str=3D, output=3D0x555555683620, = notmuch=3D0x5555555d01b0) at notmuch-dump.c:254 #6 0x000055555556964e in notmuch_database_dump (notmuch=3D0x5555555d01= b0, output_file_name=3D0x0, query_str=3D, output_format=3DDU= MP_FORMAT_BATCH_TAG, include=3D, gzip_output=3D) at notmuch-dump.c:314 #7 0x0000555555569e4b in notmuch_dump_command (config=3D, argc=3D, argv=3D0x7fffffffd860) at notmuch-dump.c:413 #8 0x0000555555565426 in main (argc=3D2, argv=3D0x7fffffffd858) at not= much.c:505 This is the libz 'printf' pass-through code via 'notmuch dump'. (gdb) finish Run till exit from #0 __GI___libc_write (fd=3D8, buf=3D0x555555683710,= nbytes=3D8192) at ../sysdeps/unix/sysv/linux/write.c:26 #notmuch-dump batch-tag:3 config,properties,tags First line got printed. gz_comp (state=3Dstate@entry=3D0x555555683620, flush=3D0) at gzwrite.c:= 90 90 gzwrite.c: No such file or directory. Value returned is $1 =3D 8192 Supposedly 8192 bytes have been written, which seems a bit dubious, but I have not studies the fine details of how FIFO buffering vs. SIGPIPE/EPIPE work -- presumably indeed 8192 bytes were written into the FIFO buffer, but then only line read, then the FIFO/buffer closed, so the other bytes lost, and then only on the next 'write', we get... (gdb) c Continuing. =20=20=20=20 Breakpoint 1, __GI___libc_write (fd=3D8, buf=3D0x555555683710, nbytes= =3D8192) at ../sysdeps/unix/sysv/linux/write.c:26 26 ../sysdeps/unix/sysv/linux/write.c: No such file or directory. (gdb) finish Run till exit from #0 __GI___libc_write (fd=3D8, buf=3D0x555555683710,= nbytes=3D8192) at ../sysdeps/unix/sysv/linux/write.c:26 =20=20=20=20 Program received signal SIGPIPE, Broken pipe. ... the expected SIGPIPE (though, ignored thanks to gpgme initialization), and... 0x00007ffff789a904 in __GI___libc_write (fd=3D8, buf=3D0x555555683710, = nbytes=3D8192) at ../sysdeps/unix/sysv/linux/write.c:26 26 in ../sysdeps/unix/sysv/linux/write.c (gdb) finish Run till exit from #0 0x00007ffff789a904 in __GI___libc_write (fd=3D8,= buf=3D0x555555683710, nbytes=3D8192) at ../sysdeps/unix/sysv/linux/write.c= :26 gz_comp (state=3Dstate@entry=3D0x555555683620, flush=3D0) at gzwrite.c:= 90 90 gzwrite.c: No such file or directory. Value returned is $2 =3D -1 ... the 'write' fails... (gdb) print errno $3 =3D 32 ... with EPIPE... (gdb) finish Run till exit from #0 gz_comp (state=3Dstate@entry=3D0x555555683620, f= lush=3D0) at gzwrite.c:90 0x00007ffff7d909ff in gzvprintf (file=3D0x555555683620, format=3D, va=3Dva@entry=3D0x7fffffffd190) at gzwrite.c:442 442 in gzwrite.c Value returned is $4 =3D -1 ..., which gets propagated up... (gdb) finish Run till exit from #0 0x00007ffff7d909ff in gzvprintf (file=3D0x555555= 683620, format=3D, va=3Dva@entry=3D0x7fffffffd190) at gzwrit= e.c:442 gzprintf (file=3Dfile@entry=3D0x555555683620, format=3Dformat@entry=3D0= x55555558f54e " -- %s\n") at gzwrite.c:459 459 in gzwrite.c Value returned is $5 =3D -1 ..., and propagated up... (gdb) finish Run till exit from #0 gzprintf (file=3Dfile@entry=3D0x555555683620, fo= rmat=3Dformat@entry=3D0x55555558f54e " -- %s\n") at gzwrite.c:459 0x000055555556964e in dump_tags_message (size_p=3D, buff= er_p=3D, output=3D, output_format=3D, message=3D, ctx=3D) at notmuch-dump.c= :203 203 gzprintf (output, " -- %s\n", *buffer_p); Value returned is $6 =3D -1 (gdb) print errno=20=20 $7 =3D 32 ..., and propagated up, but ignored here. :-( (gdb) list 198 buffer_p, size_p)) { 199 fprintf (stderr, "Error quoting message id %s: %s\n= ", 200 message_id, strerror (errno)); 201 return EXIT_FAILURE; 202 } 203 gzprintf (output, " -- %s\n", *buffer_p); 204 } 205 return EXIT_SUCCESS; 206 } 207 Indeed there is a lot of code in 'notmuch-dump.c' that doesn't check return values for 'printf'-like function calls. Unrelated to the task that triggered me to look into this, it's of course bad that we don't handle such error returns. So, do we have to fix up all these individually (can GCC's '-Wunused-result', 'warn_unused_result' function attribute help?), or switch to a programming language/framework that provides a little bit more convenience regarding such things? Can C++ do it? ;-P Same story for 'notmuch search': $ mkfifo f $ head -n 1 < f & [1] 775782 $ gdb -q notmuch Reading symbols from notmuch... (gdb) break write Breakpoint 1 at 0xd420 (gdb) run search \* > f Starting program: [...]/notmuch search \* > f [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.= 1". =20=20=20=20 Breakpoint 1, __GI___libc_write (fd=3D1, buf=3D0x555555629a80, nbytes= =3D4096) at ../sysdeps/unix/sysv/linux/write.c:26 26 ../sysdeps/unix/sysv/linux/write.c: No such file or directory. (gdb) bt #0 0x00007ffff789a8f0 in __GI___libc_write (fd=3D1, buf=3D0x555555629a= 80, nbytes=3D4096) at ../sysdeps/unix/sysv/linux/write.c:26 #1 0x00007ffff782cc85 in _IO_new_file_write (f=3D0x7ffff7969760 <_IO_2= _1_stdout_>, data=3D0x555555629a80, n=3D4096) at fileops.c:1183 #2 0x00007ffff782c016 in new_do_write (fp=3D0x7ffff7969760 <_IO_2_1_stdout_>, data=3D0x555555629a80 "thre= ad:", '0' , "32bb2 the future [1/1] Jenna Moss; Steve B= urbon, Washington (hurd list spam)\nthread:", '0' , "4105= a the future [1/1] \346\257\217\345\244\251\344\273\205\061\060\345\205\2= 03; \344\273\205\062\071\070\345\205\203,\346\234\200\346\226\260\061\061\0= 62\345\261\212 2012\347\247\213\345\255\243\345\271\277\344\272\244\344\274= \232\344\271"..., to_do=3Dto_do@entry=3D4096) at libioP.h:904 #3 0x00007ffff782dd99 in _IO_new_do_write (to_do=3D4096, data=3D, fp=3D) at fileops.c:430 #4 0x00007ffff782dd99 in _IO_new_do_write (fp=3D, data= =3D, to_do=3D4096) at fileops.c:430 #5 0x00007ffff782d30e in _IO_new_file_xsputn (n=3D12, data=3D, f=3D) at libioP.h:904 #6 0x00007ffff782d30e in _IO_new_file_xsputn (f=3D0x7ffff7969760 <_IO_= 2_1_stdout_>, data=3D, n=3D12) at fileops.c:1204 #7 0x00007ffff7817346 in __vfprintf_internal (s=3D0x7ffff7969760 <_IO_= 2_1_stdout_>, format=3Dformat@entry=3D0x555555590b89 "[%d/%d] %s; %s (", ap= =3Dap@entry=3D0x7fffffffd0c0, mode_flags=3Dmode_flags@entry=3D0) at ../libi= o/libioP.h:904 #8 0x00007ffff7803beb in __printf (format=3Dformat@entry=3D0x555555590= b89 "[%d/%d] %s; %s (") at printf.c:33 #9 0x0000555555570b19 in do_search_threads (ctx=3D0x5555555a3160 ) at notmuch-search.c:182 #10 0x0000555555570b19 in notmuch_search_command (config=3D, argc=3D, argv=3D) at notmuch-search.c:851 #11 0x0000555555565426 in main (argc=3D3, argv=3D0x7fffffffd848) at not= much.c:505 (gdb) finish Run till exit from #0 __GI___libc_write (fd=3D1, buf=3D0x555555629a80,= nbytes=3D4096) at ../sysdeps/unix/sysv/linux/write.c:26 thread:0000000000032bb2 the future [1/1] Jenna Moss; Steve Burbon, Wa= shington (hurd list spam) _IO_new_file_write (f=3D0x7ffff7969760 <_IO_2_1_stdout_>, data=3D0x5555= 55629a80, n=3D4096) at fileops.c:1189 1189 fileops.c: No such file or directory. Value returned is $1 =3D 4096 (gdb) c Continuing. =20=20=20=20 Breakpoint 1, __GI___libc_write (fd=3D1, buf=3D0x555555629a80, nbytes= =3D4096) at ../sysdeps/unix/sysv/linux/write.c:26 26 ../sysdeps/unix/sysv/linux/write.c: No such file or directory. (gdb) finish Run till exit from #0 __GI___libc_write (fd=3D1, buf=3D0x555555629a80,= nbytes=3D4096) at ../sysdeps/unix/sysv/linux/write.c:26 =20=20=20=20 Program received signal SIGPIPE, Broken pipe. 0x00007ffff789a904 in __GI___libc_write (fd=3D1, buf=3D0x555555629a80, = nbytes=3D4096) at ../sysdeps/unix/sysv/linux/write.c:26 26 in ../sysdeps/unix/sysv/linux/write.c (gdb) finish Run till exit from #0 0x00007ffff789a904 in __GI___libc_write (fd=3D1,= buf=3D0x555555629a80, nbytes=3D4096) at ../sysdeps/unix/sysv/linux/write.c= :26 _IO_new_file_write (f=3D0x7ffff7969760 <_IO_2_1_stdout_>, data=3D0x5555= 55629a80, n=3D4096) at fileops.c:1189 1189 fileops.c: No such file or directory. Value returned is $2 =3D -1 (gdb) print errno $3 =3D 32 ['finish' a few frames] (gdb) finish Run till exit from #0 __printf (format=3Dformat@entry=3D0x555555590b89= "[%d/%d] %s; %s (") at printf.c:36 0x0000555555570b19 in do_search_threads (ctx=3D0x5555555a3160 ) at notmuch-search.c:182 182 printf ("[%d/%d] %s; %s (", Value returned is $7 =3D -1 (gdb) print errno $8 =3D 32 (gdb) list 177 /* Special case for the text formatter */ 178 printf ("thread:%s %12s ", 179 thread_id, 180 relative_date); 181 if (total =3D=3D files) 182 printf ("[%d/%d] %s; %s (", 183 matched, 184 total, 185 sanitize_string (ctx_quote, authors= ), 186 sanitize_string (ctx_quote, subject= )); Gr=C3=BC=C3=9Fe Thomas --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQGzBAEBCgAdFiEEU9WEfWKGQazCmycCAKI7+41Q4XkFAl4m1rgACgkQAKI7+41Q 4XmsHgv/YkUg90ksdTqhPu1+HJg5pQNYpsoAzPOqZDskYzg0S2rnnypsOm5dW9MQ K4AIf9o5qE/qysPfoFvXUI63hVXUfVTsm+JWM81W9V7k8qJxy6pOz14A2Yzdwa/8 fpBr1kO/xZ7V2HBGXCIC2M2Dzt54JebTOS1fgbc8vQbDCZFV6VvjoQOuWj28QI0A JKcZwD9ng6UjVXbpV7jjCf9t+uoaO4ReMLlnuKST6EyEgfQk8m3DXU1KA8CFyZQp vnM62Dx/tXA4twK9VSNKUKwGSAGvX8HkJUkciqXrnobWk4oHWVegRmhIuZJZyDfM VhhsbERCTyw9J26EP+UOviDUei4mD96ddIbOp84XVQL+79xn/4GMuN+j3ddIO9Ij fcOJVeylt5vrVUqljVoL3kQhl1X5N4CNVtAM1eReDVlWnuTANT8hBHnK45iBguuA Y9Uo5v+8EuxP1t46VodCykdYVRYeoHRncJDylZn8yrwDg5oP8AsZ6A+gK18FmfNl gwRVHPO1 =1JpL -----END PGP SIGNATURE----- --=-=-=--