[pkg-gnupg-maint] Bug#795368: gnupg-agent: Fails to function as a SSH agent with smartcard

Sun Aug 30 09:40:33 UTC 2015

Hello,

On Thu, 13 Aug 2015, Mark Brown wrote:
> Version: 2.0.28-3

In my case I have the problem with 2.1.7-2. 

> After some recent upgrades I am no longer able to use a GnuPG smartcard
> to authenticate with remote systems using SSH.  I have gnupg-agent
> configured as my SSH and am able to see the key with ssh-add -l but if I
> try to connect to a remote system SSH displays the error "Agent admitted
> failure to sign using the key.".

I saw this only with SSH from testing, not with the SSH from unstable.
But even with the version in unstable it did not manage to use the key
even though it's correctly listed in "ssh-add -L".

I debugged this further and it seems that the problem lies in the way that
the agent is started. In my case, it's started by
/etc/X11/Xsession.d/90gpg-agent because I have "use-gpg-agent" in
/etc/X11/Xsession.options.

$ sudo cat /proc/7819/environ | sed -e "s/\x0/\n/g"
USER=rhertzog
LC_TIME=fr_FR.UTF-8
XDG_SEAT=seat0
HOME=/home/rhertzog
DESKTOP_SESSION=gnome
LC_MONETARY=fr_FR.UTF-8
LOGNAME=rhertzog
USERNAME=rhertzog
XDG_SESSION_ID=11
WINDOWPATH=7:7:7:7
PATH=/home/rhertzog/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
GDM_LANG=fr_FR.utf8
XDG_RUNTIME_DIR=/run/user/1000
DISPLAY=:1
LANG=fr_FR.utf8
XDG_CURRENT_DESKTOP=GNOME
XDG_SESSION_DESKTOP=gnome
XAUTHORITY=/var/run/gdm3/auth-for-rhertzog-C022ZV/database
SHELL=/bin/bash
GDMSESSION=gnome
LC_MEASUREMENT=fr_FR.UTF-8
XDG_VTNR=7
PWD=/home/rhertzog
XDG_DATA_DIRS=/usr/share/gnome:/usr/local/share/:/usr/share/
LC_NUMERIC=fr_FR.UTF-8
LC_PAPER=fr_FR.UTF-8

In particular it seems worth noting that the environment does
not have any DBUS_SESSION_BUS_ADDRESS yet.

Now when I enable debug log of gpg-agent I saw this:
2015-08-30 10:50:01 gpg-agent[7819] starting a new PIN Entry
2015-08-30 10:50:02 gpg-agent[7819] DBG: connection to PIN entry established
2015-08-30 10:50:02 gpg-agent[7819] DBG: error calling pinentry: Opération annulée <Pinentry>
2015-08-30 10:50:02 gpg-agent[7819] DBG: chan_7 -> CAN
2015-08-30 10:50:02 gpg-agent[7819] DBG: chan_7 <- ERR 100663573 L'appel IPC a été annulé <SCD>
2015-08-30 10:50:02 gpg-agent[7819] DBG: chan_7 -> CAN
2015-08-30 10:50:02 gpg-agent[7819] DBG: chan_7 <- ERR 100663571 Commande IPC inconnue <SCD>
2015-08-30 10:50:02 gpg-agent[7819] smartcard signing failed: Opération annulée
2015-08-30 10:50:02 gpg-agent[7819] ssh sign request failed: Opération annulée <Pinentry>

There are french strings here, but it says "operation canceled", "IPC call got canceled"...

Going further I straced gpg-agent and saw this (cleaned up a bit):
[pid  9900] write(12, "GETPIN", 6 <unfinished ...>
[pid  9901] <... read resumed> "GETPIN", 1002) = 6
[pid  9900] <... write resumed> )       = 6
[...]
[pid  9901] eventfd2(0, O_NONBLOCK|O_CLOEXEC) = 5
[pid  9901] write(5, "\1\0\0\0\0\0\0\0", 8) = 8
[...]
[pid  9901] open("/var/lib/dbus/machine-id", O_RDONLY) = 6
[pid  9901] fstat(6, {st_mode=S_IFREG|0644, st_size=33, ...}) = 0
[pid  9901] read(6, "aa07449049f342009b491bfa00cf9f19\n", 33) = 33
[pid  9901] close(6)                    = 0
[pid  9901] poll([{fd=5, events=POLLIN}], 1, 0) = 1 ([{fd=5, revents=POLLIN}])
[pid  9901] write(5, "\1\0\0\0\0\0\0\0", 8) = 8
[pid  9901] futex(0x10f6580, FUTEX_WAKE_PRIVATE, 2147483647) = 0
[pid  9901] write(2, "\n** (pinentry:9901): WARNING **: couldn't create prompt for gnupg passphrase: Cannot autolaunch D-Bus without X11 $DISPLAY\n", 123) = 123
[pid  9901] write(1, "ERR 83886179 Op\303\251ration annul\303\251e <Pinentry>", 43) = 43
[pid  9900] <... read resumed> "ERR 83886179 Op\303\251ration annul\303\251e <Pinentry>", 1002) = 43
[pid  9901] write(1, "\n", 1 <unfinished ...>
[pid  9900] read(8,  <unfinished ...>
[pid  9901] <... write resumed> )       = 1
[pid  9900] <... read resumed> "\n", 959) = 1
[pid  9901] read(0,  <unfinished ...>
[pid  9900] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2945, ...}) = 0
[pid  9900] write(3, "2015-08-30 10:50:02 gpg-agent[7819] DBG: error calling pinentry: Op\303\251ration annul\303\251e <Pinentry", 94) = 94
[pid  9900] write(3, ">\n", 2)          = 2
[pid  9900] write(12, "BYE", 3)         = 3

So the problem is that /usr/bin/pinentry fails. On my GNOME 3 system
it actually points to /usr/bin/pinentry-gnome3.

And effectively I can recreate the error message with this:
$ env -u DBUS_SESSION_BUS_ADDRESS -u DISPLAY LANG=C /usr/bin/pinentry-gnome3 --display :1
OK Pleased to meet you
GETPIN

** (pinentry-gnome3:11624): WARNING **: couldn't create prompt for gnupg passphrase: Cannot autolaunch D-Bus without X11 $DISPLAY
ERR 83886179 Operation cancelled <Pinentry>

If i restart the gpg-agent in the running session, then it works fine.  So
I just have to kill it and restart "gpg-agent --daemon" from a graphical
terminal and it works fine again.

My guess is thus that:
1/ gpg-agent drops the DISPLAY environment variable (and only passes it
   through the command line option --display)
2/ pinentry-gnome3 does not reinject it in its own environement
3/ gpg-agent keeps the DBUS_SESSION_BUS_ADDRESS variable if it's in the
   environment and effectively hides the former problem when it's started
   from within the graphical session

I don't know what's the proper fix is for this...

But I would suggest at least:
1/ to improve /usr/bin/pinentry-gnome3 to reinject the DISPLAY variable
   so that the DBUS auto-launch works again
2/ possibly reconsider the way the gpg-agent is started so that it's
   part of the user session ? (I noticed that closing the graphical
   session did not close the gpg-agent)
3/ have a way for pinentry programs to indicate a failure due to
   requirement not being met so that alternative pinentry programs can be
   tried?

Cheers,
-- 
Raphaël Hertzog ◈ Debian Developer

Support Debian LTS: http://www.freexian.com/services/debian-lts.html
Learn to master Debian: http://debian-handbook.info/get/