pinentry-touchid
pinentry-touchid copied to clipboard
Published
20 hours ago •
jorgelbg
jorgelbg
help needed: using Yubikey, no touch ID prompt, bad PIN error
Thanks for creating this tool!
environment
I'm using M1 Mac, OS X 12.1, gpg 2.3.4, pinentry-mac 1.1.1.1, pinentry-touchid 0.0.2. My GPG private key is on my Yubikey 5C NFC.
Problem
If I use pinentry-touchid in ~/.gnupg/gpg-agent.conf
pinentry-program /opt/homebrew/opt/pinentry-touchid/bin/pinentry-touchid
and run echo 1234 | gpg -as -, I see
gpg: signing failed: Bad PIN
-----BEGIN PGP MESSAGE-----
gpg: signing failed: Bad PIN
I'm not prompted for a PIN or for touch ID.
What I expect
To be prompted for touch ID, then get encrypted message.
More info
/tmp/pinentry-touchid.log says 2022/02/06 18:19:49 main.go:105: Ready!
gpg-agent.log says
2022-02-06 18:19:49 gpg-agent[95746] starting a new PIN Entry
2022-02-06 18:19:49 gpg-agent[95746] DBG: connection to PIN entry established
2022-02-06 18:19:49 gpg-agent[95746] You may want to update to a newer pinentry
2022-02-06 18:19:50 gpg-agent[95746] DBG: chan_9 -> [ 44 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ...(76 byte(s) skipped) ]
2022-02-06 18:19:50 gpg-agent[95746] DBG: chan_9 -> END
2022-02-06 18:19:50 gpg-agent[95746] DBG: chan_9 <- ERR 100663383 Bad PIN <SCD>
2022-02-06 18:19:50 gpg-agent[95746] smartcard signing failed: Bad PIN
2022-02-06 18:19:50 gpg-agent[95746] command 'PKSIGN' failed: Bad PIN <SCD>
2022-02-06 18:19:50 gpg-agent[95746] DBG: chan_8 -> ERR 100663383 Bad PIN <SCD>
2022-02-06 18:19:50 gpg-agent[95746] DBG: chan_8 <- [eof]
2022-02-06 18:19:50 gpg-agent[95746] DBG: chan_9 -> RESTART
2022-02-06 18:19:50 gpg-agent[95746] DBG: chan_9 <- OK
I know my Yubikey and pinentry-mac are working because if I use pinentry-mac in ~/.gnupg/gpg-agent.conf
pinentry-program /opt/homebrew/bin/pinentry-mac
and run echo 1234 | gpg -as -, I'm prompted for my PIN, then the encrypted message shows up in my terminal.
Could you enable the debug options for gpg-agent? It seems that it is sending something to pinentry-touchid and but it is just getting an END as a reply? I haven't currently tested this with a Yubikey, but I will give it a try. You can also check the output of $TMPDIR/pinentry-touchid.log to see if anything interesting gets logged.
@jorgelbg Here's my ~/.gnupg/gpg-agent.conf
enable-ssh-support
default-cache-ttl 600
max-cache-ttl 7200
pinentry-program /opt/homebrew/opt/pinentry-touchid/bin/pinentry-touchid
debug-level guru
log-file /Users/dxia/.gnupg/gpg-agent.log
Here's the output of tail -f /Users/dxia/.gnupg/gpg-agent.log. First I ran gpgconf --kill gpg-agent && gpg-connect-agent reloadagent /bye. Then after the gap below, I ran echo 1234 | gpg -as -. It looks like gpg-agent is trying to ask me to enter the key's secret key, but I am not prompted for it, and the encryption fails.
2022-08-07 21:41:23 gpg-agent[89402] listening on socket '/Users/dxia/.gnupg/S.gpg-agent'
2022-08-07 21:41:23 gpg-agent[89402] listening on socket '/Users/dxia/.gnupg/S.gpg-agent.extra'
2022-08-07 21:41:23 gpg-agent[89402] listening on socket '/Users/dxia/.gnupg/S.gpg-agent.browser'
2022-08-07 21:41:23 gpg-agent[89402] listening on socket '/Users/dxia/.gnupg/S.gpg-agent.ssh'
2022-08-07 21:41:23 gpg-agent[89403] gpg-agent (GnuPG) 2.3.7 started
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 -> OK Pleased to meet you, process 89401
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 <- RESET
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 <- OPTION ttyname=/dev/ttys005
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 <- OPTION ttytype=xterm-256color
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 <- OPTION lc-ctype=en_US.UTF-8
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 <- OPTION lc-messages=en_US.UTF-8
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 <- reloadagent
2022-08-07 21:41:23 gpg-agent[89403] SIGHUP received - re-reading configuration and flushing cache
2022-08-07 21:41:23 gpg-agent[89403] DBG: agent_flush_cache
2022-08-07 21:41:23 gpg-agent[89403] reading options from '/Users/dxia/.gnupg/gpg-agent.conf'
2022-08-07 21:41:23 gpg-agent[89403] enabled debug flags: mpi crypto memory cache memstat hashing ipc
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:23 gpg-agent[89403] DBG: chan_8 <- [eof]
2022-08-07 21:41:27 gpg-agent[89403] DBG: agent_cache_housekeeping
2022-08-07 21:41:31 gpg-agent[89403] DBG: agent_cache_housekeeping
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK Pleased to meet you, process 89415
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- RESET
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- OPTION ttyname=/dev/ttys005
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- OPTION ttytype=xterm-256color
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- OPTION lc-ctype=en_US.UTF-8
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- OPTION lc-messages=en_US.UTF-8
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- GETINFO version
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> D 2.3.7
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- OPTION allow-pinentry-notify
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- OPTION agent-awareness=2.1.0
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- SCD SERIALNO
2022-08-07 21:41:33 gpg-agent[89403] no running /opt/homebrew/Cellar/gnupg/2.3.7_1/libexec/scdaemon daemon - starting it
2022-08-07 21:41:33 gpg-agent[89403] DBG: agent_flush_cache (pincache only)
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK GNU Privacy Guard's Smartcard server ready
2022-08-07 21:41:33 gpg-agent[89403] first connection to daemon /opt/homebrew/Cellar/gnupg/2.3.7_1/libexec/scdaemon established
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> GETINFO socket_name
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- D /Users/dxia/.gnupg/S.scdaemon
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: additional connections at '/Users/dxia/.gnupg/S.scdaemon'
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> OPTION event-signal=31
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> SERIALNO
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S SERIALNO ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> S SERIALNO ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- SCD SERIALNO
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> SERIALNO
2022-08-07 21:41:33 gpg-agent[89403] SIGUSR2 received - updating card event counter
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S SERIALNO ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> S SERIALNO ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- SCD GETATTR KEY-FPR
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> GETATTR KEY-FPR
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S KEY-FPR 1 ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> S KEY-FPR 1 ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S KEY-FPR 2 ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> S KEY-FPR 2 ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S KEY-FPR 3 ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> S KEY-FPR 3 ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- READKEY --card --no-data -- $SIGNKEYID
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> GETATTR SERIALNO
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S SERIALNO ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> GETATTR $SIGNKEYID
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S $SIGNKEYID OPENPGP.1
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> READKEY -- OPENPGP.1
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- [ 44 20 28 31 30 3a 70 75 62 6c 69 63 2d 6b 65 79 ...(546 byte(s) skipped) ]
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- READKEY --card --no-data -- $ENCRKEYID
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> GETATTR SERIALNO
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S SERIALNO ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> GETATTR $ENCRKEYID
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S $ENCRKEYID OPENPGP.2
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> READKEY -- OPENPGP.2
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- [ 44 20 28 31 30 3a 70 75 62 6c 69 63 2d 6b 65 79 ...(546 byte(s) skipped) ]
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- KEYINFO ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> KEYINFO --list
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S KEYINFO *** T *** OPENPGP.1 sc
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S KEYINFO *** T *** OPENPGP.2 e
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S KEYINFO *** T *** OPENPGP.3 sa
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: agent_get_cache '***'.0 (mode 2) ...
2022-08-07 21:41:33 gpg-agent[89403] DBG: ... miss
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> S KEYINFO *** T *** OPENPGP.1 - - - - A
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- RESET
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- SIGKEY ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- SETKEYDESC Please+enter+the+passphrase+to+unlock+the+OpenPGP+secret+key:%0A%22David+Xia+(personal+PGP+key)+<[email protected]>%22%0A4096-bit+RSA+key,+ID+0x5F38B0A1B60734DF,%0Acreated+2015-05-01+(main+key+ID+0x34469DFBDC90312C).%0A
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- SETHASH 10 ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 -> OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_8 <- PKSIGN
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> SERIALNO --all
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S SERIALNO ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> KEYINFO ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- S KEYINFO *** T *** OPENPGP.1 sc
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: encoded hash: *** \
2022-08-07 21:41:33 gpg-agent[89403] DBG: *** \
2022-08-07 21:41:33 gpg-agent[89403] DBG: ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> SETDATA ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- OK
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 -> PKSIGN --hash=sha512 ***
2022-08-07 21:41:33 gpg-agent[89403] DBG: chan_9 <- [ 49 4e 51 55 49 52 45 20 4e 45 45 44 50 49 4e 20 ...(88 byte(s) skipped) ]
2022-08-07 21:41:33 gpg-agent[89403] starting a new PIN Entry
2022-08-07 21:41:33 gpg-agent[89403] DBG: connection to PIN entry established
2022-08-07 21:41:33 gpg-agent[89403] You may want to update to a newer pinentry
2022-08-07 21:41:34 gpg-agent[89403] DBG: chan_9 -> [ 44 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ...(76 byte(s) skipped) ]
2022-08-07 21:41:34 gpg-agent[89403] DBG: chan_9 -> END
2022-08-07 21:41:34 gpg-agent[89403] DBG: chan_9 <- ERR 100663383 Bad PIN <SCD>
2022-08-07 21:41:34 gpg-agent[89403] smartcard signing failed: Bad PIN
2022-08-07 21:41:34 gpg-agent[89403] command 'PKSIGN' failed: Bad PIN <SCD>
2022-08-07 21:41:34 gpg-agent[89403] DBG: chan_8 -> ERR 100663383 Bad PIN <SCD>
2022-08-07 21:41:34 gpg-agent[89403] DBG: chan_8 <- [eof]
2022-08-07 21:41:34 gpg-agent[89403] DBG: chan_9 -> RESTART
2022-08-07 21:41:34 gpg-agent[89403] DBG: chan_9 <- OK
Hi, I've got the same issue. Normal key ... it works (following documentation). Key on Yubikey not.
Many thanks.
I tested it, smart cards seem to be unsupported, you only get this double PIN prompt. Since you have to enter the PIN twice every time, this is objectively worse than the normal pinentry-mac programme.
