Yubico / Yubico.NET.SDK

A YubiKey SDK for .NET developers
Apache License 2.0
96 stars 48 forks source link

8010000B SCARD_E_SHARING_VIOLATION #72

Closed DSBloom closed 1 month ago

DSBloom commented 2 months ago

Hello,

I've recently started having this error when trying to do any Yubikey operations. I see this error in the internal Yubico logging. This is a WPF app written in Dotnet 6, I am using version 1.9.1 of the SDK.

How can I find out what else us using the Yubikey? I've rebooted my machine and it didn't fix it. I don't understand why this error started popping up when my app has been working for years.

2024-04-10 09:05:40.2965 [Yubico.Core logger] INFO FindByTransport UsbSmartCard
2024-04-10 09:05:40.2965 [Yubico.Core logger] INFO Creating WindowsHidDeviceListener.
2024-04-10 09:05:40.2965 [Yubico.Core logger] INFO Registered callback with ConfigMgr32.
2024-04-10 09:05:40.2965 [Yubico.Core logger] INFO Creating DesktopSmartCardDeviceListener.
2024-04-10 09:05:40.3094 [Yubico.Core logger] INFO SCardEstablishContext called successfully.
2024-04-10 09:05:40.3094 [Yubico.Core logger] INFO SCardListReaders called successfully.
2024-04-10 09:05:40.3094 [Yubico.Core logger] INFO Creating YubiKeyDeviceListener instance.
2024-04-10 09:05:40.3094 [Yubico.Core logger] INFO Performing initial cache population.
2024-04-10 09:05:40.3094 [Yubico.Core logger] INFO Smart card listener thread started. ThreadID is 22.
2024-04-10 09:05:40.3094 [Yubico.Core logger] INFO Entering write-lock.
2024-04-10 09:05:40.3094 [Yubico.Core logger] INFO SCardGetStatusChange called successfully.
2024-04-10 09:05:40.3234 [Yubico.Core logger] INFO Reader states:
\\?PnP?\Notification: [0 : UNAWARE] => [3 : CHANGED], Alcorlink USB Smart Card Reader 0: [0 : UNAWARE] => [1 : CHANGED, PRESENT, UNPOWERED], Microsoft Virtual Smart Card 0: [0 : UNAWARE] => [1 : CHANGED, PRESENT, INUSE], Yubico Yubikey 4 U2F+CCID 0: [0 : UNAWARE] => [1 : CHANGED, PRESENT, INUSE]
2024-04-10 09:05:40.3234 [Yubico.Core logger] INFO SCardListReaders called successfully.
2024-04-10 09:05:40.3234 [Yubico.Core logger] INFO SCardGetStatusChange called successfully.
2024-04-10 09:05:40.3234 [Yubico.Core logger] INFO Reader states:
\\?PnP?\Notification: [0 : UNAWARE] => [3 : CHANGED], Alcorlink USB Smart Card Reader 0: [0 : UNAWARE] => [1 : CHANGED, PRESENT, UNPOWERED], Microsoft Virtual Smart Card 0: [0 : UNAWARE] => [1 : CHANGED, PRESENT, INUSE], Yubico Yubikey 4 U2F+CCID 0: [0 : UNAWARE] => [1 : CHANGED, PRESENT, INUSE]
2024-04-10 09:05:40.3234 [Yubico.Core logger] INFO SmartCardDevice instance created [path = Alcorlink USB Smart Card Reader 0, atr = 3B-D6-97-00-81-B1-FE-45-1F-87-80-31-C1-52-41-1A-2B]
2024-04-10 09:05:40.3234 [Yubico.Core logger] INFO SmartCardDevice instance created [path = Microsoft Virtual Smart Card 0, atr = 3B-8D-01-80-FB-A0-00-00-03-97-42-54-46-59-04-01-CF]
2024-04-10 09:05:40.3234 [Yubico.Core logger] INFO SmartCardDevice instance created [path = Yubico Yubikey 4 U2F+CCID 0, atr = 3B-F8-13-00-00-81-31-FE-15-59-75-62-69-6B-65-79-34-D4]
2024-04-10 09:05:40.3234 [Yubico.Core logger] INFO ISmartCardDevice Smart Card: Alcorlink USB Smart Card Reader 0 arrived.
2024-04-10 09:05:40.3234 [Yubico.Core logger] INFO ISmartCardDevice Smart Card: Microsoft Virtual Smart Card 0 arrived.
2024-04-10 09:05:40.3234 [Yubico.Core logger] INFO ISmartCardDevice Smart Card: Yubico Yubikey 4 U2F+CCID 0 arrived.
2024-04-10 09:05:40.3234 [Yubico.Core logger] INFO SCardEstablishContext called successfully.
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO SCardListReaders called successfully.
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO Found 3 smart card devices.
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO SCardGetStatusChange called successfully.
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO Updated SCard reader states: Alcorlink USB Smart Card Reader 0: [0 : UNAWARE] => [1 : CHANGED, PRESENT, UNPOWERED], Microsoft Virtual Smart Card 0: [0 : UNAWARE] => [1 : CHANGED, PRESENT, INUSE], Yubico Yubikey 4 U2F+CCID 0: [0 : UNAWARE] => [1 : CHANGED, PRESENT, INUSE]
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO SmartCardDevice instance created [path = Alcorlink USB Smart Card Reader 0, atr = 3B-D6-97-00-81-B1-FE-45-1F-87-80-31-C1-52-41-1A-2B]
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO SmartCardDevice instance created [path = Microsoft Virtual Smart Card 0, atr = 3B-8D-01-80-FB-A0-00-00-03-97-42-54-46-59-04-01-CF]
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO SmartCardDevice instance created [path = Yubico Yubikey 4 U2F+CCID 0, atr = 3B-F8-13-00-00-81-31-FE-15-59-75-62-69-6B-65-79-34-D4]
2024-04-10 09:05:40.3389 [Yubico.Core logger] WARN SDK running in an un-elevated Windows process. Skipping FIDO enumeration as this requires process elevation.
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO Found 0 HID Keyboard devices, 0 HID FIDO devices, and 1 Smart Card devices for processing.
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO Cache currently aware of 0 YubiKeys.
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO Processing device Smart Card: Yubico Yubikey 4 U2F+CCID 0
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO Getting device info for smart card Smart Card: Yubico Yubikey 4 U2F+CCID 0.
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO Attempting to read device info via the management application.
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO SCardEstablishContext called successfully.
2024-04-10 09:05:40.3389 [Yubico.Core logger] ERROR SCardConnect called and FAILED. Result = 8010000B SCARD_E_SHARING_VIOLATION: The smart card cannot be accessed because of other outstanding connections.
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO Context disposed.
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO CardHandle disposed.
2024-04-10 09:05:40.3389 [Yubico.Core logger] ERROR Encountered a YubiKey but was unable to connect to it. This interface will be ignored.
2024-04-10 09:05:40.3389 [Yubico.Core logger] INFO Exiting write-lock.
2024-04-10 09:05:40.3565 [Yubico.Core logger] INFO YubiKey device listener thread started. ThreadID is 23.
DennisDyallo commented 2 months ago

There's an ongoing discussion to improve the disposing of the Yubikey connection and the thread that manages it. To me it's odd that it has only started happening to you recently. Perhaps @GregDomzalski @jamiehankins might have some additional insight.

GregDomzalski commented 2 months ago

Yeah - I had, perhaps rather short-sightedly, switched our handle opening for smart cards to be exclusive. This was to combat the Windows smart card stack (i.e. minidrivers) from coming and yanking the connection out from under us. This behavior was introduced in 1.9.1. Downgrading to 1.9.0 would resolve this issue for you. Unfortunately 1.10.0 just shipped with this same behavior in tact. We should probably consider reverting that one change or putting it behind an AppContext switch to toggle the behavior and releasing a 1.10.1 so folks can continue to track the latest release.

But in reality, a better, longer term fix is probably for us to always select the smart card app at the beginning of each transaction. That would prevent the previously observed behavior of "invalid command" being thrown later on after Windows has essentially switched the YubiKey to PIV away from whatever you were doing at that moment. I still haven't thought through all of the implications of doing that w.r.t. any state being tracked by the YubiKey. And still, the issue that remains that we don't really have a great way to block PIV activation if you are using a different USB interface like FIDO or OTP...