Hello,
In my case I have the problem with 2.1.7-2.
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,