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
883 stars 126 forks source link

Yubikey 4: oath: No matching device found (otp works however) #191

Closed fff7d1bc closed 5 years ago

fff7d1bc commented 5 years ago

I am unable to get oath working with Yubikey 4

Versions:

% ykman -v
YubiKey Manager (ykman) version: 1.0.0
Libraries:
    libykpers 1.19.0
    libusb 1.0.22

The output

# ykman --log-level=DEBUG oath list
2018-12-14T21:46:16+0100 INFO [ykman.logging_setup.setup:59] Initialized logging for ykman version: 1.0.1
2018-12-14T21:46:16+0100 DEBUG [ykman.descriptor.Descriptor.open_device:75] transports: 0x4, self.mode.transports: 0x7
2018-12-14T21:46:16+0100 DEBUG [ykman.descriptor.open_device:80] Opening driver for serial: None, type: YUBIKEY.YK4, mode: OTP+FIDO+CCID
2018-12-14T21:46:16+0100 DEBUG [ykman.descriptor.open_device:82] Attempt 1 of 10
2018-12-14T21:46:16+0100 DEBUG [ykman.descriptor.open_device:101] Sleeping for 0.100000 s
2018-12-14T21:46:16+0100 DEBUG [ykman.descriptor.open_device:82] Attempt 2 of 10
2018-12-14T21:46:16+0100 DEBUG [ykman.descriptor.open_device:101] Sleeping for 0.200000 s
2018-12-14T21:46:16+0100 DEBUG [ykman.descriptor.open_device:82] Attempt 3 of 10
2018-12-14T21:46:16+0100 DEBUG [ykman.descriptor.open_device:101] Sleeping for 0.300000 s
2018-12-14T21:46:17+0100 DEBUG [ykman.descriptor.open_device:82] Attempt 4 of 10
2018-12-14T21:46:17+0100 DEBUG [ykman.descriptor.open_device:101] Sleeping for 0.400000 s
2018-12-14T21:46:17+0100 DEBUG [ykman.descriptor.open_device:82] Attempt 5 of 10
2018-12-14T21:46:17+0100 DEBUG [ykman.descriptor.open_device:101] Sleeping for 0.500000 s
2018-12-14T21:46:17+0100 DEBUG [ykman.descriptor.open_device:82] Attempt 6 of 10
2018-12-14T21:46:17+0100 DEBUG [ykman.descriptor.open_device:101] Sleeping for 0.600000 s
2018-12-14T21:46:18+0100 DEBUG [ykman.descriptor.open_device:82] Attempt 7 of 10
2018-12-14T21:46:18+0100 DEBUG [ykman.descriptor.open_device:101] Sleeping for 0.700000 s
2018-12-14T21:46:19+0100 DEBUG [ykman.descriptor.open_device:82] Attempt 8 of 10
2018-12-14T21:46:19+0100 DEBUG [ykman.descriptor.open_device:101] Sleeping for 0.800000 s
2018-12-14T21:46:20+0100 DEBUG [ykman.descriptor.open_device:82] Attempt 9 of 10
2018-12-14T21:46:20+0100 DEBUG [ykman.descriptor.open_device:101] Sleeping for 0.900000 s
2018-12-14T21:46:20+0100 DEBUG [ykman.descriptor.open_device:82] Attempt 10 of 10
2018-12-14T21:46:20+0100 DEBUG [ykman.descriptor.open_device:101] Sleeping for 1.000000 s
2018-12-14T21:46:21+0100 DEBUG [ykman.descriptor.open_device:103] No matching device found
Usage: ykman [OPTIONS] COMMAND [ARGS]...
Try "ykman -h" for help.

Error: Failed connecting to the YubiKey.

I can use other features like otp just fine.

And if I specify the device by ID from the info, I am getting

# ykman -d ASDF --log-level=DEBUG oath list
2018-12-14T21:49:19+0100 INFO [ykman.logging_setup.setup:59] Initialized logging for ykman version: 1.0.1
2018-12-14T21:49:19+0100 DEBUG [ykman.descriptor._open_driver:159] Opening driver for transports: TRANSPORT.CCID, serial: ASDF, key_type: None, mode: None
2018-12-14T21:49:19+0100 DEBUG [ykman.descriptor._open_driver:161] Attempt 1 of 10
2018-12-14T21:49:19+0100 DEBUG [ykman.descriptor._open_driver:184] Sleeping for 0.100000 s
2018-12-14T21:49:19+0100 DEBUG [ykman.descriptor._open_driver:187] No driver found for serial: ASDF, key_type: None, mode: None
2018-12-14T21:49:19+0100 DEBUG [ykman.descriptor._open_driver:161] Attempt 2 of 10
2018-12-14T21:49:19+0100 DEBUG [ykman.descriptor._open_driver:184] Sleeping for 0.200000 s
2018-12-14T21:49:19+0100 DEBUG [ykman.descriptor._open_driver:187] No driver found for serial: ASDF, key_type: None, mode: None
2018-12-14T21:49:19+0100 DEBUG [ykman.descriptor._open_driver:161] Attempt 3 of 10
2018-12-14T21:49:19+0100 DEBUG [ykman.descriptor._open_driver:184] Sleeping for 0.300000 s
2018-12-14T21:49:19+0100 DEBUG [ykman.descriptor._open_driver:187] No driver found for serial: ASDF, key_type: None, mode: None
2018-12-14T21:49:19+0100 DEBUG [ykman.descriptor._open_driver:161] Attempt 4 of 10
2018-12-14T21:49:19+0100 DEBUG [ykman.descriptor._open_driver:184] Sleeping for 0.400000 s
2018-12-14T21:49:20+0100 DEBUG [ykman.descriptor._open_driver:187] No driver found for serial: ASDF, key_type: None, mode: None
2018-12-14T21:49:20+0100 DEBUG [ykman.descriptor._open_driver:161] Attempt 5 of 10
2018-12-14T21:49:20+0100 DEBUG [ykman.descriptor._open_driver:184] Sleeping for 0.500000 s
2018-12-14T21:49:20+0100 DEBUG [ykman.descriptor._open_driver:187] No driver found for serial: ASDF, key_type: None, mode: None
2018-12-14T21:49:20+0100 DEBUG [ykman.descriptor._open_driver:161] Attempt 6 of 10
2018-12-14T21:49:20+0100 DEBUG [ykman.descriptor._open_driver:184] Sleeping for 0.600000 s
2018-12-14T21:49:21+0100 DEBUG [ykman.descriptor._open_driver:187] No driver found for serial: ASDF, key_type: None, mode: None
2018-12-14T21:49:21+0100 DEBUG [ykman.descriptor._open_driver:161] Attempt 7 of 10
2018-12-14T21:49:21+0100 DEBUG [ykman.descriptor._open_driver:184] Sleeping for 0.700000 s
2018-12-14T21:49:21+0100 DEBUG [ykman.descriptor._open_driver:187] No driver found for serial: ASDF, key_type: None, mode: None
2018-12-14T21:49:21+0100 DEBUG [ykman.descriptor._open_driver:161] Attempt 8 of 10
2018-12-14T21:49:21+0100 DEBUG [ykman.descriptor._open_driver:184] Sleeping for 0.800000 s
2018-12-14T21:49:22+0100 DEBUG [ykman.descriptor._open_driver:187] No driver found for serial: ASDF, key_type: None, mode: None
2018-12-14T21:49:22+0100 DEBUG [ykman.descriptor._open_driver:161] Attempt 9 of 10
2018-12-14T21:49:22+0100 DEBUG [ykman.descriptor._open_driver:184] Sleeping for 0.900000 s
2018-12-14T21:49:23+0100 DEBUG [ykman.descriptor._open_driver:187] No driver found for serial: ASDF, key_type: None, mode: None
2018-12-14T21:49:23+0100 DEBUG [ykman.descriptor._open_driver:161] Attempt 10 of 10
2018-12-14T21:49:23+0100 DEBUG [ykman.descriptor._open_driver:184] Sleeping for 1.000000 s
2018-12-14T21:49:24+0100 DEBUG [ykman.descriptor._open_driver:187] No driver found for serial: ASDF, key_type: None, mode: None
2018-12-14T21:49:24+0100 DEBUG [ykman.descriptor._open_driver:159] Opening driver for transports: 7, serial: ASDF, key_type: None, mode: None
2018-12-14T21:49:24+0100 DEBUG [ykman.descriptor._open_driver:161] Attempt 1 of 10
2018-12-14T21:49:24+0100 DEBUG [ykman.driver_otp.open_devices:221] Success in opening key at position 0
2018-12-14T21:49:24+0100 DEBUG [ykman.device.__init__:198] Read config from device...
2018-12-14T21:49:24+0100 DEBUG [ykman.device.__init__:200] Success!
2018-12-14T21:49:24+0100 DEBUG [ykman.descriptor._open_driver:166] Found driver: <ykman.driver_otp.OTPDriver object at 0x7fe57283e7f0> serial: ASDF, key_type: YUBIKEY.YK4, mode: OTP+FIDO+CCID
2018-12-14T21:49:24+0100 DEBUG [ykman.device.__init__:198] Read config from device...
2018-12-14T21:49:24+0100 DEBUG [ykman.device.__init__:200] Success!
2018-12-14T21:49:24+0100 DEBUG [ykman.driver_otp.__del__:208] Destroy <ykman.driver_otp.OTPDriver object at 0x7fe57283e7f0>
2018-12-14T21:49:24+0100 DEBUG [ykman.driver_otp.close:203] Close <ykman.driver_otp.OTPDriver object at 0x7fe57283e7f0>
Traceback (most recent call last):
  File "/root/src/venv/bin/ykman", line 11, in <module>
    sys.exit(main())
  File "/root/src/venv/lib/python3.6/site-packages/ykman/cli/__main__.py", line 212, in main
    cli(obj={})
  File "/root/src/venv/lib/python3.6/site-packages/click/core.py", line 764, in __call__
    return self.main(*args, **kwargs)
  File "/root/src/venv/lib/python3.6/site-packages/click/core.py", line 717, in main
    rv = self.invoke(ctx)
  File "/root/src/venv/lib/python3.6/site-packages/click/core.py", line 1134, in invoke
    Command.invoke(self, ctx)
  File "/root/src/venv/lib/python3.6/site-packages/click/core.py", line 956, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/root/src/venv/lib/python3.6/site-packages/click/core.py", line 555, in invoke
    return callback(*args, **kwargs)
  File "/root/src/venv/lib/python3.6/site-packages/click/decorators.py", line 17, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/root/src/venv/lib/python3.6/site-packages/ykman/cli/util.py", line 77, in inner
    f(*args, **kwargs)
  File "/root/src/venv/lib/python3.6/site-packages/ykman/cli/__main__.py", line 157, in cli
    ctx.call_on_close(dev.close)
AttributeError: 'NoneType' object has no attribute 'close'

Any idea how to debug it?

dagheyman commented 5 years ago

Thanks for the report. What operating system is this on? How did you install ykman?

fff7d1bc commented 5 years ago

Hi,

This is Gentoo, tried both ykman installed via Portage tree and using pip. The same results. otp works, oath is unable to detect device.

dagheyman commented 5 years ago

I'm not too familiar with gentoo, but it sounds like the CCID communication is not working correctly. Does $ ykman openpgp info or $ ykman piv info seem to work? You need some kind of smart card driver running, like pcscd. Maybe this page is helpful? https://wiki.gentoo.org/wiki/PCSC-Lite

dagheyman commented 5 years ago

Did you have a chance do try the commands mentioned above?

fff7d1bc commented 5 years ago

Hi,

Both info result in failing to find Yubikey here. By default Gentoo runs with udev, or udev compatible interface, but here I am using mdev insteadl. The pcsc-lite require either udev or libusb, I used the later, but when I try to debug the pcscd, when I run it with pcscd -a -d -f the moment I insert Yubikey i see

07362783 hotplug_libusb.c:536:HPAddHotPluggable() Adding USB device: 1:5:0
00000037 readerfactory.c:1075:RFInitializeReader() Attempting startup of Yubico YubiKey OTP+FIDO+CCID 00 00 using /usr/lib64/readers/usb/ifd-ccid.bundle/Contents/Linux/libccid.so
00000104 readerfactory.c:950:RFBindFunctions() Loading IFD Handler 3.0
00000030 ifdhandler.c:1961:init_driver() Driver version: 1.4.30
00000940 ifdhandler.c:1978:init_driver() LogLevel: 0x0003
00000008 ifdhandler.c:1989:init_driver() DriverOptions: 0x0000
00000222 ifdhandler.c:110:CreateChannelByNameOrChannel() Lun: 0, device: usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if0
00000016 ccid_usb.c:302:OpenUSBByName() Using: /usr/lib64/readers/usb/ifd-ccid.bundle/Contents/Info.plist
00000884 ccid_usb.c:320:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rousseau@free.fr)
00000007 ccid_usb.c:321:OpenUSBByName() ifdProductString: Generic CCID driver
00000004 ccid_usb.c:322:OpenUSBByName() Copyright: This driver is protected by terms of the GNU Lesser General Public License version 2.1, or (at your option) any later version.
00000791 ccid_usb.c:660:OpenUSBByName() Found Vendor/Product: 1050/0407 (Yubico YubiKey OTP+FIDO+CCID)
00000006 ccid_usb.c:662:OpenUSBByName() Using USB bus/device: 1/5
00000004 ccid_usb.c:722:OpenUSBByName() bNumDataRatesSupported is 0
00036691 ifdhandler.c:381:IFDHGetCapabilities() tag: 0xFB3, usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if0 (lun: 0)
00000016 readerfactory.c:396:RFAddReader() Using the reader polling thread
00000176 ifdhandler.c:381:IFDHGetCapabilities() tag: 0xFAE, usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if0 (lun: 0)
00000007 ifdhandler.c:476:IFDHGetCapabilities() Reader supports 1 slot(s)
00000007 hotplug_libusb.c:536:HPAddHotPluggable() Adding USB device: 1:5:1
00000011 ifdhandler.c:381:IFDHGetCapabilities() tag: 0xFAF, usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if0 (lun: 0)
00000007 readerfactory.c:727:RFSetReaderName() Support 16 simultaneous readers
00000372 ifdhandler.c:1154:IFDHPowerICC() action: PowerUp, usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if0 (lun: 0)
00000202 eventhandler.c:289:EHStatusHandlerThread() powerState: POWER_STATE_POWERED
00000007 ifdhandler.c:381:IFDHGetCapabilities() tag: 0xFAD, usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if0 (lun: 0)
00000007 readerfactory.c:338:RFAddReader() Driver is thread safe
00000008 readerfactory.c:1075:RFInitializeReader() Attempting startup of Yubico YubiKey OTP+FIDO+CCID 01 00 using /usr/lib64/readers/usb/ifd-ccid.bundle/Contents/Linux/libccid.so
00000008 readerfactory.c:864:RFLoadReader() Reusing already loaded driver for /usr/lib64/readers/usb/ifd-ccid.bundle/Contents/Linux/libccid.so
00000004 Card ATR: 3B F8 13 00 00 81 31 FE 15 59 75 62 69 6B 65 79 34 D4 
00000014 readerfactory.c:950:RFBindFunctions() Loading IFD Handler 3.0
00000029 ifdhandler.c:110:CreateChannelByNameOrChannel() Lun: 10000, device: usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if1
00000013 ccid_usb.c:302:OpenUSBByName() Using: /usr/lib64/readers/usb/ifd-ccid.bundle/Contents/Info.plist
00000939 ccid_usb.c:320:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rousseau@free.fr)
00000008 ccid_usb.c:321:OpenUSBByName() ifdProductString: Generic CCID driver
00000005 ccid_usb.c:322:OpenUSBByName() Copyright: This driver is protected by terms of the GNU Lesser General Public License version 2.1, or (at your option) any later version.
00000216 ccid_usb.c:547:OpenUSBByName() USB device 1/5 already in use. Checking next one.
00000226 ccid_usb.c:799:OpenUSBByName() Device not found?
00000005 ifdhandler.c:150:CreateChannelByNameOrChannel() failed
00000006 readerfactory.c:1106:RFInitializeReader() Open Port 0x200001 Failed (usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if1)
00000007 readerfactory.c:376:RFAddReader() Yubico YubiKey OTP+FIDO+CCID init failed.
00000005 readerfactory.c:610:RFRemoveReader() UnrefReader() count was: 1
00000006 readerfactory.c:1126:RFUnInitializeReader() Attempting shutdown of Yubico YubiKey OTP+FIDO+CCID 01 00.
00000018 hotplug_libusb.c:536:HPAddHotPluggable() Adding USB device: 1:5:2
00000008 ifdhandler.c:381:IFDHGetCapabilities() tag: 0xFAF, usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if0 (lun: 0)
00000006 readerfactory.c:727:RFSetReaderName() Support 16 simultaneous readers
00000006 ifdhandler.c:381:IFDHGetCapabilities() tag: 0xFAD, usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if0 (lun: 0)
00000006 readerfactory.c:338:RFAddReader() Driver is thread safe
00000005 readerfactory.c:1075:RFInitializeReader() Attempting startup of Yubico YubiKey OTP+FIDO+CCID 01 00 using /usr/lib64/readers/usb/ifd-ccid.bundle/Contents/Linux/libccid.so
00000006 readerfactory.c:864:RFLoadReader() Reusing already loaded driver for /usr/lib64/readers/usb/ifd-ccid.bundle/Contents/Linux/libccid.so
00000009 readerfactory.c:950:RFBindFunctions() Loading IFD Handler 3.0
00000017 ifdhandler.c:110:CreateChannelByNameOrChannel() Lun: 10000, device: usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if2
00000009 ccid_usb.c:302:OpenUSBByName() Using: /usr/lib64/readers/usb/ifd-ccid.bundle/Contents/Info.plist
00000881 ccid_usb.c:320:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rousseau@free.fr)
00000007 ccid_usb.c:321:OpenUSBByName() ifdProductString: Generic CCID driver
00000006 ccid_usb.c:322:OpenUSBByName() Copyright: This driver is protected by terms of the GNU Lesser General Public License version 2.1, or (at your option) any later version.
00000208 ccid_usb.c:547:OpenUSBByName() USB device 1/5 already in use. Checking next one.
00000225 ccid_usb.c:799:OpenUSBByName() Device not found?
00000004 ifdhandler.c:150:CreateChannelByNameOrChannel() failed
00000006 readerfactory.c:1106:RFInitializeReader() Open Port 0x200002 Failed (usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if2)
00000008 readerfactory.c:376:RFAddReader() Yubico YubiKey OTP+FIDO+CCID init failed.
00000006 readerfactory.c:610:RFRemoveReader() UnrefReader() count was: 1
00000006 readerfactory.c:1126:RFUnInitializeReader() Attempting shutdown of Yubico YubiKey OTP+FIDO+CCID 01 00.
04997700 ifdhandler.c:1154:IFDHPowerICC() action: PowerDown, usb:1050/0407:libhal:/org/freedesktop/Hal/devices/usb_device_1050_0407_serialnotneeded_if0 (lun: 0)
00000153 eventhandler.c:482:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED

Which makes me wonder, s the /hal/ thing looks like an interface udev would provide here, but I do not run udev.

fff7d1bc commented 5 years ago

Looks like it's connected to app-crypt/ccid not playing nice without udev. I will look into it more.

fff7d1bc commented 5 years ago

Okay, so here are findings:

ccid library does use dlopen() during runtime to libudev if possible, and then uses it to poke USB devices. if I make ccid being unable to find libudev, which I keep around for some broken software that requires it during link time, but do not run it, it fails. I will follow it up with ccid authors. Thanks for support!

fff7d1bc commented 5 years ago

Update: my testing method was flawed. It was not about udev per se, but about the /dev/bus/usb/ ownershiop. By default pcscd was running as it's own user and for debug I was running it as root in foreground with all logs to stdout. That was root cause. pcscd was in fact unable to open the yubikey device.