Bug#868550: still some remaining agent startup race (probability 10^-3 ?)

[Ian Jackson]

Package: gnupg2
Version: 2.1.18-6

I just had an invocation of the dgit test suite fail in one of the
tests because this happened:
gpg: can't connect to the agent: IPC connect call failed

Unfortunately the failure is nonreproducible. gpg didn't quote the
errno value. A longer log excerpt is below. (The W: messages from
apt about apt.conf.d/ are expected and normal.)

I haven't calculated the failure probability exactly, but this failure
occurred after about 10 test runs each consisting of 70 individual
test cases, most of which contains many (at a guess, 10?) gnupg
invocations (which may or may not share agent startup). So probably
between 1/100 and 1/50000, say.

(The dgit commit was 242ba73109ae30e7d8849b01f0c668b87d4f4d63; the
environment was stretch, last updated a few days ago.)

Thanks for your attention.

Regards,
Ian.

+ export APT_CONFIG=/home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/ds-etc-apt/conf
+ APT_CONFIG=/home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/ds-etc-apt/conf
+ gpg --export Hannibal
gpg: WARNING: unsafe permissions on homedir '/home/ian/things/Dgit/2dgit/tests/tmp/gnupg/gnupg'
+ fakeroot apt-key add
W: Unable to read /home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
W: Unable to read /home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
W: Unable to read /home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
W: Unable to read /home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
W: Unable to read /home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
W: Unable to read /home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
W: Unable to read /home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
Warning: apt-key output should not be parsed (stdout is not a terminal)
W: Unable to read /home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
gpg: can't connect to the agent: IPC connect call failed
+ test 2 = 0
+ t-report-failure
+ set +x
TEST FAILED
cwd: /home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless
funcs: t-report-failure t-reprepro-cfg main
lines: 1 55 0
files: tests/lib /home/ian/things/Dgit/2dgit/tests/lib-reprepro tests/tests/downstream-gitless


--
Ian Jackson <ijac...@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.

[Ian Jackson]

Ian Jackson writes ("still some remaining agent startup race (probability 10^-3 ?)"):

> I just had an invocation of the dgit test suite fail in one of the
> tests because this happened:
> gpg: can't connect to the agent: IPC connect call failed

I have had another failure which I suspect may be the same bug.
This time I saw this:

+ reprepro --outdir /home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/ds-mirror --basedir /home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/ds-mirror includedsc avon /home/ian/things/Dgit/2dgit/tests/tmp/downstream-gitless/mirror/pool/main/example_2.1.dsc
gpgme gave error GPGME:54: Unusable secret key
ERROR: Could not finish exporting 'avon'!

Ian.

[Tony Finch]

Ian mentioned this bug to me and encouraged me to describe some similar
problems I have had to deal with in recent versions of gnupg which were
not problems in older versions.

I have a gpg wrapper called regpg https://dotat.at/prog/regpg/

It has a test suite that is supposed to work with gnupg 1.4, 2.0, 2.1, and 2.2.

For versions 2.1 and above (which make the agent obligatory), the test
suite explicitly starts the agent at the beginning of each test script and
kills it at the end; it also uses --debug-quick-random to avoid stalls due
to bogus entropy accounting.

https://git.uis.cam.ac.uk/x/uis/git/regpg.git/blob/HEAD:/t/lib/T.pm#l100

There was also an issue that I had to split the first test script which
originally re-initialized the temporary $GPGHOME and generated some test
private keys; the re-initialization caused the agent to commit suicide,
which caused key generation to fail, so I split it into separate scripts,
one to initialize $GPGHOME, and a second one to generate keys (after the
shared per-script setup code restarted the agent).

Tony.
--
f.anthony.n.finch <d...@dotat.at> http://dotat.at/ - I xn--zr8h punycode
Fitzroy: Northeast, backing north, 6 to gale 8. Rough or very rough, becoming
high later in northwest. Rain then showers. Good, occasionally moderate.

[Tony Finch]

I am seeing random failures with gnupg more frequently than I used to.

I have an Ansible plugin that invokes gpg in a very straightforward manner:

https://dotat.at/cgi/git/regpg.git/blob/HEAD:/ansible/filter.py

In the situation I use this plugin, I am typically decrypting and
installing secrets on 15 servers in parallel. This happens several times
during an Ansible run, for a different kind of secret each time. Usually
one of these decryptions will randomly fail during the run, like this:

TASK [ssh : ssh host private keys]

gpg: decryption failed: No secret key

failed: [rnb-a.dns.cam.ac.uk] (item=ssh_host_ed25519_key) => {"failed": true, "item": "ssh_host_ed25519_key", "msg": "gpg --decrypt /home/fanf2/work/dns/ipreg/ansible/roles/ssh/files/rec/ssh_host_ed25519_key.asc failed: "}

The agent is pre-loaded with the passphrase at the start of the run, so
there is no user interaction while it is in progress. The random failures
are becoming more frequent as the number of servers increases.

I'm using gnupg 2.1.18-8~deb9u3 on Debian Stretch.

Tony.
--
f.anthony.n.finch <d...@dotat.at> http://dotat.at/

Dover, Wight, Portland, Plymouth: Southwest backing south 4 or 5, occasionally
3 at first, increasing 6 at times later in Plymouth. Slight or moderate,
becoming rough in west Plymouth. Fair. Good.