Werner Koch writes ("Re: Bug#841143: [pkg-gnupg-maint] Bug#841143: Suspected
race in gpg1 to gpg2 conversion or agent startup"):
> You may want to read the top of gnupg/common/dotlock.c to see why we use
> this scheme. It is the only _portable_ way of doing advisory locks
> _across platforms_. FWIW, GNOME uses the same code.
Well, I'm not *sure* it's startup that's the problem. Right now I
have an instance of the dgit test suite which has hung.
As you can see in the transcripts below:
* I have four gpg processes which are stuck. I investigated one, and
it is in the startup / agent connection code. strace shows it
selecting on the agent socket which netstat shows is CONNECTED.
* The agent process is selecting only on an inotify fd. Surely it
should be selecting at least on a socket master fd.
I'm not sure I can match up all the sockets properly with this
information, but I think this is clearly a bug. That it happens to me
in the dgit test suite, but rarely to anyone else, also suggests it's
a bug in the startup logic.
There may have been a previous agent with this GNUPGHOME, but if so
that directory was deleted and recreated before any of the current
crop of gpg were started, and the corresponding agent no longer
exists.
I have already arranged to do the conversion from gpg1 format data
(which is what the test suite starts with) once. That is, I do this:
some things which may leave an agent lying around, such
as a previous run of the test suite
rm -rf .../tests/tmp
GNUPGHOME=.../tests/tmp/gnupg/gnupg gpg --list-secret
many times in parallel, things which call
GNUPGHOME=.../tests/tmp/gnupg/gnupg gpg something
This is all with 2.1.16-3.
I'm going to try working around it by serialising all my calls to gpg.
Thanks for your attention.
Regards,
Ian.
zealot:~> ps -efH | grep gpg
ian 5101 1467 0 12:20 pts/9 00:00:00 gpg
--detach-sign --armor -u 39B13D8A .git/dgit/tag-dgit.tmp
ian 5099 2755 0 12:20 pts/9 00:00:00 gpg
--detach-sign --armor -u 39B13D8A .git/dgit/tag-dgit.tmp
ian 5098 4213 0 12:20 pts/9 00:00:00 gpg
--detach-sign --armor -u 39B13D8A .git/dgit/tag-maintview.tmp
ian 5392 5285 0 12:20 pts/9 00:00:00 gpg
--detach-sign --armor -u 39B13D8A tag.tmp
ian 1961 1 0 12:20 ? 00:00:00 gpg-agent --homedir
/home/ian/things/Dgit/2dgit/tests/tmp/gnupg/gnupg --use-standard-socket --daemon
ian 5502 5436 0 12:31 pts/84 00:00:00 grep gpg
zealot:~>
root(ian)@zealot:~> strace -p5101
strace: Process 5101 attached
read(8, ^Cstrace: Process 5101 detached
<detached ...>
root(ian)@zealot:~> ll /proc/5101/fd/8
lrwx------ 1 ian ian 64 Jan 8 12:34 /proc/5101/fd/8 -> socket:[5837034]
root(ian)@zealot:~> strace -p1961
strace: Process 1961 attached
pselect6(8, [7], NULL, NULL, NULL, {[], 8}^Cstrace: Process 1961 detached
<detached ...>
root(ian)@zealot:~> ll /proc/1961/fd
total 0
dr-x------ 2 root root 0 Jan 8 12:28 ./
dr-xr-xr-x 9 ian ian 0 Jan 8 12:20 ../
lr-x------ 1 root root 64 Jan 8 12:28 0 -> /dev/null
l-wx------ 1 root root 64 Jan 8 12:28 1 -> /dev/null
l-wx------ 1 root root 64 Jan 8 12:28 2 -> /dev/null
lrwx------ 1 root root 64 Jan 8 12:28 3 -> socket:[5827012]
lrwx------ 1 root root 64 Jan 8 12:28 4 -> socket:[5827013]
lrwx------ 1 root root 64 Jan 8 12:28 5 -> socket:[5827014]
lrwx------ 1 root root 64 Jan 8 12:28 6 -> socket:[5827015]
lr-x------ 1 root root 64 Jan 8 12:28 7 -> anon_inode:inotify
lr-x------ 1 root root 64 Jan 8 12:28 9 -> /dev/urandom
root(ian)@zealot:~>
root(ian)@zealot:~> gdb /usr/bin/gpg 5101
GNU gdb (Debian 7.11.1-2+b1) 7.11.1
Copyright (C) 2016 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. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/bin/gpg...Reading symbols from
/usr/lib/debug/.build-id/29/a11dd70c57cf6c90a9927b30c7f81aa3448f72.debug...done.
done.
Attaching to program: /usr/bin/gpg, process 5101
Reading symbols from /usr/lib/x86_64-linux-gnu/libgtk3-nocsd.so.0...(no
debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libz.so.1...(no debugging symbols
found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libbz2.so.1.0...(no debugging
symbols found)...done.
Reading symbols from /usr/lib/x86_64-linux-gnu/libsqlite3.so.0...(no debugging
symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libgcrypt.so.20...(no debugging
symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libreadline.so.7...(no debugging
symbols found)...done.
Reading symbols from /usr/lib/x86_64-linux-gnu/libassuan.so.0...(no debugging
symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libgpg-error.so.0...(no debugging
symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libc.so.6...Reading symbols from
/usr/lib/debug/.build-id/29/725acf575edd8ab3451049e651dbdff55ebf33.debug...done.
done.
Reading symbols from /lib/x86_64-linux-gnu/libdl.so.2...Reading symbols from
/usr/lib/debug/.build-id/68/f719036af8966a0c853efb18b31f69a98f7537.debug...done.
done.
Reading symbols from /lib/x86_64-linux-gnu/libpthread.so.0...Reading symbols
from
/usr/lib/debug/.build-id/a4/bddfcd387c9e824fbc5000a0c6b62c1788a265.debug...done.
done.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Reading symbols from /lib/x86_64-linux-gnu/libm.so.6...Reading symbols from
/usr/lib/debug/.build-id/a0/0ff62b9ca7497ce2e747bbbe4df0aa3a18f898.debug...done.
done.
Reading symbols from /lib/x86_64-linux-gnu/libtinfo.so.5...(no debugging
symbols found)...done.
Reading symbols from /lib64/ld-linux-x86-64.so.2...Reading symbols from
/usr/lib/debug/.build-id/08/08c1bb645f921bacd138bc23d38f59fb4a9c67.debug...done.
done.
0x00007ff97af355c0 in __read_nocancel () at
../sysdeps/unix/syscall-template.S:84
84 ../sysdeps/unix/syscall-template.S: No such file or directory.
(gdb) bt
#0 0x00007ff97af355c0 in __read_nocancel () at
../sysdeps/unix/syscall-template.S:84
#1 0x00007ff97b411993 in ?? () from /usr/lib/x86_64-linux-gnu/libassuan.so.0
#2 0x00007ff97b411b49 in ?? () from /usr/lib/x86_64-linux-gnu/libassuan.so.0
#3 0x00007ff97b4110f8 in assuan_client_read_response () from
/usr/lib/x86_64-linux-gnu/libassuan.so.0
#4 0x00007ff97b411483 in ?? () from /usr/lib/x86_64-linux-gnu/libassuan.so.0
#5 0x00007ff97b416508 in ?? () from /usr/lib/x86_64-linux-gnu/libassuan.so.0
#6 0x00007ff97b4168c6 in assuan_socket_connect () from
/usr/lib/x86_64-linux-gnu/libassuan.so.0
#7 0x000056219dc9319e in start_new_gpg_agent (r_ctx=r_ctx@entry=0x56219ded8260
<agent_ctx>, errsource=errsource@entry=GPG_ERR_SOURCE_GPG,
agent_program=0x0, opt_lc_ctype=0x0, opt_lc_messages=0x0,
session_env=0x56219e036c10, autostart=1, verbose=0, debug=0, status_cb=0x0,
status_cb_arg=0x0) at ../../common/asshelp.c:348
#8 0x000056219dc6253f in start_agent (for_card=for_card@entry=0, ctrl=0x0) at
../../g10/call-agent.c:234
#9 0x000056219dc6400e in agent_probe_any_secret_key (ctrl=ctrl@entry=0x0,
keyblock=0x56219e043c90) at ../../g10/call-agent.c:1459
#10 0x000056219dc12081 in lookup (ctx=ctx@entry=0x56219e03f3e0,
ret_keyblock=ret_keyblock@entry=0x7ffd6fe3e688,
ret_found_key=ret_found_key@entry=0x7ffd6fe3e690,
want_secret=want_secret@entry=1) at ../../g10/getkey.c:3701
#11 0x000056219dc132ad in key_byname (retctx=retctx@entry=0x0,
namelist=<optimized out>, pk=pk@entry=0x56219e03f320,
want_secret=want_secret@entry=1,
include_unusable=1, ret_kb=0x7ffd6fe3e688, ret_kb@entry=0x0, ret_kdbhd=0x0)
at ../../g10/getkey.c:1120
#12 0x000056219dc13529 in getkey_byname (ctrl=ctrl@entry=0x56219e03f1f0,
retctx=retctx@entry=0x0, pk=pk@entry=0x56219e03f320,
name=name@entry=0x56219e036ccc "39B13D8A", want_secret=want_secret@entry=1,
ret_keyblock=ret_keyblock@entry=0x0) at ../../g10/getkey.c:2134
#13 0x000056219dc3c887 in build_sk_list (ctrl=ctrl@entry=0x56219e03f1f0,
locusr=<optimized out>, locusr@entry=0x56219e036cc0,
ret_sk_list=ret_sk_list@entry=0x7ffd6fe3e808, use=use@entry=1) at
../../g10/skclist.c:192
#14 0x000056219dc435d3 in sign_file (ctrl=0x56219e03f1f0,
filenames=0x56219e03f270, detached=1, locusr=0x56219e036cc0, encryptflag=0,
remusr=0x0,
outfile=0x0) at ../../g10/sign.c:802
#15 0x000056219dbfc10c in main (argc=<optimized out>, argv=<optimized out>) at
../../g10/gpg.c:4050
(gdb)
root(ian)@zealot:~> gdb /usr/bin/gpg-agent 1961
GNU gdb (Debian 7.11.1-2+b1) 7.11.1
Copyright (C) 2016 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. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/bin/gpg-agent...Reading symbols from
/usr/lib/debug/.build-id/c3/105921095789d42687491a3f88da6b6ca11fac.debug...done.
done.
Attaching to program: /usr/bin/gpg-agent, process 1961
Reading symbols from /usr/lib/x86_64-linux-gnu/libgtk3-nocsd.so.0...(no
debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libgcrypt.so.20...(no debugging
symbols found)...done.
Reading symbols from /usr/lib/x86_64-linux-gnu/libassuan.so.0...(no debugging
symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libgpg-error.so.0...(no debugging
symbols found)...done.
Reading symbols from /usr/lib/x86_64-linux-gnu/libnpth.so.0...(no debugging
symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libpthread.so.0...Reading symbols
from
/usr/lib/debug/.build-id/a4/bddfcd387c9e824fbc5000a0c6b62c1788a265.debug...done.
done.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Reading symbols from /lib/x86_64-linux-gnu/libc.so.6...Reading symbols from
/usr/lib/debug/.build-id/29/725acf575edd8ab3451049e651dbdff55ebf33.debug...done.
done.
Reading symbols from /lib/x86_64-linux-gnu/libdl.so.2...Reading symbols from
/usr/lib/debug/.build-id/68/f719036af8966a0c853efb18b31f69a98f7537.debug...done.
done.
Reading symbols from /lib64/ld-linux-x86-64.so.2...Reading symbols from
/usr/lib/debug/.build-id/08/08c1bb645f921bacd138bc23d38f59fb4a9c67.debug...done.
done.
0x00007f071fd5438c in __pselect (nfds=8, readfds=0x7fff243a2720, writefds=0x0,
exceptfds=0x0, timeout=<optimized out>, sigmask=<optimized out>)
at ../sysdeps/unix/sysv/linux/pselect.c:69
69 ../sysdeps/unix/sysv/linux/pselect.c: No such file or directory.
(gdb) bt
#0 0x00007f071fd5438c in __pselect (nfds=8, readfds=0x7fff243a2720,
writefds=0x0, exceptfds=0x0, timeout=<optimized out>, sigmask=<optimized out>)
at ../sysdeps/unix/sysv/linux/pselect.c:69
#1 0x00007f072023037c in npth_pselect () from
/usr/lib/x86_64-linux-gnu/libnpth.so.0
#2 0x00005584bb449546 in handle_connections (listen_fd=<optimized out>,
listen_fd_extra=<optimized out>, listen_fd_browser=<optimized out>,
listen_fd_ssh=<optimized out>) at ../../agent/gpg-agent.c:2937
#3 0x00005584bb44608e in main (argc=<optimized out>, argv=<optimized out>) at
../../agent/gpg-agent.c:1714
(gdb)
root(ian)@zealot:~> netstat -panex | grep gpg
unix 2 [ ACC ] STREAM LISTENING 5827012 1961/gpg-agent
/home/ian/things/Dgit/2dgit/tests/tmp/gnupg/gnupg/S.gpg-agent
unix 2 [ ACC ] STREAM LISTENING 5827013 1961/gpg-agent
/home/ian/things/Dgit/2dgit/tests/tmp/gnupg/gnupg/S.gpg-agent.extra
unix 2 [ ACC ] STREAM LISTENING 5827014 1961/gpg-agent
/home/ian/things/Dgit/2dgit/tests/tmp/gnupg/gnupg/S.gpg-agent.browser
unix 2 [ ACC ] STREAM LISTENING 5827015 1961/gpg-agent
/home/ian/things/Dgit/2dgit/tests/tmp/gnupg/gnupg/S.gpg-agent.ssh
unix 3 [ ] STREAM CONNECTING 0 -
/home/ian/things/Dgit/2dgit/tests/tmp/gnupg/gnupg/S.gpg-agent
unix 3 [ ] STREAM CONNECTING 0 -
/home/ian/things/Dgit/2dgit/tests/tmp/gnupg/gnupg/S.gpg-agent
unix 3 [ ] STREAM CONNECTING 0 -
/home/ian/things/Dgit/2dgit/tests/tmp/gnupg/gnupg/S.gpg-agent
unix 3 [ ] STREAM CONNECTED 5837032 5098/gpg
unix 3 [ ] STREAM CONNECTING 0 -
/home/ian/things/Dgit/2dgit/tests/tmp/gnupg/gnupg/S.gpg-agent
unix 3 [ ] STREAM CONNECTED 5835246 5099/gpg
unix 3 [ ] STREAM CONNECTED 5835335 5392/gpg
unix 3 [ ] STREAM CONNECTED 5837034 5101/gpg
root(ian)@zealot:~>
--
Ian Jackson <ijack...@chiark.greenend.org.uk> These opinions are my own.
If I emailed you from an address @fyvzl.net or @evade.org.uk, that is
a private address which bypasses my fierce spamfilter.
