Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

help needed: using Yubikey, no touch ID prompt, bad PIN error #20

Open
davidxia opened this issue Feb 6, 2022 · 5 comments
Open

help needed: using Yubikey, no touch ID prompt, bad PIN error #20

davidxia opened this issue Feb 6, 2022 · 5 comments

Comments

@davidxia
Copy link

davidxia commented Feb 6, 2022

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.

@ka2er
Copy link

ka2er commented Feb 8, 2022

same issue

@jorgelbg
Copy link
Owner

jorgelbg commented Aug 4, 2022

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.

@davidxia
Copy link
Author

davidxia commented Aug 8, 2022

@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)+<david@davidxia.com>%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

@whoo
Copy link

whoo commented Sep 26, 2023

Hi,
I've got the same issue.
Normal key ... it works (following documentation).
Key on Yubikey not.

image

Many thanks.

@phoerious
Copy link

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants