error EAGAIN from read() in fido_hid_read() during “fido2-token -I «device»”

[ar-an-ribe]

Hello, all,

I recently purchased two YubiKey 5 NFC devices. My old computer still runs OS X 10.9.5, so I compiled and installed a more recent version of CCID on it to allow it to recognize the YubiKeys. I’ve also compiled an OS X 10.9.5-friendly version of libfido2 1.15.0 by providing my own clock_gettime() call, since Apple didn’t provide its own clock_gettime() call until macOS 10.12.

When I run “fido2-token -I «device»” on my computer against either YubiKey, output such as this is often emitted:

$ fido2-token -V && fido2-token -L

1.15.0
ioreg://4295015390: vendor=0x1050, product=0x0407 (Yubico YubiKey OTP+FIDO+CCID)

$ fido2-token -I ioreg://4295015390

fido2-token: fido_dev_open ioreg://4295015390: FIDO_ERR_RX

$ fido2-token -d -I ioreg://4295015390

fido_tx: dev=0x7fcfd0c07060, cmd=0x06
fido_tx: buf=0x7fcfd0c07060, len=8
fido_rx: dev=0x7fcfd0c07060, cmd=0x06, ms=-1
fido_hid_read: read: Resource temporarily unavailable
rx: rx_preamble
fido_dev_open_rx: fido_rx
fido2-token: fido_dev_open ioreg://4295015390: FIDO_ERR_RX

Is EAGAIN a common error that is returned from the read() call in the fido_hid_read() function of src/hid_osx.c? It seems to happen quite frequently when I run the “fido2-token -I «device»” command, and I’m not doing anything else with the YubiKeys when I run this command. [As an experiment, I increased the wait between calls to read() in the schedule_io_loop() function of src/hid_osx.c from five seconds to ten seconds in case five seconds wasn’t enough time, but that didn’t seem to reduce the frequency of the EAGAIN error.]

[LDVG]

Hi,

Is EAGAIN a common error that is returned from the read() call in the fido_hid_read() function of src/hid_osx.c?

It's not something we'd imagine seeing under normal operation. We're using a non-blocking pipe to read the data from the report callback; EAGAIN just means that the pipe is empty. Why the authenticator is not responding to the command (or why the callback would not fire) is unclear. We've seen similar reports before, but the root cause has usually been something else ^{1 2 3}.

and I’m not doing anything else with the YubiKeys when I run this command

You mentioned CCID, are you sure there is no other program/daemon polling the device over that interface? Have you tried killing the PCSC daemon?

Do you have multiple devices plugged in at the same time when you get this issue?

Could you show us the output of a successful run of fido2-token -I?

Could you show us the output of FIDO_DEBUG=1 fido2-token -L?

Footnotes

1. https://github.com/Yubico/libfido2/issues/783 ↩

2. https://github.com/Yubico/libfido2/issues/800 ↩

3. https://github.com/Yubico/libfido2/issues/694 ↩

[ar-an-ribe]

I have pushed a branch called xxx-ci, which polls the backend slightly differently. If you could try building that and see if it helps, that'd be helpful.

After building and installing the xxx-ci branch, killing pcscd, and inserting one YubiKey, here’s what happened:

$ fido2-token -V && FIDO_DEBUG=1 fido2-token -L

1.16.0
run_manifest: found 1 hid device
fido_tx: dev=0x7fb333500540, cmd=0x06
fido_tx: buf=0x7fb333500540, len=8
0000: 25 ff da b6 7e 7f c3 1d
fido_pcsc_write: writing: buf=0x7fff5afda980, len=14
0000: 00 a4 04 00 08 a0 00 00 06 47 2f 00 01 00
fido_pcsc_write: read: buf=0x7fb333500010, len=2
0000: 6a 82
fido_rx: dev=0x7fb333500540, cmd=0x06, ms=-1
fido_pcsc_read: reading: buf=0x7fb333500010, len=2
0000: 6a 82
rx_init: read
fido_dev_open_rx: fido_rx
nfc_is_fido: fido_dev_open: 0xfffffffe
copy_info: nfc_is_fido: pcsc://slot0
run_manifest: found 0 pcsc devices
ioreg://4295028539: vendor=0x1050, product=0x0407 (Yubico YubiKey OTP+FIDO+CCID)

$ FIDO_DEBUG=1 fido2-token -L

run_manifest: found 1 hid device
fido_tx: dev=0x7fb82bd01760, cmd=0x06
fido_tx: buf=0x7fb82bd01760, len=8
0000: c4 e9 d1 56 bc 2b 49 da
fido_pcsc_write: writing: buf=0x7fff52c6a980, len=14
0000: 00 a4 04 00 08 a0 00 00 06 47 2f 00 01 00
fido_pcsc_write: read: buf=0x7fb82bc0edc0, len=2
0000: 6a 82
fido_rx: dev=0x7fb82bd01760, cmd=0x06, ms=-1
fido_pcsc_read: reading: buf=0x7fb82bc0edc0, len=2
0000: 6a 82
rx_init: read
fido_dev_open_rx: fido_rx
nfc_is_fido: fido_dev_open: 0xfffffffe
copy_info: nfc_is_fido: pcsc://slot0
run_manifest: found 0 pcsc devices
ioreg://4295028539: vendor=0x1050, product=0x0407 (Yubico YubiKey OTP+FIDO+CCID)

$ FIDO_DEBUG=1 fido2-token -L

run_manifest: found 1 hid device
fido_tx: dev=0x7f9459d0bd30, cmd=0x06
fido_tx: buf=0x7f9459d0bd30, len=8
0000: d8 f1 1a 16 d7 b9 d1 99
fido_pcsc_write: writing: buf=0x7fff5558a980, len=14
0000: 00 a4 04 00 08 a0 00 00 06 47 2f 00 01 00
fido_pcsc_write: read: buf=0x7f9459d104e0, len=2
0000: 6a 82
fido_rx: dev=0x7f9459d0bd30, cmd=0x06, ms=-1
fido_pcsc_read: reading: buf=0x7f9459d104e0, len=2
0000: 6a 82
rx_init: read
fido_dev_open_rx: fido_rx
nfc_is_fido: fido_dev_open: 0xfffffffe
copy_info: nfc_is_fido: pcsc://slot0
run_manifest: found 0 pcsc devices
ioreg://4295028539: vendor=0x1050, product=0x0407 (Yubico YubiKey OTP+FIDO+CCID)

So far, so good, as far as I can tell; three runs produced the same (non-debugging) output line. The next command was

$ fido2-token -I ioreg://4295028539
^C

This command produced no output for a few minutes before I’d interrupted it. After interrupting it, I’d added the -d option:

$ fido2-token -d -I ioreg://4295028539

see output_from_539.txt

The ’539 output looks like it contains an expected result. I then tried it twice without the -d option:

$ fido2-token -I ioreg://4295028539

proto: 0x02
major: 0x05
minor: 0x07
build: 0x01
caps: 0x05 (wink, cbor, msg)
version strings: U2F_V2, FIDO_2_0, FIDO_2_1_PRE, FIDO_2_1
extension strings: credProtect, hmac-secret, largeBlobKey, credBlob, minPinLength
transport strings: nfc, usb
algorithms: es256 (public-key), eddsa (public-key), es384 (public-key)
aaguid: a25342c03cdc44148e46f4807fca511c
options: rk, up, noplat, noalwaysUv, credMgmt, authnrCfg, noclientPin, largeBlobs, pinUvAuthToken, setMinPINLength, makeCredUvNotRqd, credentialMgmtPreview
fwversion: 0x50701
maxmsgsiz: 1280
maxcredcntlst: 8
maxcredlen: 128
maxcredblob: 32
maxlargeblob: 4096
maxrpids in minpinlen: 1
remaining rk(s): 100
minpinlen: 4
pin protocols: 2, 1
pin retries: undefined
pin change required: false
uv retries: undefined

$ fido2-token -I ioreg://4295028539

same output as above

Leaving the plugged-in YubiKey in place, I then inserted the second YubiKey and reran the -L command:

$ FIDO_DEBUG=1 fido2-token -L

run_manifest: found 2 hid devices
fido_tx: dev=0x7fbea840f070, cmd=0x06
fido_tx: buf=0x7fbea840f070, len=8
0000: ec e9 61 9c 19 cd e3 a6
fido_pcsc_write: writing: buf=0x7fff5b7a0980, len=14
0000: 00 a4 04 00 08 a0 00 00 06 47 2f 00 01 00
fido_pcsc_write: read: buf=0x7fbea840edc0, len=2
0000: 6a 82
fido_rx: dev=0x7fbea840f070, cmd=0x06, ms=-1
fido_pcsc_read: reading: buf=0x7fbea840edc0, len=2
0000: 6a 82
rx_init: read
fido_dev_open_rx: fido_rx
nfc_is_fido: fido_dev_open: 0xfffffffe
copy_info: nfc_is_fido: pcsc://slot0
fido_tx: dev=0x7fbea8500340, cmd=0x06
fido_tx: buf=0x7fbea8500340, len=8
0000: b3 41 b5 56 d4 e0 65 d5
fido_pcsc_write: writing: buf=0x7fff5b7a0980, len=14
0000: 00 a4 04 00 08 a0 00 00 06 47 2f 00 01 00
fido_pcsc_write: read: buf=0x7fbea840edc0, len=2
0000: 6a 82
fido_rx: dev=0x7fbea8500340, cmd=0x06, ms=-1
fido_pcsc_read: reading: buf=0x7fbea840edc0, len=2
0000: 6a 82
rx_init: read
fido_dev_open_rx: fido_rx
nfc_is_fido: fido_dev_open: 0xfffffffe
copy_info: nfc_is_fido: pcsc://slot1
run_manifest: found 0 pcsc devices
ioreg://4295028539: vendor=0x1050, product=0x0407 (Yubico YubiKey OTP+FIDO+CCID)
ioreg://4295028636: vendor=0x1050, product=0x0407 (Yubico YubiKey OTP+FIDO+CCID)

which looks good. I then ran the -I command on the second (’636) YubiKey twice:

$ fido2-token -I ioreg://4295028636

proto: 0x02
major: 0x05
minor: 0x07
build: 0x01
caps: 0x05 (wink, cbor, msg)
version strings: U2F_V2, FIDO_2_0, FIDO_2_1_PRE, FIDO_2_1
extension strings: credProtect, hmac-secret, largeBlobKey, credBlob, minPinLength
transport strings: nfc, usb
algorithms: es256 (public-key), eddsa (public-key), es384 (public-key)
aaguid: a25342c03cdc44148e46f4807fca511c
options: rk, up, noplat, noalwaysUv, credMgmt, authnrCfg, noclientPin, largeBlobs, pinUvAuthToken, setMinPINLength, makeCredUvNotRqd, credentialMgmtPreview
fwversion: 0x50701
maxmsgsiz: 1280
maxcredcntlst: 8
maxcredlen: 128
maxcredblob: 32
maxlargeblob: 4096
maxrpids in minpinlen: 1
remaining rk(s): 100
minpinlen: 4
pin protocols: 2, 1
pin retries: undefined
pin change required: false
uv retries: undefined

$ fido2-token -I ioreg://4295028636
^C

The first run’s output looked good, but no output was produced in the first few minutes on the second run. I interrupted that run, and decided to rerun it by bracketing it with start and end times to see how long it might take for output to be emitted:

$ date -u && fido2-token -I ioreg://4295028636 ; date -u

Fri Jan 31 22:04:19 UTC 2025
^C
Fri Jan 31 22:24:32 UTC 2025

I interrupted it after twenty minutes without output. I then repeated this command line, but added a -d option; that completed successfully, with an elapsed time of ten seconds under one second (EDIT: corrected my subtraction error).

The presence of long periods of time without output from fido2-token -I «device» is a new development in the xxx-ci branch. That didn’t happen whenever the -d option was added, but that option was consistently added after an interrupted -d-less run.

To my knowledge, no other program was trying to access the YubiKeys during this time; I didn’t run ykman during this session with the xxx-ci branch.

[LDVG]

Thanks.

The presence of long periods of time without output from fido2-token -I «device» is a new development in the xxx-ci branch.

The implementation in that branch polls the run loop differently, giving it more chances to fire the callback and effectively has an infinite timeout waiting for the data to be delivered. Unfortunately, it's not entirely unsurprising that you'd see no output instead of EAGAIN. I cannot see anything obviously wrong with our implementation, nor have we been able to reproduce this internally so far using more modern versions of OS X. At this point we cannot rule out the issue being in the environment.

[ar-an-ribe]

I cannot see anything obviously wrong with our implementation, nor have we been able to reproduce this internally so far using more modern versions of OS X.

What is the oldest version of OS X that you’d successfully tested? (If the source for its CCID version is publicly available, I might be able to port its version of CCID to OS X 10.9.5 to see if that would make a difference.)

At this point we cannot rule out the issue being in the environment.

It’s certainly a possibility. After a similar testing régime as before, but only using the -I command with the -d option, I finally captured a lack of output when two YubiKeys were plugged in and I was trying to get information on the second plugged-in device:

$ date -u && fido2-token -d -I ioreg://4295033999 ; date -u

Mon Feb 3 23:58:35 UTC 2025
fido_tx: dev=0x7fa420c07060, cmd=0x06
fido_tx: buf=0x7fa420c07060, len=8
0000: 12 0d c0 69 3e fa 61 89
fido_rx: dev=0x7fa420c07060, cmd=0x06, ms=-1
^C
Tue Feb 4 00:07:37 UTC 2025

Apparently the “hanging” occurs after the first fido_rx: debugging line and before the first rx_preamble: debugging line, which might point to the d->io.read call within rx_frame() in src/io.c.

[LDVG]

What is the oldest version of OS X that you’d successfully tested? (If the source for its CCID version is publicly available, I might be able to port its version of CCID to OS X 10.9.5 to see if that would make a difference.)

To be clear, we do not use CCID to communicate with the authenticator, but USB HID. OS X 10.9.5 was EOL before the first release of libfido2 if I recall correctly. We'll keep trying to reproduce this on currently supported versions of OS X. Paging in @martelletto; have you seen anything like this in the past?

Apparently the “hanging” occurs after the first fido_rx.

Yes, at the same place you'd previously see EAGAIN.

[martelletto]

Apologies for the delay on this. Yes, macOS 10.9.5 predates libfido2's first release, and I don't think libfido2 was ever tested or known to work with 10.9.5. This is the first time I hear about this issue, and the symptoms are consistent with @LDVG's analysis.