Follow-up to Crashes with gpg-agent 2.1.18

[Shah, Amul]

Please excuse any Outlook formatting oddities. I am re-sending this as it has not
shown up on the mailing list.

I think that this is a follow up to a thread from January (last email in thread
https://lists.gnupg.org/pipermail/gnupg-devel/2017-January/032516.html) because it
started with me seeing the message "Ohhhh jeeee: ... this is a bug
(sexp.c:1433:do_vsexp_sscan)" in the gpg-agent log. Now in trying to reproduce the
error, the gpg- agent hits a PKDECRYPT failure claiming that it cannot allocate
memory.

I tried debugging the error down into libgcrypt, but could not see where things
could go wrong unless the memory manager is not npthread safe. Since I made no
progress, I'm sending this mail along with a test case similar to the one from the
previous thread.

Note that we don't encounter this problem with older GnuPG versions, GnuPG 2.15
and earlier.

Could someone take a look at this or give me some pointers on how I can help
myself?

Thanks,
Amul

---- Host Information ----
Distributor ID: Debian
Description:    Debian GNU/Linux 9.0 (stretch)
Release:        9.0
Codename:       stretch

Package: gnupg2 Version: 2.1.18-6
Package: gnupg-agent    Version: 2.1.18-6
Package: libgcrypt20    Version: 1.7.6-1
Package: libgpgme11     Version: 1.8.0-3+b2
Package: libnpth0       Version: 1.3-1
Package: libassuan0     Version: 2.4.3-2

---- Error Information ----
2017-03-30 19:34:43 gpg-agent[745886] starting a new PIN Entry
2017-03-30 19:34:43 gpg-agent[745886] failed to build S-Exp (off=0): Cannot allocate memory
2017-03-30 19:34:43 gpg-agent[745886] failed to read the secret key
2017-03-30 19:34:43 gpg-agent[745886] command 'PKDECRYPT' failed: Cannot allocate memory <gcrypt>
2017-03-30 19:34:43 gpg-agent[745886] failed to build S-Exp (off=0): Cannot allocate memory
2017-03-30 19:34:43 gpg-agent[745886] failed to read the secret key
2017-03-30 19:34:44 gpg-agent[745886] handler 0x7ff368f81700 for fd 184 started
2017-03-30 19:34:44 gpg-agent[745886] Warning: using insecure memory!
2017-03-30 19:34:44 gpg-agent[745886] retrieving cache entry '29395A5EFE485B83873C2B5435FCB4DC482765FD' failed: Invalid cipher mode
--
2017-03-30 19:34:44 gpg-agent[745886] retrieving cache entry '29395A5EFE485B83873C2B5435FCB4DC482765FD' failed: Invalid cipher mode
2017-03-30 19:34:44 gpg-agent[745886] command 'PKDECRYPT' failed: Cannot allocate memory <gcrypt>
2017-03-30 19:34:44 gpg-agent[745886] retrieving cache entry '29395A5EFE485B83873C2B5435FCB4DC482765FD' failed: Invalid cipher mode

---- Test case ----
echo "# Setup agent config to avoid interactive password prompting"
echo "verbose" >> $GNUPGHOME/gpg-agent.conf
echo "log-file $GNUPGHOME/agent.log" >> $GNUPGHOME/gpg-agent.conf
echo "pinentry-program $GNUPGHOME/pinentry.csh" >> $GNUPGHOME/gpg-agent.conf

cat >$GNUPGHOME/pinentry.csh << EOF
#!/bin/tcsh
set word = ""
while (("\$word" != "getpin") && ("\$word" != "GETPIN"))  echo "OK"
set word = "\$<"
end
echo "D abc123"
echo "OK"
EOF
chmod a+rx $GNUPGHOME/pinentry.csh

yes | gpg2 --passphrase abc123 --quick-gen-key user at host.com

echo # Encrypt a file
rm -f test.gpg
echo testme > test
gpg2 -e -r user at host.com test

echo "# This had better work"
gpg2 -d test.gpg || exit 9

echo "# Hit the agent hard"
for i in $(seq 1 200); do (gpg2 -d test.gpg > test${i}.log 2>&1 & ); done wait gpg-connect-agent 'getinfo pid' /bye sleep 1 gpg-connect-agent killagent /bye grep 'fail' *.log grep -C1 --color -E "jee|memory" $GNUPGHOME/agent.log

echo "Doit!"
echo "rm -rf $GNUPGHOME"
gpg-connect-agent killagent /bye

---- Full test case output ----
# Do Setup
# Setup agent config to avoid interactive password prompting
gpg: keybox '/tmp/tmp.t40xj0I2lY/pubring.kbx' created We need to generate a lot of random bytes. It is a good idea to perform some other action (type on the keyboard, move the mouse, utilize the
disks) during the prime generation; this gives the random number generator a better chance to gain enough entropy.
We need to generate a lot of random bytes. It is a good idea to perform some other action (type on the keyboard, move the mouse, utilize the
disks) during the prime generation; this gives the random number generator a better chance to gain enough entropy.
gpg: /tmp/tmp.t40xj0I2lY/trustdb.gpg: trustdb created
gpg: key 4DB73400DF6568DF marked as ultimately trusted
gpg: directory '/tmp/tmp.t40xj0I2lY/openpgp-revocs.d' created
gpg: revocation certificate stored as '/tmp/tmp.t40xj0I2lY/openpgp-revocs.d/61F7B673B3ABCE0A308314AE4DB73400DF6568DF.rev'
public and secret key created and signed.

pub   rsa2048 2017-03-30 [SC] [expires: 2019-03-30]
      61F7B673B3ABCE0A308314AE4DB73400DF6568DF
      61F7B673B3ABCE0A308314AE4DB73400DF6568DF
uid                      user at host.com
sub   rsa2048 2017-03-30 [E]


gpg: checking the trustdb
gpg: marginals needed: 3  completes needed: 1  trust model: pgp
gpg: depth: 0  valid:   1  signed:   0  trust: 0-, 0q, 0n, 0m, 0f, 1u
gpg: next trustdb check due at 2019-03-30 # This had better work
gpg: encrypted with 2048-bit RSA key, ID 5941F75AFA9801E6, created 2017-03-30
      "user at host.com"
testme
# Hit the agent hard
D 745886
OK
OK closing connection
test25.log:gpg: public key decryption failed: Cannot allocate memory
test25.log:gpg: decryption failed: No secret key
test7.log:gpg: public key decryption failed: Cannot allocate memory
test7.log:gpg: decryption failed: No secret key
2017-03-30 19:34:43 gpg-agent[745886] starting a new PIN Entry
2017-03-30 19:34:43 gpg-agent[745886] failed to build S-Exp (off=0): Cannot allocate memory
2017-03-30 19:34:43 gpg-agent[745886] failed to read the secret key
2017-03-30 19:34:43 gpg-agent[745886] command 'PKDECRYPT' failed: Cannot allocate memory <gcrypt>
2017-03-30 19:34:43 gpg-agent[745886] failed to build S-Exp (off=0): Cannot allocate memory
2017-03-30 19:34:43 gpg-agent[745886] failed to read the secret key
2017-03-30 19:34:44 gpg-agent[745886] handler 0x7ff368f81700 for fd 184 started
2017-03-30 19:34:44 gpg-agent[745886] Warning: using insecure memory!
2017-03-30 19:34:44 gpg-agent[745886] retrieving cache entry '29395A5EFE485B83873C2B5435FCB4DC482765FD' failed: Invalid cipher mode
--
2017-03-30 19:34:44 gpg-agent[745886] retrieving cache entry '29395A5EFE485B83873C2B5435FCB4DC482765FD' failed: Invalid cipher mode
2017-03-30 19:34:44 gpg-agent[745886] command 'PKDECRYPT' failed: Cannot allocate memory <gcrypt>
2017-03-30 19:34:44 gpg-agent[745886] retrieving cache entry '29395A5EFE485B83873C2B5435FCB4DC482765FD' failed: Invalid cipher mode Doit!
rm -rf /tmp/tmp.t40xj0I2lY
OK closing connection


The information contained in this message is proprietary and/or confidential. If you are not the intended recipient, please: (i) delete the message and all copies; (ii) do not disclose, distribute or use the message in any manner; and (iii) notify the sender immediately. In addition, please be aware that any message addressed to our domain is subject to archiving and review by persons other than the intended recipient. Thank you.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: </pipermail/attachments/20170405/b9c46ecb/attachment.html>