Forwarded gpg ssh agent doesn't see smartcard ssh key, only (none)
Open, Needs TriagePublic

Description

The setup is exactly the same as in [0], except for gpg-bridge, where normal gpg socket is used instead of the extra socket. Please see that link for the description of the setup and configs.

I am using gpg ssh agent and ssh key on Yubikey, and:

  • on both machines with Yubikey plugged in locally ssh authentication works correctly
  • both machines have the Yubikey auth key in $GNUPGHOME/sshcontrol (not necessary according to gpg documentation, but just to eliminate potential problems)
  • ssh-add -L prints the key on both machines:

when plugged into local it gives:

> ssh-add -L
ssh-rsa [...] cardno:<DISPSERIALNO>
ssh-rsa [...] (none)

when plugged into remote it gives:

❯ ssh-add -L
ssh-rsa [...] cardno:<DISPSERIALNO>
ssh-rsa [...] (none)

when plugged into local, in remote ssh it gives:

❯ ssh-add -L
ssh-rsa [...] (none)

Both cardno:<DISPSERIALNO> and (none) are the same identical keys. Roughly speaking, duplicated under different names(?).

Additional comment about "Session:" below. Seems like gpg agent doesn't see the card key and ssh suggests me to plug in the card, all it sees is the (none) key.

Any advice on this problem?

Below are the logs of gpg-agent without any additional commentary.

Local

Prepare for session:

> gpgconf --kill all
> rm ~/.gnupg/*log
> gpg-connect-agent updatestartuptty /bye
gpg-connect-agent: no running gpg-agent - starting 'C:\Program Files (x86)\gnupg\bin\gpg-agent.exe'
gpg-connect-agent: waiting for the agent to come up ... (5s)
gpg-connect-agent: connection to agent established
OK

Session:

> ssh pc
Last login: ...
gpg-connect-agent: no running gpg-agent - starting '/usr/bin/gpg-agent'
gpg-connect-agent: waiting for the agent to come up ... (5s)
gpg-connect-agent: connection to agent established
❯ ssh -T git@github.com
Please insert the card with serial number:

  <DISPSERIALNO>
  OK
  Cancel
[oc]? o
Please insert the card with serial number:

  <DISPSERIALNO>
  OK
  Cancel
[oc]? c
sign_and_send_pubkey: signing failed for RSA "(none)" from agent: agent refused operation
git@github.com: Permission denied (publickey).
❯
Connection to <REMOTE_MACHINE_IP> closed.
>

<gpg-agent.log> after session:

2020-09-11 07:14:29 gpg-agent[7656] listening on socket 'C:\Users\avemilia\AppData\Roaming\gnupg\S.gpg-agent'
2020-09-11 07:14:29 gpg-agent[7656] listening on socket 'C:\Users\avemilia\AppData\Roaming\gnupg\S.gpg-agent.extra'
2020-09-11 07:14:29 gpg-agent[7656] listening on socket 'C:\Users\avemilia\AppData\Roaming\gnupg\S.gpg-agent.browser'
2020-09-11 07:14:29 gpg-agent[7656] listening on socket 'C:\Users\avemilia\AppData\Roaming\gnupg\S.gpg-agent.ssh'
2020-09-11 07:14:29 gpg-agent[7656] gpg-agent (GnuPG) 2.2.23 started
2020-09-11 07:14:29 gpg-agent[7656] putty message loop thread started
2020-09-11 07:14:29 gpg-agent[7656] DBG: chan_0x00000284 -> OK Pleased to meet you
2020-09-11 07:14:29 gpg-agent[7656] DBG: chan_0x00000284 <- RESET
2020-09-11 07:14:29 gpg-agent[7656] DBG: chan_0x00000284 -> OK
2020-09-11 07:14:29 gpg-agent[7656] DBG: chan_0x00000284 <- updatestartuptty
2020-09-11 07:14:29 gpg-agent[7656] DBG: chan_0x00000284 -> OK
2020-09-11 07:14:29 gpg-agent[7656] DBG: chan_0x00000284 <- [eof]
2020-09-11 07:14:36 gpg-agent[7656] DBG: ssh map file 'WSLPageantRequest'
2020-09-11 07:14:36 gpg-agent[7656] DBG: ssh map handle 0x00000298
2020-09-11 07:14:36 gpg-agent[7656] DBG:           my sid: 'S-1-5-21-2866614668-1482101499-365976279-1001'
2020-09-11 07:14:36 gpg-agent[7656] DBG: ssh map file sid: 'S-1-5-21-2866614668-1482101499-365976279-1001'
2020-09-11 07:14:36 gpg-agent[7656] DBG: ssh IPC buffer at 0x00770000
2020-09-11 07:14:36 gpg-agent[7656] ssh request handler for request_identities (11) started
2020-09-11 07:14:36 gpg-agent[7656] no running SCdaemon - starting it
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- OK GNU Privacy Guard's Smartcard server ready
2020-09-11 07:14:36 gpg-agent[7656] DBG: first connection to SCdaemon established
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 -> GETINFO socket_name
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- D C:\Users\avemilia\AppData\Roaming\gnupg\S.scdaemon
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:36 gpg-agent[7656] DBG: additional connections at 'C:\Users\avemilia\AppData\Roaming\gnupg\S.scdaemon'
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 -> OPTION event-signal=0x00000280
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 -> SERIALNO
2020-09-11 07:14:36 gpg-agent[7656] SIGUSR2 received - updating card event counter
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- S SERIALNO <SERIALNO>
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 -> GETINFO card_list
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- S SERIALNO <SERIALNO>
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 -> SERIALNO --demand=<SERIALNO>
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- S SERIALNO <SERIALNO>
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 -> GETATTR $AUTHKEYID
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- S $AUTHKEYID OPENPGP.3
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 -> GETATTR SERIALNO
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- S SERIALNO <SERIALNO>
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 -> READKEY OPENPGP.3
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_000002C4 <- [ 44 20 28 ... ]
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 -> GETATTR $DISPSERIALNO
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- S $DISPSERIALNO <DISPSERIALNO>
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:36 gpg-agent[7656] ssh request handler for request_identities (11) ready
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 -> RESTART
2020-09-11 07:14:36 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:37 gpg-agent[7656] DBG: ssh map file 'WSLPageantRequest'
2020-09-11 07:14:37 gpg-agent[7656] DBG: ssh map handle 0x00000298
2020-09-11 07:14:37 gpg-agent[7656] DBG:           my sid: 'S-1-5-21-2866614668-1482101499-365976279-1001'
2020-09-11 07:14:37 gpg-agent[7656] DBG: ssh map file sid: 'S-1-5-21-2866614668-1482101499-365976279-1001'
2020-09-11 07:14:37 gpg-agent[7656] DBG: ssh IPC buffer at 0x00770000
2020-09-11 07:14:37 gpg-agent[7656] ssh request handler for sign_request (13) started
2020-09-11 07:14:37 gpg-agent[7656] new connection to SCdaemon established (reusing)
2020-09-11 07:14:37 gpg-agent[7656] DBG: chan_0x000002c4 -> SERIALNO --demand=<SERIALNO>
2020-09-11 07:14:37 gpg-agent[7656] DBG: chan_0x000002c4 <- S SERIALNO <SERIALNO>
2020-09-11 07:14:37 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:37 gpg-agent[7656] DBG: detected card with S/N <SERIALNO>
2020-09-11 07:14:37 gpg-agent[7656] DBG: chan_0x000002c4 -> SETDATA [...]
2020-09-11 07:14:37 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:37 gpg-agent[7656] DBG: chan_0x000002c4 -> PKAUTH OPENPGP.3
2020-09-11 07:14:37 gpg-agent[7656] DBG: chan_000002C4 <- [ 49 4e 51 ... ]
2020-09-11 07:14:37 gpg-agent[7656] starting a new PIN Entry
2020-09-11 07:14:37 gpg-agent[7656] DBG: connection to PIN entry established
2020-09-11 07:14:45 gpg-agent[7656] DBG: chan_000002C4 -> [ 44 20 7e ... ]
2020-09-11 07:14:45 gpg-agent[7656] DBG: chan_0x000002c4 -> END
2020-09-11 07:14:48 gpg-agent[7656] DBG: chan_000002C4 <- [ 44 20 b3 ... ]
2020-09-11 07:14:48 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:14:48 gpg-agent[7656] ssh request handler for sign_request (13) ready
2020-09-11 07:14:48 gpg-agent[7656] DBG: chan_0x000002c4 -> RESTART
2020-09-11 07:14:48 gpg-agent[7656] DBG: chan_0x000002c4 <- OK
2020-09-11 07:15:33 gpg-agent[7656] DBG: chan_0x00000294 -> OK Pleased to meet you
2020-09-11 07:15:33 gpg-agent[7656] DBG: chan_0x00000294 <- GETINFO pid
2020-09-11 07:15:33 gpg-agent[7656] DBG: chan_0x00000294 -> D 7656
2020-09-11 07:15:33 gpg-agent[7656] DBG: chan_0x00000294 -> OK
2020-09-11 07:15:33 gpg-agent[7656] DBG: chan_0x00000294 <- BYE
2020-09-11 07:15:33 gpg-agent[7656] DBG: chan_0x00000294 -> OK closing connection

Remote

Prepare for session:

❯ gpgconf --kill all
❯ rm ~/.gnupg/*log
❯ gpg-connect-agent updatestartuptty /bye
gpg-connect-agent: no running gpg-agent - starting '/usr/bin/gpg-agent'
gpg-connect-agent: waiting for the agent to come up ... (5s)
gpg-connect-agent: connection to agent established
OK

<gpg-agent.log> after session:

2020-09-11 07:14:02 gpg-agent[105576] listening on socket '/run/user/1000/gnupg/S.gpg-agent'
2020-09-11 07:14:02 gpg-agent[105576] listening on socket '/run/user/1000/gnupg/S.gpg-agent.extra'
2020-09-11 07:14:02 gpg-agent[105576] listening on socket '/run/user/1000/gnupg/S.gpg-agent.browser'
2020-09-11 07:14:02 gpg-agent[105576] listening on socket '/run/user/1000/gnupg/S.gpg-agent.ssh'
2020-09-11 07:14:02 gpg-agent[105577] gpg-agent (GnuPG) 2.2.23 started
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 -> OK Pleased to meet you, process 105574
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 <- RESET
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 -> OK
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 <- OPTION ttyname=/dev/pts/1
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 -> OK
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 <- OPTION ttytype=xterm-kitty
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 -> OK
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 <- OPTION display=:0
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 -> OK
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 <- OPTION xauthority=/home/ave/.Xauthority
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 -> OK
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 <- OPTION putenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 -> OK
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 <- OPTION lc-ctype=en_US.UTF-8
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 -> OK
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 <- OPTION lc-messages=en_US.UTF-8
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 -> OK
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 <- updatestartuptty
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 -> OK
2020-09-11 07:14:02 gpg-agent[105577] DBG: chan_10 <- [eof]
2020-09-11 07:14:47 gpg-agent[105577] socket file has been removed - shutting down
2020-09-11 07:14:47 gpg-agent[105577] gpg-agent (GnuPG) 2.2.23 stopped
2020-09-11 07:14:48 gpg-agent[105666] listening on socket '/run/user/1000/gnupg/S.gpg-agent'
2020-09-11 07:14:48 gpg-agent[105666] listening on socket '/run/user/1000/gnupg/S.gpg-agent.extra'
2020-09-11 07:14:48 gpg-agent[105666] listening on socket '/run/user/1000/gnupg/S.gpg-agent.browser'
2020-09-11 07:14:48 gpg-agent[105666] listening on socket '/run/user/1000/gnupg/S.gpg-agent.ssh'
2020-09-11 07:14:48 gpg-agent[105667] gpg-agent (GnuPG) 2.2.23 started
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 -> OK Pleased to meet you, process 105664
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 <- RESET
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 -> OK
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 <- OPTION ttyname=/dev/pts/2
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 -> OK
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 <- OPTION ttytype=xterm-256color
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 -> OK
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 <- OPTION putenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 -> OK
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 <- OPTION lc-ctype=en_US.UTF-8
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 -> OK
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 <- OPTION lc-messages=en_US.UTF-8
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 -> OK
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 <- updatestartuptty
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 -> OK
2020-09-11 07:14:48 gpg-agent[105667] DBG: chan_10 <- [eof]
2020-09-11 07:15:22 gpg-agent[105667] ssh handler 0x7f29eddcf640 for fd 10 started
2020-09-11 07:15:22 gpg-agent[105667] ssh request handler for request_identities (11) started
2020-09-11 07:15:22 gpg-agent[105667] no running SCdaemon - starting it
2020-09-11 07:15:22 gpg-agent[105667] DBG: chan_11 <- OK GNU Privacy Guard's Smartcard server ready
2020-09-11 07:15:22 gpg-agent[105667] DBG: first connection to SCdaemon established
2020-09-11 07:15:22 gpg-agent[105667] DBG: chan_11 -> GETINFO socket_name
2020-09-11 07:15:22 gpg-agent[105667] DBG: chan_11 <- D /run/user/1000/gnupg/S.scdaemon
2020-09-11 07:15:22 gpg-agent[105667] DBG: chan_11 <- OK
2020-09-11 07:15:22 gpg-agent[105667] DBG: additional connections at '/run/user/1000/gnupg/S.scdaemon'
2020-09-11 07:15:22 gpg-agent[105667] DBG: chan_11 -> OPTION event-signal=12
2020-09-11 07:15:22 gpg-agent[105667] DBG: chan_11 <- OK
2020-09-11 07:15:22 gpg-agent[105667] DBG: chan_11 -> SERIALNO
2020-09-11 07:15:22 gpg-agent[105667] DBG: chan_11 <- ERR 100696144 No such device <SCD>
2020-09-11 07:15:22 gpg-agent[105667] ssh request handler for request_identities (11) ready
2020-09-11 07:15:22 gpg-agent[105667] ssh request handler for sign_request (13) started
2020-09-11 07:15:22 gpg-agent[105667] DBG: chan_11 -> SERIALNO --demand=<SERIALNO>
2020-09-11 07:15:22 gpg-agent[105667] DBG: chan_11 <- ERR 100696144 No such device <SCD>
2020-09-11 07:15:22 gpg-agent[105667] DBG: no device present
2020-09-11 07:15:22 gpg-agent[105667] starting a new PIN Entry
2020-09-11 07:15:22 gpg-agent[105667] DBG: connection to PIN entry established
2020-09-11 07:15:28 gpg-agent[105667] DBG: chan_11 -> SERIALNO --demand=<SERIALNO>
2020-09-11 07:15:28 gpg-agent[105667] DBG: chan_11 <- ERR 100696144 No such device <SCD>
2020-09-11 07:15:28 gpg-agent[105667] DBG: no device present
2020-09-11 07:15:28 gpg-agent[105667] starting a new PIN Entry
2020-09-11 07:15:28 gpg-agent[105667] DBG: connection to PIN entry established
2020-09-11 07:15:30 gpg-agent[105667] DBG: error calling pinentry: Operation cancelled <Pinentry>
2020-09-11 07:15:30 gpg-agent[105667] smartcard signing failed: Operation cancelled
2020-09-11 07:15:30 gpg-agent[105667] ssh sign request failed: Operation cancelled <Pinentry>
2020-09-11 07:15:30 gpg-agent[105667] ssh request handler for sign_request (13) ready
2020-09-11 07:15:30 gpg-agent[105667] DBG: chan_11 -> RESTART
2020-09-11 07:15:30 gpg-agent[105667] DBG: chan_11 <- OK
2020-09-11 07:15:30 gpg-agent[105667] ssh handler 0x7f29eddcf640 for fd 10 terminated

[0] https://dev.gnupg.org/T5062

Details

Version
2.2.23
avemilia created this task.Fri, Sep 11, 8:25 AM
avemilia updated the task description. (Show Details)
avemilia updated the task description. (Show Details)Fri, Sep 11, 8:33 AM
avemilia updated the task description. (Show Details)Fri, Sep 11, 8:38 AM