search

Yubico / yubikey-manager

Python library and command line tool for configuring any YubiKey over all USB interfaces.
https://developers.yubico.com/yubikey-manager/
BSD 2-Clause "Simplified" License
879 stars 126 forks source link

ykman fails to connect to yubikey if other device present #500

Closed jhogendorn closed 2 years ago

jhogendorn commented 2 years ago

Steps to reproduce

  1. run ykman oath account code <id>
  2. no prompt to touch yubikey, few second wait
  3. get Error: No YubiKey found with the given interface(s)
  4. Open Yubico Authenticator GUI, it recognises the device but 'no accounts found'
  5. Google for a bit, no results that match, mostly talking about crashed support services.
  6. Be stumped, wonder if its died or a version got bumped or macos is doing something weird and blocking the key for security.
  7. Realise theres a debug flag for the command, run it.
  8. Go back and forth for a bit. Wonder why theres 2 different device id's in the debug log.
  9. Realise you have the ledger plugged in, unplug
  10. Test again, same error
  11. Unplug and replug the yubikey
  12. Test again, everything comes up milhouse
  13. Log ticket so that someone else has a google hit, even if this is 'out of scope' and gets a 'wontfix'

Expected result

  1. run ykman oath account code <id>
  2. be prompted to touch yubikey
  3. recieve OTP code

Actual results and logs

With two devices:

ykman --log-level DEBUG oath accounts list
2022-04-21T11:21:33+1000 INFO [ykman.logging_setup.setup:76] Initialized logging for level: DEBUG
2022-04-21T11:21:33+1000 INFO [ykman.logging_setup.setup:77] Running ykman version: 4.0.8
2022-04-21T11:21:33+1000 DEBUG [ykman.logging_setup.log_sys_info:48] Python: 3.10.2 (main, Feb  2 2022, 08:42:42) [Clang 13.0.0 (clang-1300.0.29.3)]
2022-04-21T11:21:33+1000 DEBUG [ykman.logging_setup.log_sys_info:49] Platform: darwin
2022-04-21T11:21:33+1000 DEBUG [ykman.logging_setup.log_sys_info:50] Arch: x86_64
2022-04-21T11:21:33+1000 DEBUG [ykman.logging_setup.log_sys_info:56] Running as admin: False
2022-04-21T11:21:33+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295597732
2022-04-21T11:21:33+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:21:33+1000 ERROR [ykman.cli.__main__.retrying_connect:102] Failed opening connection
Traceback (most recent call last):
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 97, in retrying_connect
    return connect_to_device(serial, connections)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/device.py", line 249, in connect_to_device
    raise ValueError("No YubiKey found with the given interface(s)")
ValueError: No YubiKey found with the given interface(s)
2022-04-21T11:21:33+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295597732
2022-04-21T11:21:33+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:21:34+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295597732
2022-04-21T11:21:34+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:21:34+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:21:34+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295597732
2022-04-21T11:21:34+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295597732
2022-04-21T11:21:34+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:21:34+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295597732
2022-04-21T11:21:34+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:21:35+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295597732
2022-04-21T11:21:35+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:21:35+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295597732
2022-04-21T11:21:35+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:21:35+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:21:35+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295597732
2022-04-21T11:21:35+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:21:35+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295597732
2022-04-21T11:21:36+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295597732
2022-04-21T11:21:36+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:21:36+1000 ERROR [ykman.cli.__main__.main:386] Error
Traceback (most recent call last):
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 104, in retrying_connect
    _, state = _scan_changes(state)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 91, in _scan_changes
    raise TimeoutError("Timed out waiting for state change")
TimeoutError: Timed out waiting for state change

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 378, in main
    cli(obj={})
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1128, in __call__
    return self.main(*args, **kwargs)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1053, in main
    rv = self.invoke(ctx)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1395, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 754, in invoke
    return __callback(*args, **kwargs)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/decorators.py", line 26, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/oath.py", line 540, in list
    _init_session(ctx, password, remember)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/oath.py", line 155, in _init_session
    session = ctx.obj["session"]
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/util.py", line 164, in __getitem__
    self.resolve()
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/util.py", line 161, in resolve
    self._objects[k] = f()
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 306, in <lambda>
    ctx.obj.add_resolver("conn", lambda: resolve()[0])
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 301, in resolve
    items = _run_cmd_for_single(ctx, subcmd.name, connections, reader)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 197, in _run_cmd_for_single
    return retrying_connect(None, connections, state=state)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 107, in retrying_connect
    raise e
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 97, in retrying_connect
    return connect_to_device(serial, connections)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/device.py", line 249, in connect_to_device
    raise ValueError("No YubiKey found with the given interface(s)")
ValueError: No YubiKey found with the given interface(s)
Error: No YubiKey found with the given interface(s)

After removal of second device but before replugging the yubikey

ykman --log-level DEBUG oath accounts list
2022-04-21T11:22:22+1000 INFO [ykman.logging_setup.setup:76] Initialized logging for level: DEBUG
2022-04-21T11:22:22+1000 INFO [ykman.logging_setup.setup:77] Running ykman version: 4.0.8
2022-04-21T11:22:22+1000 DEBUG [ykman.logging_setup.log_sys_info:48] Python: 3.10.2 (main, Feb  2 2022, 08:42:42) [Clang 13.0.0 (clang-1300.0.29.3)]
2022-04-21T11:22:22+1000 DEBUG [ykman.logging_setup.log_sys_info:49] Platform: darwin
2022-04-21T11:22:22+1000 DEBUG [ykman.logging_setup.log_sys_info:50] Arch: x86_64
2022-04-21T11:22:22+1000 DEBUG [ykman.logging_setup.log_sys_info:56] Running as admin: False
2022-04-21T11:22:22+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:22:22+1000 ERROR [ykman.cli.__main__.retrying_connect:102] Failed opening connection
Traceback (most recent call last):
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 97, in retrying_connect
    return connect_to_device(serial, connections)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/device.py", line 249, in connect_to_device
    raise ValueError("No YubiKey found with the given interface(s)")
ValueError: No YubiKey found with the given interface(s)
2022-04-21T11:22:22+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:22:23+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:22:23+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:22:23+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:22:23+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:22:24+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:22:24+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:22:24+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:22:24+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:22:25+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4295827557
2022-04-21T11:22:25+1000 ERROR [ykman.cli.__main__.main:386] Error
Traceback (most recent call last):
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 104, in retrying_connect
    _, state = _scan_changes(state)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 91, in _scan_changes
    raise TimeoutError("Timed out waiting for state change")
TimeoutError: Timed out waiting for state change

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 378, in main
    cli(obj={})
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1128, in __call__
    return self.main(*args, **kwargs)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1053, in main
    rv = self.invoke(ctx)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1395, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 754, in invoke
    return __callback(*args, **kwargs)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/decorators.py", line 26, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/oath.py", line 540, in list
    _init_session(ctx, password, remember)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/oath.py", line 155, in _init_session
    session = ctx.obj["session"]
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/util.py", line 164, in __getitem__
    self.resolve()
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/util.py", line 161, in resolve
    self._objects[k] = f()
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 306, in <lambda>
    ctx.obj.add_resolver("conn", lambda: resolve()[0])
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 301, in resolve
    items = _run_cmd_for_single(ctx, subcmd.name, connections, reader)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 197, in _run_cmd_for_single
    return retrying_connect(None, connections, state=state)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 107, in retrying_connect
    raise e
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 97, in retrying_connect
    return connect_to_device(serial, connections)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/device.py", line 249, in connect_to_device
    raise ValueError("No YubiKey found with the given interface(s)")
ValueError: No YubiKey found with the given interface(s)
Error: No YubiKey found with the given interface(s)

Other info

I don't mind if this gets a wontfix or immediately closed, mostly posting for google hits for other poor souls. But it could give a smarter error message perhaps?

dainnilsson commented 2 years ago

Can you run ykman --diagnose once with both devices connected and once with just the YubiKey and paste the output of those runs? From your logs it looks like ykman is unable to access the YubiKey over the CCID transport while the Ledger is connected, but I'm not sure what would cause that.

jhogendorn commented 2 years ago

Run 3 times, once with just yubikey, once with ledger plugged in locked, and then unlocked.

I ran ykman --log-level DEBUG oath accounts list again and did not replicate the issue, so there must be some other factor in this bug.

Usb info from system information

YubiKey OTP+FIDO+CCID:

  Product ID:   0x0407
  Vendor ID:    0x1050
  Version:  5.27
  Speed:    Up to 12 Mb/s
  Manufacturer: Yubico
  Location ID:  0x14300000 / 1
  Current Available (mA):   500
  Current Required (mA):    30
  Extra Operating Current (mA): 0
Nano X:

  Product ID:   0x4011
  Vendor ID:    0x2c97
  Version:  2.01
  Serial Number:    0001
  Speed:    Up to 12 Mb/s
  Manufacturer: Ledger
  Location ID:  0x01244100 / 13
  Current Available (mA):   500
  Current Required (mA):    100
  Extra Operating Current (mA): 0
❯ ykman --diagnose
ykman: 4.0.8
Python: 3.10.2 (main, Feb  2 2022, 08:42:42) [Clang 13.0.0 (clang-1300.0.29.3)]
Platform: darwin
Arch: x86_64
Running as admin: False

Detected PC/SC readers:
    Yubico YubiKey OTP+FIDO+CCID (connect: Success)

Detected YubiKeys over PC/SC:
    ScardYubiKeyDevice(pid=0407, fingerprint='Yubico YubiKey OTP+FIDO+CCID')
    RawInfo: 260102023f0302023f020400f3751704010405030502070602000007010f0801000a01000f0100
    DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, auto_eject_timeout=0, challenge_response_timeout=15, device_flags=<DEVICE_FLAG.0: 0>), serial=15955223, version=Version(major=5, minor=2, patch=7), form_factor=<FORM_FACTOR.USB_C_NANO: 4>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, is_locked=False, is_fips=False, is_sky=False)
    Device name: YubiKey 5C Nano
    PIV
        PIV version: 5.2.7
        PIN tries remaining: 3
        Management key algorithm: TDES
        CHUID:  No data available.
        CCC:    No data available.
    OATH
        Oath version: 5.2.7
        Password protected: False
    OpenPGP
        OpenPGP version: 3.4
        Application version: 5.2.7
        PIN tries remaining: 3
        Reset code tries remaining: 0
        Admin PIN tries remaining: 3
        Touch policies
        Signature key           Off
        Encryption key          Off
        Authentication key      Off
        Attestation key         Off

Detected YubiKeys over HID OTP:
    OtpYubiKeyDevice(pid=0407, fingerprint='4295829924')
    RawInfo: 260102023f0302023f020400f3751704010405030502070602000007010f0801000a01000f0100
    DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, auto_eject_timeout=0, challenge_response_timeout=15, device_flags=<DEVICE_FLAG.0: 0>), serial=15955223, version=Version(major=5, minor=2, patch=7), form_factor=<FORM_FACTOR.USB_C_NANO: 4>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, is_locked=False, is_fips=False, is_sky=False)
    Device name: YubiKey 5C Nano
    OTP: ConfigState(configured: (False, True), touch_triggered: (False, True), led_inverted: False)

Detected YubiKeys over HID FIDO:
    CtapYubiKeyDevice(pid=0407, fingerprint='4295829928')
CTAP device version: 5.2.7
CTAPHID protocol version: 2
Capabilities: 5
    RawInfo: 260102023f0302023f020400f3751704010405030502070602000007010f0801000a01000f0100
    DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, auto_eject_timeout=0, challenge_response_timeout=15, device_flags=<DEVICE_FLAG.0: 0>), serial=15955223, version=Version(major=5, minor=2, patch=7), form_factor=<FORM_FACTOR.USB_C_NANO: 4>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, is_locked=False, is_fips=False, is_sky=False)
    Device name: YubiKey 5C Nano
    Ctap2Info: {<VERSIONS: 0x01>: ['U2F_V2', 'FIDO_2_0', 'FIDO_2_1_PRE'], <EXTENSIONS: 0x02>: ['credProtect', 'hmac-secret'], <AAGUID: 0x03>: b'\xee\x88(yr\x1cI\x13\x97u=\xfc\xce\x97\x07*', <OPTIONS: 0x04>: {'rk': True, 'up': True, 'plat': False, 'clientPin': False, 'credentialMgmtPreview': True}, <MAX_MSG_SIZE: 0x05>: 1200, <PIN_UV_PROTOCOLS: 0x06>: [1], <MAX_CREDS_IN_LIST: 0x07>: 8, <MAX_CRED_ID_LENGTH: 0x08>: 128, <TRANSPORTS: 0x09>: ['usb'], <ALGORITHMS: 0x0A>: [{'alg': -7, 'type': 'public-key'}, {'alg': -8, 'type': 'public-key'}]}
PIN: Not configured

End of diagnostics
❯ ykman --diagnose
ykman: 4.0.8
Python: 3.10.2 (main, Feb  2 2022, 08:42:42) [Clang 13.0.0 (clang-1300.0.29.3)]
Platform: darwin
Arch: x86_64
Running as admin: False

Detected PC/SC readers:
    Yubico YubiKey OTP+FIDO+CCID (connect: Success)

Detected YubiKeys over PC/SC:
    ScardYubiKeyDevice(pid=0407, fingerprint='Yubico YubiKey OTP+FIDO+CCID')
    RawInfo: 260102023f0302023f020400f3751704010405030502070602000007010f0801000a01000f0100
    DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, auto_eject_timeout=0, challenge_response_timeout=15, device_flags=<DEVICE_FLAG.0: 0>), serial=15955223, version=Version(major=5, minor=2, patch=7), form_factor=<FORM_FACTOR.USB_C_NANO: 4>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, is_locked=False, is_fips=False, is_sky=False)
    Device name: YubiKey 5C Nano
    PIV
        PIV version: 5.2.7
        PIN tries remaining: 3
        Management key algorithm: TDES
        CHUID:  No data available.
        CCC:    No data available.
    OATH
        Oath version: 5.2.7
        Password protected: False
    OpenPGP
        OpenPGP version: 3.4
        Application version: 5.2.7
        PIN tries remaining: 3
        Reset code tries remaining: 0
        Admin PIN tries remaining: 3
        Touch policies
        Signature key           Off
        Encryption key          Off
        Authentication key      Off
        Attestation key         Off

Detected YubiKeys over HID OTP:
    OtpYubiKeyDevice(pid=0407, fingerprint='4295829924')
    RawInfo: 260102023f0302023f020400f3751704010405030502070602000007010f0801000a01000f0100
    DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, auto_eject_timeout=0, challenge_response_timeout=15, device_flags=<DEVICE_FLAG.0: 0>), serial=15955223, version=Version(major=5, minor=2, patch=7), form_factor=<FORM_FACTOR.USB_C_NANO: 4>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, is_locked=False, is_fips=False, is_sky=False)
    Device name: YubiKey 5C Nano
    OTP: ConfigState(configured: (False, True), touch_triggered: (False, True), led_inverted: False)

Detected YubiKeys over HID FIDO:
    CtapYubiKeyDevice(pid=0407, fingerprint='4295829928')
CTAP device version: 5.2.7
CTAPHID protocol version: 2
Capabilities: 5
    RawInfo: 260102023f0302023f020400f3751704010405030502070602000007010f0801000a01000f0100
    DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, auto_eject_timeout=0, challenge_response_timeout=15, device_flags=<DEVICE_FLAG.0: 0>), serial=15955223, version=Version(major=5, minor=2, patch=7), form_factor=<FORM_FACTOR.USB_C_NANO: 4>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, is_locked=False, is_fips=False, is_sky=False)
    Device name: YubiKey 5C Nano
    Ctap2Info: {<VERSIONS: 0x01>: ['U2F_V2', 'FIDO_2_0', 'FIDO_2_1_PRE'], <EXTENSIONS: 0x02>: ['credProtect', 'hmac-secret'], <AAGUID: 0x03>: b'\xee\x88(yr\x1cI\x13\x97u=\xfc\xce\x97\x07*', <OPTIONS: 0x04>: {'rk': True, 'up': True, 'plat': False, 'clientPin': False, 'credentialMgmtPreview': True}, <MAX_MSG_SIZE: 0x05>: 1200, <PIN_UV_PROTOCOLS: 0x06>: [1], <MAX_CREDS_IN_LIST: 0x07>: 8, <MAX_CRED_ID_LENGTH: 0x08>: 128, <TRANSPORTS: 0x09>: ['usb'], <ALGORITHMS: 0x0A>: [{'alg': -7, 'type': 'public-key'}, {'alg': -8, 'type': 'public-key'}]}
PIN: Not configured

End of diagnostics
❯ ykman --diagnose
ykman: 4.0.8
Python: 3.10.2 (main, Feb  2 2022, 08:42:42) [Clang 13.0.0 (clang-1300.0.29.3)]
Platform: darwin
Arch: x86_64
Running as admin: False

Detected PC/SC readers:
    Yubico YubiKey OTP+FIDO+CCID (connect: Success)

Detected YubiKeys over PC/SC:
    ScardYubiKeyDevice(pid=0407, fingerprint='Yubico YubiKey OTP+FIDO+CCID')
    RawInfo: 260102023f0302023f020400f3751704010405030502070602000007010f0801000a01000f0100
    DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, auto_eject_timeout=0, challenge_response_timeout=15, device_flags=<DEVICE_FLAG.0: 0>), serial=15955223, version=Version(major=5, minor=2, patch=7), form_factor=<FORM_FACTOR.USB_C_NANO: 4>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, is_locked=False, is_fips=False, is_sky=False)
    Device name: YubiKey 5C Nano
    PIV
        PIV version: 5.2.7
        PIN tries remaining: 3
        Management key algorithm: TDES
        CHUID:  No data available.
        CCC:    No data available.
    OATH
        Oath version: 5.2.7
        Password protected: False
    OpenPGP
        OpenPGP version: 3.4
        Application version: 5.2.7
        PIN tries remaining: 3
        Reset code tries remaining: 0
        Admin PIN tries remaining: 3
        Touch policies
        Signature key           Off
        Encryption key          Off
        Authentication key      Off
        Attestation key         Off

Detected YubiKeys over HID OTP:
    OtpYubiKeyDevice(pid=0407, fingerprint='4295829924')
    RawInfo: 260102023f0302023f020400f3751704010405030502070602000007010f0801000a01000f0100
    DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, auto_eject_timeout=0, challenge_response_timeout=15, device_flags=<DEVICE_FLAG.0: 0>), serial=15955223, version=Version(major=5, minor=2, patch=7), form_factor=<FORM_FACTOR.USB_C_NANO: 4>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, is_locked=False, is_fips=False, is_sky=False)
    Device name: YubiKey 5C Nano
    OTP: ConfigState(configured: (False, True), touch_triggered: (False, True), led_inverted: False)

Detected YubiKeys over HID FIDO:
    CtapYubiKeyDevice(pid=0407, fingerprint='4295829928')
CTAP device version: 5.2.7
CTAPHID protocol version: 2
Capabilities: 5
    RawInfo: 260102023f0302023f020400f3751704010405030502070602000007010f0801000a01000f0100
    DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, auto_eject_timeout=0, challenge_response_timeout=15, device_flags=<DEVICE_FLAG.0: 0>), serial=15955223, version=Version(major=5, minor=2, patch=7), form_factor=<FORM_FACTOR.USB_C_NANO: 4>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, is_locked=False, is_fips=False, is_sky=False)
    Device name: YubiKey 5C Nano
    Ctap2Info: {<VERSIONS: 0x01>: ['U2F_V2', 'FIDO_2_0', 'FIDO_2_1_PRE'], <EXTENSIONS: 0x02>: ['credProtect', 'hmac-secret'], <AAGUID: 0x03>: b'\xee\x88(yr\x1cI\x13\x97u=\xfc\xce\x97\x07*', <OPTIONS: 0x04>: {'rk': True, 'up': True, 'plat': False, 'clientPin': False, 'credentialMgmtPreview': True}, <MAX_MSG_SIZE: 0x05>: 1200, <PIN_UV_PROTOCOLS: 0x06>: [1], <MAX_CREDS_IN_LIST: 0x07>: 8, <MAX_CRED_ID_LENGTH: 0x08>: 128, <TRANSPORTS: 0x09>: ['usb'], <ALGORITHMS: 0x0A>: [{'alg': -7, 'type': 'public-key'}, {'alg': -8, 'type': 'public-key'}]}
PIN: Not configured

End of diagnostics
dainnilsson commented 2 years ago

From the diagnostics output it looks like everything is working fine (for all 3 runs), and if I understood your comment correctly you no longer see the original issue? Strange, but at least it seems to work now. I'll close the issue and hope you don't run into it again!

jhogendorn commented 2 years ago

managed to trigger it again, however this time no other usb device was plugged in.

ykman --log-level DEBUG oath accounts list
2022-05-03T17:30:12+1000 INFO [ykman.logging_setup.setup:76] Initialized logging for level: DEBUG
2022-05-03T17:30:12+1000 INFO [ykman.logging_setup.setup:77] Running ykman version: 4.0.8
2022-05-03T17:30:12+1000 DEBUG [ykman.logging_setup.log_sys_info:48] Python: 3.10.4 (main, Apr 26 2022, 19:43:24) [Clang 13.0.0 (clang-1300.0.29.30)]
2022-05-03T17:30:12+1000 DEBUG [ykman.logging_setup.log_sys_info:49] Platform: darwin
2022-05-03T17:30:12+1000 DEBUG [ykman.logging_setup.log_sys_info:50] Arch: x86_64
2022-05-03T17:30:12+1000 DEBUG [ykman.logging_setup.log_sys_info:56] Running as admin: False
2022-05-03T17:30:12+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4294969664
2022-05-03T17:30:12+1000 ERROR [ykman.cli.__main__.retrying_connect:102] Failed opening connection
Traceback (most recent call last):
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 97, in retrying_connect
    return connect_to_device(serial, connections)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/device.py", line 249, in connect_to_device
    raise ValueError("No YubiKey found with the given interface(s)")
ValueError: No YubiKey found with the given interface(s)
2022-05-03T17:30:12+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4294969664
2022-05-03T17:30:13+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4294969664
2022-05-03T17:30:13+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4294969664
2022-05-03T17:30:13+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4294969664
2022-05-03T17:30:14+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4294969664
2022-05-03T17:30:14+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4294969664
2022-05-03T17:30:14+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4294969664
2022-05-03T17:30:14+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4294969664
2022-05-03T17:30:15+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4294969664
2022-05-03T17:30:15+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4294969664
2022-05-03T17:30:15+1000 ERROR [ykman.cli.__main__.main:386] Error
Traceback (most recent call last):
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 104, in retrying_connect
    _, state = _scan_changes(state)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 91, in _scan_changes
    raise TimeoutError("Timed out waiting for state change")
TimeoutError: Timed out waiting for state change

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 378, in main
    cli(obj={})
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1128, in __call__
    return self.main(*args, **kwargs)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1053, in main
    rv = self.invoke(ctx)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 1395, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/core.py", line 754, in invoke
    return __callback(*args, **kwargs)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/click/decorators.py", line 26, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/oath.py", line 540, in list
    _init_session(ctx, password, remember)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/oath.py", line 155, in _init_session
    session = ctx.obj["session"]
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/util.py", line 164, in __getitem__
    self.resolve()
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/util.py", line 161, in resolve
    self._objects[k] = f()
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 306, in <lambda>
    ctx.obj.add_resolver("conn", lambda: resolve()[0])
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 301, in resolve
    items = _run_cmd_for_single(ctx, subcmd.name, connections, reader)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 197, in _run_cmd_for_single
    return retrying_connect(None, connections, state=state)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 107, in retrying_connect
    raise e
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/cli/__main__.py", line 97, in retrying_connect
    return connect_to_device(serial, connections)
  File "/usr/local/Cellar/ykman/4.0.8_1/libexec/lib/python3.10/site-packages/ykman/device.py", line 249, in connect_to_device
    raise ValueError("No YubiKey found with the given interface(s)")
ValueError: No YubiKey found with the given interface(s)
Error: No YubiKey found with the given interface(s)
❯ ykman --diagnose
ykman: 4.0.8
Python: 3.10.4 (main, Apr 26 2022, 19:43:24) [Clang 13.0.0 (clang-1300.0.29.30)]
Platform: darwin
Arch: x86_64
Running as admin: False

Detected PC/SC readers:

Detected YubiKeys over PC/SC:

Detected YubiKeys over HID OTP:
    OtpYubiKeyDevice(pid=0407, fingerprint='4294969713')
    RawInfo: 260102023f0302023f020400f3751704010405030502070602000007010f0801000a01000f0100
    DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, auto_eject_timeout=0, challenge_response_timeout=15, device_flags=<DEVICE_FLAG.0: 0>), serial=15955223, version=Version(major=5, minor=2, patch=7), form_factor=<FORM_FACTOR.USB_C_NANO: 4>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, is_locked=False, is_fips=False, is_sky=False)
    Device name: YubiKey 5C Nano
    OTP: ConfigState(configured: (False, True), touch_triggered: (False, True), led_inverted: False)

Detected YubiKeys over HID FIDO:
    CtapYubiKeyDevice(pid=0407, fingerprint='4294969664')
CTAP device version: 5.2.7
CTAPHID protocol version: 2
Capabilities: 5
    RawInfo: 260102023f0302023f020400f3751704010405030502070602000007010f0801000a01000f0100
    DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, auto_eject_timeout=0, challenge_response_timeout=15, device_flags=<DEVICE_FLAG.0: 0>), serial=15955223, version=Version(major=5, minor=2, patch=7), form_factor=<FORM_FACTOR.USB_C_NANO: 4>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, is_locked=False, is_fips=False, is_sky=False)
    Device name: YubiKey 5C Nano
    Ctap2Info: {<VERSIONS: 0x01>: ['U2F_V2', 'FIDO_2_0', 'FIDO_2_1_PRE'], <EXTENSIONS: 0x02>: ['credProtect', 'hmac-secret'], <AAGUID: 0x03>: b'\xee\x88(yr\x1cI\x13\x97u=\xfc\xce\x97\x07*', <OPTIONS: 0x04>: {'rk': True, 'up': True, 'plat': False, 'clientPin': False, 'credentialMgmtPreview': True}, <MAX_MSG_SIZE: 0x05>: 1200, <PIN_UV_PROTOCOLS: 0x06>: [1], <MAX_CREDS_IN_LIST: 0x07>: 8, <MAX_CRED_ID_LENGTH: 0x08>: 128, <TRANSPORTS: 0x09>: ['usb'], <ALGORITHMS: 0x0A>: [{'alg': -7, 'type': 'public-key'}, {'alg': -8, 'type': 'public-key'}]}
PIN: Not configured

End of diagnostics
❯ ykman --log-level DEBUG oath accounts list
2022-05-03T17:30:54+1000 INFO [ykman.logging_setup.setup:76] Initialized logging for level: DEBUG
2022-05-03T17:30:54+1000 INFO [ykman.logging_setup.setup:77] Running ykman version: 4.0.8
2022-05-03T17:30:54+1000 DEBUG [ykman.logging_setup.log_sys_info:48] Python: 3.10.4 (main, Apr 26 2022, 19:43:24) [Clang 13.0.0 (clang-1300.0.29.30)]
2022-05-03T17:30:54+1000 DEBUG [ykman.logging_setup.log_sys_info:49] Platform: darwin
2022-05-03T17:30:54+1000 DEBUG [ykman.logging_setup.log_sys_info:50] Arch: x86_64
2022-05-03T17:30:54+1000 DEBUG [ykman.logging_setup.log_sys_info:56] Running as admin: False
2022-05-03T17:30:54+1000 DEBUG [fido2.hid.macos.list_descriptors:453] Found CTAP device: 4300560983
2022-05-03T17:30:54+1000 DEBUG [ykman.pcsc.send_and_receive:118] SEND: 00a4040008a000000527471117
2022-05-03T17:30:54+1000 DEBUG [ykman.pcsc.send_and_receive:120] RECV: 5669727475616c206d6772202d2046572076657273696f6e20352e322e37 SW=9000
2022-05-03T17:30:54+1000 DEBUG [ykman.pcsc.send_and_receive:118] SEND: 001d000000
2022-05-03T17:30:54+1000 DEBUG [ykman.pcsc.send_and_receive:120] RECV: 260102023f0302023f020400f3751704010405030502070602000007010f0801000a01000f0100 SW=9000
2022-05-03T17:30:54+1000 DEBUG [ykman.device.read_info:453] Read info: DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, auto_eject_timeout=0, challenge_response_timeout=15, device_flags=<DEVICE_FLAG.0: 0>), serial=15955223, version=Version(major=5, minor=2, patch=7), form_factor=<FORM_FACTOR.USB_C_NANO: 4>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.FIDO2|OATH|PIV|OPENPGP|4|U2F|OTP: 575>}, is_locked=False, is_fips=False, is_sky=False)
2022-05-03T17:30:54+1000 DEBUG [ykman.pcsc.send_and_receive:118] SEND: 00a4040007a0000005272101
2022-05-03T17:30:54+1000 DEBUG [ykman.pcsc.send_and_receive:120] RECV: 79030502077108b9894f25870a61f8 SW=9000
2022-05-03T17:30:54+1000 DEBUG [ykman.pcsc.send_and_receive:118] SEND: 00a1000000
2022-05-03T17:30:54+1000 DEBUG [ykman.pcsc.send_and_receive:120] RECV: 7213213150617373776f72643a506572736f6e616c723a2161726e3a6177733a69616d3a3a3231353933303631303335353a6d66612f6a6f73682e686f67656e646f726e406d616e74616c75732e636f6d SW=9000

unplugging and replugging the yubikey resolved.

I use a program called 'ejectify' to eject all drives when i disconnect from the dock, perhaps this is somehow 'ejecting' the yubikey?