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
877 stars 125 forks source link

ykman piv info errors #574

Closed reuven-cohen closed 8 months ago

reuven-cohen commented 11 months ago

Steps to reproduce

Running "ykman piv info" produces the following error.

~ % ykman piv info ERROR: An unexpected error has occuredTraceback (most recent call last): File "ykman/_cli/main.py", line 377, in main File "click/core.py", line 1157, in call File "click/core.py", line 1078, in main File "click/core.py", line 1688, in invoke File "click/core.py", line 1688, in invoke File "click/core.py", line 1434, in invoke File "click/core.py", line 783, in invoke File "click/decorators.py", line 33, in new_func File "ykman/_cli/piv.py", line 208, in info File "ykman/piv.py", line 540, in get_piv_info File "ykman/piv.py", line 376, in list_certificates File "yubikit/piv.py", line 814, in get_certificate KeyError: 112

Expected result

It should display PIV info of the currently inserted YubiKey

Actual results and logs

See output above

Other info

Upon installing 5.0.1, ykman piv info correctly displays info from the inserted YubiKey. Every other 'ykman * info' command produces normal output.

dainnilsson commented 11 months ago

Based on the above info it looks like you have a malformed certificate in one of the slots (or at least ykman thinks its malformed). If you run the command with logging enabled you should be able to identify which certificate is causing the problem.

ykman --log-level debug piv info

Once we figure out which one it is, we should be able to take a closer look and see why it's malformed.

reuven-cohen commented 11 months ago

[DELETED For Github] = Removed SerialNumber from the output for public posting The odd part is that 5.0.1 works fine, when I tried 5.1.1 it produced the same error as 5.2.1

~ % ykman --log-level debug piv info
INFO 15:39:50.66 [ykman.logging.set_log_level:60] Logging at level: DEBUG
WARNING 15:39:50.66 [ykman.logging.set_log_level:64] 
#############################################################################
#                                                                           #
# WARNING: Sensitive data may be logged!                                    #
# Some personally identifying information may be logged, such as usernames! #
#                                                                           #
#############################################################################
INFO 15:39:50.66 [ykman._cli.__main__.cli:239] System info:
  ykman:            5.2.1
  Python:           3.12.0 (v3.12.0:0fb18b02c8, Oct  2 2023, 09:45:56) [Clang 13.0.0 (clang-1300.0.29.30)]
  Platform:         darwin
  Arch:             arm64
  System date:      2023-11-01
  Running as admin: False

DEBUG 15:39:50.105 [ykman.device.add:165] Add device for <class 'yubikit.core.smartcard.SmartCardConnection'>: ScardYubiKeyDevice(pid=0406, fingerprint='Yubico YubiKey FIDO+CCID')
DEBUG 15:39:50.106 [yubikit.support.read_info:264] Attempting to read device info, using ScardSmartCardConnection
DEBUG 15:39:50.107 [yubikit.management.__init__:446] Management session initialized for connection=ScardSmartCardConnection, version=4.4.5
DEBUG 15:39:50.108 [yubikit.support.read_info:292] Read info: DeviceInfo(config=DeviceConfig(enabled_capabilities={}, auto_eject_timeout=0, challenge_response_timeout=0, device_flags=<DEVICE_FLAG: 0>), serial=[DELETED For Github], version=Version(major=4, minor=4, patch=5), form_factor=<FORM_FACTOR.UNKNOWN: 0>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.OTP|U2F|OATH|PIV|OPENPGP|4: 63>}, is_locked=False, is_fips=False, is_sky=False)
DEBUG 15:39:50.108 [yubikit.support.read_info:351] Device info, after tweaks: DeviceInfo(config=DeviceConfig(enabled_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.U2F|OATH|PIV|OPENPGP|4: 62>}, auto_eject_timeout=0, challenge_response_timeout=0, device_flags=<DEVICE_FLAG: 0>), serial=[DELETED For Github], version=Version(major=4, minor=4, patch=5), form_factor=<FORM_FACTOR.UNKNOWN: 0>, supported_capabilities={<TRANSPORT.USB: 'usb'>: <CAPABILITY.OTP|U2F|OATH|PIV|OPENPGP|4: 63>}, is_locked=False, is_fips=True, is_sky=False)
DEBUG 15:39:50.109 [ykman.device.add:176] Resolved device [DELETED For Github]
DEBUG 15:39:50.111 [yubikit.core.smartcard.enable_touch_workaround:159] Touch workaround enabled=False
DEBUG 15:39:50.111 [yubikit.piv.__init__:446] PIV session initialized (version=4.4.5)
DEBUG 15:39:50.111 [ykman.piv.get_pivman_data:252] Reading pivman data
DEBUG 15:39:50.111 [yubikit.piv.get_object:765] Reading data from object slot 0x5fff00
DEBUG 15:39:50.111 [ykman.piv.get_pivman_data:258] No data, initializing blank
DEBUG 15:39:50.111 [ykman.piv.get_pivman_data:252] Reading pivman data
DEBUG 15:39:50.111 [yubikit.piv.get_object:765] Reading data from object slot 0x5fff00
DEBUG 15:39:50.112 [ykman.piv.get_pivman_data:258] No data, initializing blank
DEBUG 15:39:50.112 [yubikit.piv.get_pin_metadata:644] Getting PIN metadata
DEBUG 15:39:50.112 [yubikit.piv.get_pin_attempts:572] Getting PIN attempts
DEBUG 15:39:50.112 [yubikit.piv.get_pin_metadata:644] Getting PIN metadata
DEBUG 15:39:50.112 [yubikit.piv.get_pin_attempts:586] Using value from empty verify
DEBUG 15:39:50.112 [yubikit.piv.get_puk_metadata:649] Getting PUK metadata
DEBUG 15:39:50.112 [yubikit.piv.get_management_key_metadata:654] Getting management key metadata
DEBUG 15:39:50.112 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc102
DEBUG 15:39:50.113 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc107
DEBUG 15:39:50.114 [yubikit.piv.get_certificate:808] Reading certificate in slot 82 (RETIRED1)
DEBUG 15:39:50.114 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc10d
DEBUG 15:39:50.114 [yubikit.piv.get_certificate:808] Reading certificate in slot 83 (RETIRED2)
DEBUG 15:39:50.114 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc10e
DEBUG 15:39:50.115 [yubikit.piv.get_certificate:808] Reading certificate in slot 84 (RETIRED3)
DEBUG 15:39:50.115 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc10f
DEBUG 15:39:50.116 [yubikit.piv.get_certificate:808] Reading certificate in slot 85 (RETIRED4)
DEBUG 15:39:50.116 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc110
DEBUG 15:39:50.116 [yubikit.piv.get_certificate:808] Reading certificate in slot 86 (RETIRED5)
DEBUG 15:39:50.116 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc111
DEBUG 15:39:50.117 [yubikit.piv.get_certificate:808] Reading certificate in slot 87 (RETIRED6)
DEBUG 15:39:50.117 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc112
DEBUG 15:39:50.118 [yubikit.piv.get_certificate:808] Reading certificate in slot 88 (RETIRED7)
DEBUG 15:39:50.118 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc113
DEBUG 15:39:50.118 [yubikit.piv.get_certificate:808] Reading certificate in slot 89 (RETIRED8)
DEBUG 15:39:50.118 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc114
DEBUG 15:39:50.119 [yubikit.piv.get_certificate:808] Reading certificate in slot 8A (RETIRED9)
DEBUG 15:39:50.119 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc115
DEBUG 15:39:50.119 [yubikit.piv.get_certificate:808] Reading certificate in slot 8B (RETIRED10)
DEBUG 15:39:50.120 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc116
DEBUG 15:39:50.120 [yubikit.piv.get_certificate:808] Reading certificate in slot 8C (RETIRED11)
DEBUG 15:39:50.120 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc117
DEBUG 15:39:50.121 [yubikit.piv.get_certificate:808] Reading certificate in slot 8D (RETIRED12)
DEBUG 15:39:50.121 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc118
DEBUG 15:39:50.121 [yubikit.piv.get_certificate:808] Reading certificate in slot 8E (RETIRED13)
DEBUG 15:39:50.121 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc119
DEBUG 15:39:50.122 [yubikit.piv.get_certificate:808] Reading certificate in slot 8F (RETIRED14)
DEBUG 15:39:50.122 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc11a
DEBUG 15:39:50.122 [yubikit.piv.get_certificate:808] Reading certificate in slot 90 (RETIRED15)
DEBUG 15:39:50.122 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc11b
DEBUG 15:39:50.123 [yubikit.piv.get_certificate:808] Reading certificate in slot 91 (RETIRED16)
DEBUG 15:39:50.123 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc11c
DEBUG 15:39:50.124 [yubikit.piv.get_certificate:808] Reading certificate in slot 92 (RETIRED17)
DEBUG 15:39:50.124 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc11d
DEBUG 15:39:50.124 [yubikit.piv.get_certificate:808] Reading certificate in slot 93 (RETIRED18)
DEBUG 15:39:50.124 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc11e
DEBUG 15:39:50.125 [yubikit.piv.get_certificate:808] Reading certificate in slot 94 (RETIRED19)
DEBUG 15:39:50.125 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc11f
DEBUG 15:39:50.125 [yubikit.piv.get_certificate:808] Reading certificate in slot 95 (RETIRED20)
DEBUG 15:39:50.125 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc120
DEBUG 15:39:50.126 [yubikit.piv.get_certificate:808] Reading certificate in slot 9A (AUTHENTICATION)
DEBUG 15:39:50.126 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc105
DEBUG 15:39:50.131 [yubikit.piv.get_certificate:808] Reading certificate in slot 9C (SIGNATURE)
DEBUG 15:39:50.131 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc10a
ERROR 15:39:50.133 [ykman._cli.__main__.main:393] An unexpected error has occured
Traceback (most recent call last):
  File "ykman/_cli/__main__.py", line 377, in main
  File "click/core.py", line 1157, in __call__
  File "click/core.py", line 1078, in main
  File "click/core.py", line 1688, in invoke
  File "click/core.py", line 1688, in invoke
  File "click/core.py", line 1434, in invoke
  File "click/core.py", line 783, in invoke
  File "click/decorators.py", line 33, in new_func
  File "ykman/_cli/piv.py", line 208, in info
  File "ykman/piv.py", line 540, in get_piv_info
  File "ykman/piv.py", line 376, in list_certificates
  File "yubikit/piv.py", line 814, in get_certificate
KeyError: 112
dainnilsson commented 11 months ago

Thanks!

Ok, that shows that the signature causing the issue is the one in slot 9C (signature). Can you conform if 5.0.1 actually shows a certificate in that slot? It might just be that it handles the error more gracefully and doesn't show anything.

I'd be interested in looking at the actual bytes stored in the slot. That would contain the certificate itself which, while it wouldn't contain any private keys, could include personally identifiable information, so you might not want to post it here. If you're with sending it via email, I can take a look at dain AT yubico DOT com. You can get this by enabling TRAFFIC-level logging and reading the certificate:

ykman --log-level traffic piv certificates export 9c -

The specific part I would like to see should be near the end, and looks like this:

DEBUG 09:22:48.412 [yubikit.piv.get_object:765] Reading data from object slot 0x5fc10a
TRAFFIC 09:22:48.412 [ykman.pcsc.send_and_receive:121] SEND: 00cb3fff0000055c035fc10a
TRAFFIC 09:22:48.416 [ykman.pcsc.send_and_receive:123] RECV: 538204aa708204a13082049d30820285a0030201020209008ec489679c77e54e300d06092a864886f70d01010b0500307e310b30090603550406130255533113301106035504080c0a43616c69666f726e69613116301406035504070c0d53616e204672616e636973636f310f300d060355040a0c0642616453534c3131302f06035504030c2842616453534c20436c69656e7420526f6f7420436572746966696361746520417574686f72697479301e170d3233303432343030303134345a170d3235303432333030303134345a306f310b30090603550406130255533113301106035504080c0a43616c69666f726e69613116301406035504070c0d53616e204672616e636973636f310f300d060355040a0c0642616453534c3122302006035504030c1942616453534c20436c69656e7420436572746966696361746530820122300d06092a864886f70d01010105000382010f003082010a0282010100c7375f11eb1e4ecfebba48e5cba3122c733e461d1e9c0dc08b8323dac765df5c7749b3e87a7d3cbad5618cf9a5c4851d922306e3e7df7bb37e26d0cb1bbe426b1669f42c72b57ee4cb0a2844126c4674219903dc6bc311580241233fb0fcbfb700591322a5817f24fed553bc4d528f904a4674b0e8bd93a6cd90004a2f7fb23fa3ea033b01a0a20de6537f6112eba69b039a4ea7ad10e8e11dc20fef09425f6ab84a0e98bdb63dcfeaa4e8cbd6380e205484e72de0c1bcc395f098a002f957e6f2d6fbb4c894a14d32bca28e70be985c15f107690f70e63160da1b5dabdf54111dc12ae343b8bfb37a3a864190966f45ec93c4b9581b97f25dc1aeb839822a8d0203010001a32d302b30090603551d1304023000301106096086480186f8420101040403020780300b0603551d0f0404030205e0300d06092a864886f70d01010b0500038202010026bef4b3a3dbecf788a231243a0ac703eed285234021c8d868fb2a4e69761eebd4b73c47d82eb0a6e430d8ee4579aa4b55c8e75e80e2271cc39ae26572d2a3fb625491b243249b5e6b4a6ef45f207090f4db6d65cf1f3d77f663ce64d61fc19c6c7398d23e884062d45279e56f5d342e840576f60d38fc7b6f85c11ac7ec1e327dc2d65e18f69ae7e865ab224a3b582d128887c34f1fd15d269f6459e44812d9bb7450417d11ab3dd07c42e06ad349f7618054fda21e80750f60057171774409354800fb64bf287b5f307d878ff749cf692facfcbe6351d430b33365f7a239051448138c7479be9332216584e3dcb914c53dc87403d783fd5114ed01a7844a6c38ebffb649b422b0d925ee5871cca45fe569736b640c4b6f06f45638b44b2f97f68cfab5bc15790feee5836344cf3a547d2d0a33e28a9662e642c03f50e0f7025aa47509f43be067a8e23ece16a2635e454dd748eeac6f66d711bbaea39598d445a158600e515e6a8fb92f24971beac997fff4155287a11f55797ff9da786c38f4cbe446e95af0e6228046bacee31c4d3861238c009efff47f3c1231f942eb1ff9cd4c9545db0c691cb9be4d1bc4ba7b2a33ff0f88db178099de659488f9840df85b5607913e661cd6b87a4242bcb1f1c9a36b08009dd26ce2cd228e07173011af3343925b82d7c07c9e40ae29317b2dc1dea16d1f1909eeb812207e3e92884b710100fe00 SW=9000
reuven-cohen commented 11 months ago

v5.0.1 shows the following: 9a and 9d Display valid cert info 9c and 9e Displays (Error: Failed to parse certificate)

YubiKey Manager QT 1.2.4 shows 9c and 9e as "Malformed Certificates"

We are just pushing the 2 certs to tokens, Auth and Encrypt, so 9c and 9e shouldn't be getting touched. It may be a glitch with our issuing system dropping junk into 9c and 9e, we're going to follow up with that vendor to review.

Agree with it looking like 5.0.1 handled the errors more gracefully as the debug command shows the same errors but still displays cert info on 9a and 9d.

I'll email you the shortly.

dainnilsson commented 11 months ago

Sounds very plausible! We'll make sure ykman handles malformed certificates more gracefully (again).

dainnilsson commented 8 months ago

This should now work better in the latest release, 5.3.0.