yubioath-flutter icon indicating copy to clipboard operation
yubioath-flutter copied to clipboard

Failed to connect to YubiKey

Open jkoch141 opened this issue 3 years ago • 11 comments

  • Yubico Authenticator version: 5.1.0
  • Operating system and version: Windows 10.0.19042
  • YubiKey model and version: YubiKey 5 NFC 5.7.2
  • Bug description summary: Yubico Authenticator is running with Yubikey plugged in. After unplugging and re-plugging the yubikey again it show the error: "Failed to connect to YubiKey". Only restart of program works

Steps to reproduce

  1. Have YubiKey plugged in
  2. Start Yubico Authenticator
  3. Observe that the OTPs are showing
  4. Unplug YubiKey
  5. Re-plug YubiKey
  6. Observe error message

Expected result

OTPs are shown again

Actual results

OTPs are not shown

jkoch141 avatar Nov 16 '21 15:11 jkoch141

Can you reproduce this every time? Furthermore, could you try running through the terminal with .\yubioath-desktop.exe --log-level DEBUG --log-file debug.txt that should create a file debug.txt that contains a debug log. You might have to run the terminal as an administrator, depending on where the file should be created. This log might contain useful information to us in order to help you.

fdennis avatar Nov 17 '21 08:11 fdennis

Hi Dennis, this happens about 90 to 95% of the time. I just did what you asked. Can I just attach the debug.txt without needing to delete/censor anything?

jkoch141 avatar Nov 17 '21 08:11 jkoch141

I am assuming you get some sort of stack trace at the very end. It would be enough for now if you just simply paste that in. In other words, we do not need to see all the SEND and RECV right now.

fdennis avatar Nov 17 '21 09:11 fdennis

Hi, here are the last lines before the SEND and RECV:

2021-11-17T09:41:27+0100 ERROR [ykman.device.list_all_devices:185] Failed opening device Traceback (most recent call last): File "C:\Program Files\Yubico\Yubico Authenticator\pymodules\ykman\device.py", line 180, in list_all_devices info = read_info(dev.pid, conn) File "C:\Program Files\Yubico\Yubico Authenticator\pymodules\ykman\device.py", line 445, in read_info info = _read_info_ccid(conn, key_type, interfaces) File "C:\Program Files\Yubico\Yubico Authenticator\pymodules\ykman\device.py", line 281, in _read_info_ccid return mgmt.read_device_info() File "C:\Program Files\Yubico\Yubico Authenticator\pymodules\yubikit\management.py", line 453, in read_device_info return DeviceInfo.parse(self.backend.read_config(), self.version) File "C:\Program Files\Yubico\Yubico Authenticator\pymodules\yubikit\management.py", line 395, in read_config return self.protocol.send_apdu(0, INS_READ_CONFIG, 0, 0) File "C:\Program Files\Yubico\Yubico Authenticator\pymodules\yubikit\core\smartcard.py", line 177, in send_apdu raise ApduError(response, sw) yubikit.core.smartcard.ApduError: APDU error: SW=0x6d00 2021-11-17T09:41:27+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:27+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:28+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:29+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:30+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:31+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:32+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:33+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:34+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:35+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:36+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:37+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:38+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:39+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:40+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:41+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:42+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:43+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:44+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:45+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:46+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:47+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:48+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:49+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:50+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:51+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:52+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:53+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:54+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:55+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:56+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:57+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}' 2021-11-17T09:41:58+0100 DEBUG [fido2.hid.windows.list_descriptors:338] Found CTAP device: b'\\?\hid#vid_1050&pid_0407&mi_01#7&b7cefbd&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}'

jkoch141 avatar Nov 17 '21 10:11 jkoch141

Thanks for providing this! Could you try unplugging and re-plugging the key several times when this happens, and see if it ever starts working again?

fdennis avatar Nov 17 '21 12:11 fdennis

Hi, here are the results:

  1. Worked
  2. Worked
  3. Recognized but no accounts shown (prompts me to add accounts)
  4. Failed to connect
  5. Failed to connect
  6. Failed to connect

Debug log is attached. debug.txt

Additionally, if I remove the via the "Safely remove" function within Windows, it also doesn't work.

jkoch141 avatar Nov 17 '21 12:11 jkoch141

FWIW I just updated to the latest yubioauth-desktop / yubico-authenticator (v5.1.0) on MacOS via Homebrew and am seeing similar behavior.

First Yubikey worked, and is seen fine through gpg-agent + scdaemon. I unplugged and plugged in a secondary Yubikey, and then the app only says "Insert your Yubikey" and is hung. Trying to quit the app results in the "spinning beachball of death" and pkill command does not exit.

Observing what is going on with the processes, and it seems that pkill -9 scdaemon command has been started by yubioauth-desktop and hung:

# Note: tmpdir & serial? scrubbed for privacy
$ sudo pstree -p 53024
Password:
-+= 00001 root /sbin/launchd
 \-+= 53024 trinitronx /private/var/folders/f0/41hvx7na83576z8379e737vx0418hv/T/AppTranslocation/CDEF012F-0123-4567-890A-BCDEF0123456/d/Yubico Authenticator.app/Contents/MacOS/yubioath-desktop
   \--- 53046 trinitronx pkill -9 scdaemon

Killing manually both scdaemon + gpg-agent un-hangs the UI so it can quit. Then not starting either gpg-agent or scdaemon (e.g.: no running gpg --card-status or similar commands) was allowing Yubico Authenticator app to function and see the Yubikey. My issue was caused by launching gpg-agent and scdaemon through running commands that needed to use the key for authentication. In the past, Yubico Authenticator has automatically managed killing the scdaemon process in the background, and appears like it's still trying to do so. However, something new is preventing that command from working properly.

So: It might be worth investigating why the pkill command was hanging. On the Windows side for the OP's issue, maybe try ensuring nothing like scdaemon has locked onto using the card?

Manual fix was running this in a terminal:

ps auxww | grep -i 'scdaemon\|gpg-agent' | grep -v grep | awk '{ print $2 }'  | xargs sudo kill -9

trinitronx avatar Nov 18 '21 00:11 trinitronx

@trinitronx Good points, thank you. It is worth pointing out that for example GPG can grab the YubiKey in exclusive mode, and thus not let go of it. Which will result in the authenticator not having access to it.

fdennis avatar Nov 18 '21 08:11 fdennis

@trinitronx Just to add to this: I have had this issue before 5.1.0 (I think the version was 5.0.5).

jkoch141 avatar Nov 18 '21 08:11 jkoch141

Hi guys, is there any update on this? Thanks!

jkoch141 avatar Jan 26 '22 12:01 jkoch141

Would be nice if this will be fixed.

Workaround for macOS:

  • install gpg-suite (gnupg don't has the required patch for shared access, it got denied upstream)
  • Add shared-access to your .gnupg/scdaemon.conf
  • restart the gpg-agent killall -9 gpg-agent

bin101 avatar Mar 30 '22 07:03 bin101

I have similar problem on macOS 12.6.1:

$ ykman list        
WARNING: Failed opening device
WARNING: Failed opening device
YubiKey 5C NFC (5.4.3) [OTP+FIDO+CCID] Serial: ****

Logs from Authenticator app:

11:01:39.994 [helper.ykman.logging] INFO: Logging at level: INFO
11:01:39.994 [helper.helper.device] INFO: Log level set to: INFO
11:01:40.152 [desktop.devices] INFO: USB state change
{"data":{"state":589520496190358251,"pids":{"1031":1}},"actions":["get","scan"],"children":{"****":{"pid":1031,"name":"YubiKey 5C NFC","serial":****}}}
11:01:45.172 [helper.helper.device] WARNING: Unable to connect via <class 'yubikit.core.smartcard.SmartCardConnection'>
Traceback (most recent call last):
  File "helper/device.py", line 293, in get_data
  File "ykman/device.py", line 257, in open_connection
  File "ykman/device.py", line 231, in connect
  File "ykman/device.py", line 231, in connect
  File "ykman/device.py", line 231, in connect
  [Previous line repeated 2 more times]
  File "ykman/device.py", line 233, in connect
ValueError: Failed to connect to the device
11:01:45.260 [desktop.devices] INFO: USB state updated, unaccounted for: {}
11:01:45.265 [helper.helper.device] WARNING: Error opening connection
Traceback (most recent call last):
  File "helper/device.py", line 302, in ccid
  File "helper/device.py", line 286, in _create_connection
  File "ykman/device.py", line 257, in open_connection
  File "ykman/device.py", line 233, in connect
ValueError: Failed to connect to the device
11:01:45.851 [about] INFO: Copying log to clipboard (6.0.0-beta.1)...

Flower7C3 avatar Nov 09 '22 09:11 Flower7C3

Similar to https://github.com/Yubico/yubioath-desktop/issues/764

Flower7C3 avatar Nov 09 '22 10:11 Flower7C3

Yubico Authenticator 6.0 has now been released and uses a new codebase. As such, this issue has been marked with the legacy label, and will be automatically closed in 7 days. If this issue is still relevant to Yubico Authenticator 6, please comment on the issue saying so, and it will be kept open (or be re-opened). Sorry for the inconvenience!

dainnilsson avatar Nov 16 '22 10:11 dainnilsson