Bug 2203272 - GPG not picking up Yubikeys set in shared mode
Summary: GPG not picking up Yubikeys set in shared mode
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Fedora
Classification: Fedora
Component: gnupg2
Version: 38
Hardware: x86_64
OS: Linux
low
high
Target Milestone: ---
Assignee: Jakub Jelen
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2023-05-11 17:23 UTC by John
Modified: 2024-01-09 09:56 UTC (History)
5 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2024-01-09 09:56:17 UTC
Type: ---
Embargoed:
fedora-admin-xmlrpc: mirror+


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker FC-836 0 None None None 2023-05-11 17:24:41 UTC

Description John 2023-05-11 17:23:32 UTC
GnuPG is not picking up Yubikeys that run in Shared mode, it only works briefly after restart pcscd but after replug you need to restart pcscd again.  This does not occur with Yubikeys that run in exclusive mode, those work just fine.

Can this be a regression?

Reproducible: Always

Steps to Reproduce:
1. Connect the Yubikey
2. Make sure it's in exclusive mode with *pcsc_scan*
3. Enable PIV with ykman if it's not in shared mode: ykman config usb --enable PIV
4. Reconnect the Yubikey
5. The card will not be recognized
6. Disable PIV ykman config usb --disable PIV and reconnect the yubikey
7. It will be recognized again and be set in exclusive mode

Comment 1 Jakub Jelen 2023-05-15 09:37:58 UTC
Hard to say. I would need some debug logs from pcscd or pcsc spy to see what is going on there.

I can just assume that either of the applications sill requests the exclusive mode, which prevents any other application to access the device.

Comment 2 John 2023-05-15 10:02:34 UTC
I'll see if I can find a Yubikey i can turn into shared mode again. The one I set to exclusive mode is not willing to enable the PIV module again sadly. How do I get debug logs from pcscd? Systemctl doesn't show that logging last time I checked the status.

Comment 3 John 2023-05-15 10:04:58 UTC
Managed to set a Yubikey to shared mode

Comment 4 John 2023-05-15 10:14:33 UTC
Bingo, looks like pcscd is throwing a SCARD_E_SHARING_VIOLATION error when GPG is trying to access the smartcard.

00671331 winscard_msg_srv.c:256:ProcessEventsServer() Common channel packet arrival
00000020 winscard_msg_srv.c:267:ProcessEventsServer() ProcessCommonChannelRequest detects: 15
00000003 pcscdaemon.c:133:SVCServiceRunLoop() A new context thread creation is requested: 15
00017256 winscard_svc.c:340:ContextThread() Authorized PC/SC client
00000008 winscard_svc.c:343:ContextThread() Thread is started: dwClientID=15, threadContext @0x55da8807d890
00000011 winscard_svc.c:361:ContextThread() Received command: CMD_VERSION from client 15
00000006 winscard_svc.c:373:ContextThread() Client is protocol version 4:4
00000003 winscard_svc.c:396:ContextThread() CMD_VERSION for client 15, rv=SCARD_S_SUCCESS
00000095 winscard_svc.c:361:ContextThread() Received command: ESTABLISH_CONTEXT from client 15
00000015 winscard.c:215:SCardEstablishContext() Establishing Context: 0x79B96A4F
00000004 winscard_svc.c:465:ContextThread() ESTABLISH_CONTEXT for client 15, rv=SCARD_S_SUCCESS
00000136 winscard_svc.c:361:ContextThread() Received command: CMD_GET_READERS_STATE from client 15
00000112 winscard_svc.c:361:ContextThread() Received command: CMD_GET_READERS_STATE from client 15
00000100 winscard_svc.c:361:ContextThread() Received command: CONNECT from client 15
00010005 winscard_svc.c:503:ContextThread() Authorized client for 'Yubico YubiKey OTP+FIDO+CCID 00 00'
00000005 winscard.c:258:SCardConnect() Attempting Connect to Yubico YubiKey OTP+FIDO+CCID 00 00 using protocol: 3
00000002 readerfactory.c:839:RFReaderInfo() RefReader() count was: 1
00000001 winscard.c:352:SCardConnect() powerState: POWER_STATE_IN_USE
00000002 winscard.c:430:SCardConnect() Active Protocol: T=1
00000003 winscard.c:456:SCardConnect() hCard Identity: 4ef1dda6
00000002 winscard.c:518:SCardConnect() UnrefReader() count was: 2
00000001 winscard_svc.c:523:ContextThread() CONNECT for client 15, rv=SCARD_E_SHARING_VIOLATION
00000172 winscard_svc.c:361:ContextThread() Received command: RELEASE_CONTEXT from client 15
00000010 winscard.c:229:SCardReleaseContext() Releasing Context: 0x79B96A4F
00000004 winscard_svc.c:480:ContextThread() RELEASE_CONTEXT for client 15, rv=SCARD_S_SUCCESS
00000036 winscard_svc.c:354:ContextThread() Client die: 15
00000015 winscard_svc.c:1071:MSGCleanupClient() Thread is stopping: dwClientID=15, threadContext @0x55da8807d890
00000003 winscard_svc.c:1079:MSGCleanupClient() Freeing SCONTEXT @0x55da8807d890

Comment 5 John 2023-05-15 10:16:07 UTC
Also adding pcsc-shared to the scdaemon.config is a workaround for this, but it keeps reprompting for the pin code with every operation instead of the default behaviour of caching it.

Comment 6 John 2023-05-15 10:19:54 UTC
These are the logs from the test with pcsc-shared setting on in scdaemon.conf

00000020 winscard_svc.c:694:ContextThread() TRANSMIT for client 15, rv=SCARD_S_SUCCESS
00000502 winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 15
00000019 winscard_svc.c:842:MSGSendReaderStates() Send reader states: 15
00001192 winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 15
00000020 winscard_svc.c:445:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE for client 15, rv=SCARD_S_SUCCESS
00000207 winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 15
00000018 winscard_svc.c:842:MSGSendReaderStates() Send reader states: 15
00000194 winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 15
00000020 winscard_svc.c:445:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE for client 15, rv=SCARD_S_SUCCESS
00000701 winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 15

❯ cat ~/.gnupg/scdaemon.conf
pcsc-shared

Comment 7 John 2023-05-15 18:22:03 UTC
I have full logs for yubikeys in shared and exclusive mode

https://share.riseup.net/#Ju4slvAqXLG09IStmwhXxA -> The logs for a key running in exclusive mode
https://share.riseup.net/#oxoyC2CdrCRna8zVCWM4JA -> The logs for a key running in shared mode

Testing methodology was plugging the Yubikeys, starting pcscd with foreground logging and running gpg --card-status when the pcscd service was up and running.

Comment 8 Heiko Schaefer 2023-05-30 16:24:53 UTC
@John, could it be that another process is grabbing the card on your system? My first suspect would be browsers.

In the "scdaemon stuck" state, you could try killing firefox/chrome* and see if that helps scdaemon get access to the card.

Comment 9 John 2023-05-30 16:34:31 UTC
Tried doing as suggested closed every application that could grab the card except for GPG and found the current error recurring in the logs when trying to access the card with gpg --card-status.

00008414 [139925683812032] winscard_svc.c:503:ContextThread() Authorized client for 'Yubico YubiKey OTP+FIDO+CCID 00 00'
00000007 [139925683812032] winscard.c:258:SCardConnect() Attempting Connect to Yubico YubiKey OTP+FIDO+CCID 00 00 using protocol: 3
00000004 [139925683812032] readerfactory.c:839:RFReaderInfo() RefReader() count was: 1
00000004 [139925683812032] winscard.c:352:SCardConnect() powerState: POWER_STATE_IN_USE
00000004 [139925683812032] winscard.c:430:SCardConnect() Active Protocol: T=1
00000004 [139925683812032] winscard.c:456:SCardConnect() hCard Identity: 21de3d04
00000002 [139925683812032] winscard.c:518:SCardConnect() UnrefReader() count was: 2
00000002 [139925683812032] winscard_svc.c:523:ContextThread() CONNECT for client 15, rv=SCARD_E_SHARING_VIOLATION

Comment 10 John 2023-11-20 16:49:58 UTC
Issue can be closed, somewhat incosistent in F39 but that's due to other issues on which I will report a seperate bug report for.

Comment 11 John 2023-11-20 17:07:38 UTC
Small update: traced it back to user error, all is fine now.

Comment 12 Jakub Jelen 2024-01-09 09:56:17 UTC
Closing as described in the previous comments. Not a gnupg2 error. Not sure what was the thing that was wrong on your side, but if you can comment on that, it might help others with similar issues.


Note You need to log in before you can comment on or make changes to this bug.