#934237 yubikey communication fails on startup

Package:
gpg-agent
Source:
gnupg2
Description:
GNU privacy guard - cryptographic agent
Submitter:
Antoine Beaupre
Date:
2019-10-01 04:09:03 UTC
Severity:
normal
#934237#5
Date:
2019-08-08 13:57:37 UTC
From:
To:
Since I upgraded this package from buster (2.12) to buster-backports
(2.17), things started going weird with my Yubikey. (At least I think
that's the trigger.)

When I login in the morning, my Yubikey setup fails to let me connect
to remove SSH servers:

$ ssh example.com
sign_and_send_pubkey: signing failed: agent refused operation
anarcat@example.com: Permission denied (publickey).

I see this in my session logs:

aoû 08 09:51:37 curie gpg-agent[3298]: scdaemon[3302] ccid open error: skip
aoû 08 09:51:37 curie gpg-agent[3298]: scdaemon[3302] ccid open error: skip
aoû 08 09:51:37 curie gpg-agent[3298]: scdaemon[3302] ccid open error: skip
aoû 08 09:51:37 curie gpg-agent[3298]: DBG: detected card with S/N D2760001240102000006036471890000
aoû 08 09:51:37 curie gpg-agent[3298]: [103B blob data]
aoû 08 09:51:37 curie gpg-agent[3298]: scdaemon[3302] le rappel du code personnel a renvoyé une erreur : L'appel IPC a été annulé
aoû 08 09:51:37 curie gpg-agent[3298]: scdaemon[3302] app_auth failed: L'appel IPC a été annulé
aoû 08 09:51:37 curie gpg-agent[3298]: smartcard signing failed: Ioctl() inapproprié pour un périphérique
aoû 08 09:51:37 curie gpg-agent[3298]: ssh sign request failed: Ioctl() inapproprié pour un périphérique <Pinentry>

Sorry for my french, but this basically says:

 * the personal code reminder returned an error: the IPC call failed
 * app_auth failed: the IPC call was canceled

I have no idea what's going on, to be honest. The Yubikey in itself
works fine: I can login on websites with Firefox with U2F, and `gpg
--card-status` and `--card-edit` look normal.

The workaround I have found is to restart gpg-agent, but it takes a
*long* time so it's pretty annoying:

$ time systemctl --user restart gpg-agent
0.00user 0.00system 1:30.09elapsed 0%CPU (0avgtext+0avgdata 3864maxresident)k
0inputs+0outputs (0major+206minor)pagefaults 0swaps

But that's a separate problem I guess.

Once gpg-agent is restarted, the Yubikey works fine again. And that
is, even if it's unplugged and plugged back in again.

I first thought this could have been a bad interaction with USBguard
but I feel that the fact it still works after restart and reconnection
rules out that problem.

#934237#10
Date:
2019-08-09 00:08:35 UTC
From:
To:
Antoine Beaupre <anarcat@debian.org> wrote:

How do you invoke gpg-agent?  If it is through your first SSH
invocation, gpg-agent wouldn't know the place where to ask PIN (TTY and
DISPLAY).

You can check if you can use your tokan with SSH after your first
invocation of:

	$ gpg --card-status

or

        $ gpg-connect-agent UPDATESTARTUPTTY /bye

Then, that's the case.

gpg-agent should know the place where to ask PIN (TTY and DISPLAY), and
it is told by gpg frontend or gpg-connct-agent.  But in the case of SSH
(external/foreign program), there is no such mechanism telling the
place.

If it is "Inappropriate ioctl for device", it means that pinentry failed
because of no place to ask.

For me, it sounds like... it is your first invocation of SSH (by systemd
watching the socket), which invokes gpg-agent.

#934237#15
Date:
2019-08-09 02:35:14 UTC
From:
To:
I don't directly invoke it. It might be through the first SSH connexion,
or earlier (see below). But it's running under `systemd --user`.

`gpg --card-status` works, as I said.

Oh god, that TTY thing. I have this in my .bashrc because of problems
with GPG on that front:

# see http://bugs.debian.org/719908
export GPG_TTY=$(tty)

I have no idea what it does or why it matters. It might be related.

It wouldn't explain why this suddenly started failing.

You know what, now that I think of it, one thing that changed recently
in my startup sequence, and that might affect this, is this:

|  .config/systemd/user/{multi-user.target.wants => default.target.wants}/smd-pull.service    | 0

This is me switching my "systemd --user"-level services from
`multi-user.target` (which does nothing) to `default.target` (which does
start services on session start.

This peculiar service is something that connects over SSH to fetch my
mail. It *might* try to talk to the Yubikey and fire up GPG agent (maybe
even before Xorg comes up, and definitely before the Yubikey is
entered).

This might be the actual trigger for this problem I'll test this (and an
older version of GPG) to see if I can backtrack the issue.

Thanks! That's very useful information, although I can't help but think
that a better error message would be useful here.. ;)

For what it's worth, gpg-agent runs as "supervised" here, i.e. it seems
to be under the control of `systemd --user`. Not sure what that means,
but when it's running, it's running under systemd and I can restart it
with `systemctl --user restart gpg-agent`.

But thanks for all the great information, I have a lot of things to move
forward with now!

A.

#934237#20
Date:
2019-08-09 02:49:08 UTC
From:
To:
workaround.

I also observed something strange. I sign all git commits automatically
here. I just did a commit, and git was able to make gpg-agent pop up the
pinentry dialog without problem for the commit OpenPGP signature, which
happens on the Yubikey. But the *push* part failed as described in this
bug report.

Then the above gpg-connect-agent hack worked around the issue.

It's strange that one function (signing) works while the other
(authentication) doesn't, no?

$ gpg --card-status
Reader ...........: Yubico Yubikey NEO OTP U2F CCID 00 00
Application ID ...: [REDACTED]
Version ..........: 2.0
Manufacturer .....: Yubico
Serial number ....: [REDACTED]
Name of cardholder: [non positionné]
Language prefs ...: [non positionné]
Sex ..............: non indiqué
URL of public key : [non positionné]
Login data .......: [non positionné]
Signature PIN ....: non forcé
Key attributes ...: rsa2048 rsa2048 rsa2048
Max. PIN lengths .: 127 127 127
PIN retry counter : 3 3 3
Signature counter : 12896
Signature key ....: 7B16 4204 D096 723B 0196  35AB 3EA1 DDDD B261 D97B
      created ....: 2017-08-23 23:10:50
Encryption key....: 7301 8B4C D3E4 82C6 E90F  B7C3 C665 A3C5 2513 53D0
      created ....: 2017-08-25 18:18:02
Authentication key: 5A23 7308 8863 DBDF 2E00  7607 604E 4B3E EE02 855A
      created ....: 2012-07-20 00:17:35
General key info..: sub  rsa2048/3EA1DDDDB261D97B 2017-08-23 Antoine Beaupré <anarcat@orangeseeds.org>
sec   rsa4096/792152527B75921E  créé : 2009-05-29  expire : 2020-06-05
ssb#  rsa2048/B7F648FED2DF2587  créé : 2012-07-18  expire : jamais
ssb>  rsa2048/604E4B3EEE02855A  créé : 2012-07-20  expire : jamais
                                nº de carte : 0006 03647189
ssb#  rsa2048/46DC033CAFD0FDF8  créé : 2012-07-24  expire : jamais
ssb   rsa4096/A51D5B109C5A5581  créé : 2009-05-29  expire : jamais
ssb>  rsa2048/3EA1DDDDB261D97B  créé : 2017-08-23  expire : jamais
                                nº de carte : 0006 03647189

But in this case, I ran 'git push' in a terminal I control,
interactively. gpg knows which terminal it's on, and it even knows which
DISPLAY it's on, and could definitely prompt me, either on the terminal
or the GUI.

I'll try again without the startup scripts next.

a.

#934237#25
Date:
2019-08-09 03:17:00 UTC
From:
To:
Control: found -1 2.2.12-1

I can confirm that the problem still occurs with the GPG version in
Debian buster (2.2.12-1), when my startup scripts talk with SSH
prematurely.

Those scripts don't even *need* the SSH key on the Yubikey, mind
you. They just start looking around and find a key with a handle and try
to offer it. The interesting thing is there's an on-disk key that works
for that SSH connexion: it's its entire purpose. While the Yubikey can
*also* authenticate to that server, I don't actually *use* that key to
connect anyways.

So if I could rephrase that bug, I'd say that gpg-agent is
"sticky". Whenever it gets called first is what determines the TTY. If
that TTY is messed up (because it gets called too early in the session),
it's forever doomed and needs to restart or be retold where it is:

    gpg-connect-agent UPDATESTARTUPTTY /bye

This seems sub-optimal. It's also quite strange it affects only
authentication and not signing: it might be something specific to
gpg-agent's SSH support.

I would argue that GPG's concept of a TTY is somewhat broken. I've
encountered this before, as I said earlier, in #719908, and I'm still
unconvinced at the way things are handled. But I'm not skilled enough in
all those interactions to tell what would be the correct way.

All I know is weird stuff happens like this all the time, and I often
end up restarting those daemons and things kind of work. But "kind of
works" isn't great: I'd love if GnuPG "just worked" all the time. :)

Thanks for the excellent feedback, and I hope the details I've provided
are useful. I have found the problem on my side, so from my point of
view the problem is "solved" in its immediacy, so feel free to close
this bug. But if you think (like me) the underlying problem should be
solved, I'd be happy to assist you with further testing.

Thanks!

A.

#934237#32
Date:
2019-09-30 18:36:51 UTC
From:
To:
it is.  gpg-agent's SSH support uses OpenSSH's ssh-agent protocol, which
has no way of indicating to the agent how/where the prompts should
happen.

gpg-agent's native mechanism uses an entirely different protocol (on a
different socket too).  The gpg-agent mechansism *does* provide a way
for the invoking client to tell the agent where the prompting should
happen.  This means that when gpg itself talks to gpg-agent, it sets the
DISPLAY, DBUS_SESSION_BUS_ADDRESS, GPG_TTY, etc. options explicitly.

But when ssh talks to what it thinks is the ssh-agent, it provides no
such information.

If you use a graphical environment with a per-user dbus session which is
initialized with the rest of your systemd user session manager, then you
should also use a pinentry that communicates over dbus -- in this case,
gpg-agent should be started with knowledge of the dbus session, and so
the pinentry should automatically know how to communicate with the user.

afaik, pinentry-gnome3 is the only pinentry that communicates over dbus
at the moment.

so, the recommended way of avoiding these problems longer term on a
system with a graphical environment is (as the superuser):

      apt install pinentry-gnome3 dbus-user-session
      update-alternatives --set pinentry /usr/bin/pinentry-gnome3

and then log out and log back in again.

If that doesn't work for you, i'd definitely like to know about it.