Continuing Confusion with CTAP USB data

[Fujimi Bentley]

Making a new thread because this is a new issue strange behaviour with webauthn.io

My token has different behaviour when connected at different times to webauthn.io...

Situation 1: 

1. Start webauthn.io's registration

2. Insert FIDO token pop up

3. Load firmware to usb (essentially insert)
4. webauthn.io performs CTAPHID_INIT once (0x06)

5. webauthn.io performs CTAPHID_CBOR once (0x04) for authenticatorGetInfo (0x04)

6. continues with get assertion etc.

This is DIFFERENT behaviour to when the FIDO token is connected first:

Situation 2:

1. Load firmware to usb

2. start webauthn.io's registration

3. webauthn.io has a freak out and repeatedly sends CTAPHID_INIT and CTAPHID_CBOR 

4. does not proceed with get assertion

This is using chrome by the way.

I considered that it might be an issue with my MCU's communication to host, BUT CTAPHID_INIT is definitely working, the host/webauthn.io is sending back the CID sent so the 8 byte nonce within CTAPHID_INIT is been accepted...

Is this just an issue with webauthn.io? I can't think of a good reason why I am getting this behaviour, am I expected to reset the USB HID interface upon CTAPHID_INIT as well?

Regards!

Fujimi

[Fujimi Bentley]

This only happens when connection is USB3, it works in both scenarios when in USB 2 mode.... I will continue investigating.

[Fujimi Bentley]

Might as well tack on abit more info about timing

Please ignore the 10000 value on time, I just did that in my debug outputer to keep it looking nice and inline

Working situation 1

Time in ms : Direction : Data

100010068: FIDO data input: ffffffff 86 0008 ca4f341a1096f2c3 00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

100010101: FIDO data output: ffffffff 86 0011 ca4f341a1096f2c3 00000001 02 010001 0700000000000000000000000000000000000000000000000000000000000000000000000000000000

100010113: FIDO data input: 00000001 90 0001 04 0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

100010128: FIDO data output: 00000001 90 00a9 00 aa0183665532465f5632684649444f5f325f306c4649444f5f325f315f50524502826b6372656450726f746563746b686d61632d73656372

100010146: FIDO data output: 00000001 00 657403509f77e279a6e24d58b70031e5943c6a9804a562726bf5627570f564706c6174f469636c69656e7450696ef47563726564656e7469616c4d

100010167: FIDO data output: 00000001 01 676d7450726576696577f505190800068101070a0818600981637573620a81a263616c672664747970656a7075626c69632d6b6579000000000000

100010187: FIDO data input: 00000001 90 0091 02 a4016b776562617574686e2e696f025820b8f61f95075fb9880885294e881b57f587196fb1a1cf35bf9c7be86f11fcbe3a0381a262696458

etc.

Fail situation 2

100013257: FIDO data input: ffffffff 86 0008 8744a2528fb3adf6 00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

100013289: FIDO data output: ffffffff 860011 8744a2528fb3adf6 00000001 02 010001 0700000000000000000000000000000000000000000000000000000000000000000000000000000000

100014049: FIDO data input: 00000001 90 0001 04 0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

100014062: FIDO data output: 00000001 90 00a9 00 aa0183665532465f5632684649444f5f325f306c4649444f5f325f315f50524502826b6372656450726f746563746b686d61632d73656372

100014080: FIDO data output: 00000001 00 657403509f77e279a6e24d58b70031e5943c6a9804a562726bf5627570f564706c6174f469636c69656e7450696ef47563726564656e7469616c4d

100014149: FIDO data output: 00000001 01 676d7450726576696577f505190800068101070a0818600981637573620a81a263616c672664747970656a7075626c69632d6b6579000000000000

(At this point just repeats INIT and get auth info)

100017117: FIDO data input: ffffffff 86 0008 d0f9d721ca59a171 00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

100017149: FIDO data output: ffffffff 86 0011 d0f9d721ca59a171 00000002 02010001 0700000000000000000000000000000000000000000000000000000000000000000000000000000000

100017161: FIDO data input: 00000002900001040000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

100017176: FIDO data output: 000000029000a900aa0183665532465f5632684649444f5f325f306c4649444f5f325f315f50524502826b6372656450726f746563746b686d61632d73656372

etc.

Looking at the data like this I noticed that there is a gap in the last CBOR response of around 70ms, not sure why, will change firmware to reduce this

On Saturday, September 23, 2023 at 11:40:01 AM UTC+10 Fujimi Bentley wrote:

[Fujimi Bentley]

Well not sure if anyone finds this helpful, ensuring that the time between responses is around 20ms or less fixes the issue

I have no idea why webauthn.io did not report a timeout or why it's not a problem on USB2, maybe my MCU's timing when running on USB2 is just faster in doing things in general....

[Fujimi Bentley]

New update, just having responses within 20 ms does not fix the issue (times are now between 14 to 16ms in reponses/sending HID packets).

Not sure what the problem with USB 3 is....

Are there any websites like webauthn.io that actually give a log of what is going on? I really want to see what is happening server side?

[Fujimi Bentley]

Ah was my mistake, in trying to make it go as fast as possible the buffer for HID output was not been reset properly. 20 MS in response time seems to keep things happy, this might be able to be streteched but I'll just aim to make everything move as fast as possible and if an idle period of 20ms+ occurs, send a keep alive as soon as possible..

I feel this is more stringent then needed but hey...

[Fujimi Bentley]

Final note, did a test on timing, it seems like it can support much larger times (tested with an artificial wait of 400ms)

I think the issue was me been silly the entire time, the USB channel was not ready to send, but that confuses me since I was getting INIT responses back successfully..... 

[My1]

just out of curiosity, can you check how USB2 times were pre-optimization?

--
You received this message because you are subscribed to the Google Groups "FIDO Dev (fido-dev)" group.
To unsubscribe from this group and stop receiving emails from it, send an email to fido-dev+u...@fidoalliance.org.
To view this discussion on the web visit https://groups.google.com/a/fidoalliance.org/d/msgid/fido-dev/3c03ca2f-b9bb-45c7-8bff-e9436a044d33n%40fidoalliance.org.

[Fujimi Bentley]

Times swung from 143ms at longest (unoptimized) to a min of 14ms, can squeeze more out of it but don't think I need to, timing didn't change significantly between USB2 or 3.

I was looking at the wrong thing for sure, this was an MCU/USB DMA channel issue.

I put a wait in for 400ms between each response and webauthn accepted it no problem, the problem was definitely because the USB DMA channel handler was rushed (I gave it 50ms thinking that's plenty of time but that did not seem to be enough for some reason... Messages are even been handled in less then 20ms too but a wait of 50 causes problem... So this really confuses me but hey)

I got to emphasize I'm measuring time between messages as after each USB buffer is commited, this includes the full process of waiting for the channel handler, debug output and data handling.... Which after optimizations is done in less then 20ms... but setting DMA channel handler time to 50ms is not enough...???? 

What I had is not a FIDO problem, I just don't get why I had this problem... INIT worked every time and always responded with the data sent correctly too...

Regards! Soz the symptoms didn't make sense for this problem...

Fujimi