[Pcsclite-muscle] Race condition during readerstate update

[Marc Kewitz]

Hi,

so I dug deeper and I am not sure why, but we had the polling interval bInterval for the usb ccid interrupt channel set to 255. I have set it to 1 now, but we are still too slow as the interrupt and answer are more or less intertwined now, often still too slow to update the status.
The important log starts at around line 3140.

Do you maybe have any idea on this?

Kind regards,
Marc


-----Original Message-----
From: Kewitz Marc 11CNEN 
Sent: Monday, August 31, 2020 9:41 AM
To: 'Ludovic Rousseau' <ludovic.rousseau at gmail.com>
Cc: pcsclite-muscle at lists.infradead.org
Subject: RE: Re: Re: [Pcsclite-muscle] Race condition during readerstate update /ur/

Hi again,

the smartcard handling on the second processor is done by us, but the ccid/usb driver is coming from silicon labs.
Anyways, I hadn't checked the usb logs yet and you are right, the bulk in message arrives before the interrupt, although the interrupt is sent out first. So something in between changes the order or withholds the interrupt.

ffffffc0698a5700 473023064 S Bo:3:015:3 -115 32 = 6f160000 00008300 00000cca 018e0000 0d970101 8e0808e0 6408dae0 13f90000
ffffffc0698a5700 473024054 C Bo:3:015:3 0 32 >
ffffffc0698a5700 473024183 S Bi:3:015:4 -115 65556 <
ffffffc0698a5700 473025044 C Bi:3:015:4 0 10 = 80000000 00008340 fe00
ffffffc06a97dd00 473026948 S Bo:3:015:1 -115 31 = 41542554 4558543d 322c312c 22536d61 7274632e 20537461 74652022 2c310d
ffffffc06a97dd00 473027057 C Bo:3:015:1 0 31 >
ffffffc0698a5200 473033028 C Ii:3:015:5 0:128 2 = 5002
ffffffc0698a5200 473033108 S Ii:3:015:5 -115:128 8 <

The  6f160000 000083 ( 83 being the sequence number of the ccid header ) is answered by 80000000 000083. Only then the interrupt arrives.
I will dig into this.

Thanks again for the help
Marc

-----Original Message-----
From: Ludovic Rousseau <ludovic.rousseau at gmail.com> 
Sent: Friday, August 28, 2020 4:00 PM
To: Kewitz Marc 11CNEN <Marc.Kewitz.ext at rohde-schwarz.com>
Cc: pcsclite-muscle at lists.infradead.org
Subject: *EXT* Re: Re: [Pcsclite-muscle] Race condition during readerstate update

Le ven. 28 août 2020 à 15:02, Marc Kewitz <Marc.Kewitz.ext at rohde-schwarz.com> a écrit :
>
> Hi Ludovic,
>
> thank you for the quick response. The log is attached. It basically starts around line 5250. You see the xfrblock request, then it gets a negative answer. We see 2 SCardStatus requests and then we only see the interrupt handling.
> The message for the interrupt is sent before the xfrblock answer.

Did you write the reader firmware?
Do you have the same problem with a "commercial" multi-slot reader?

What is strange is that the card event is received on the interrupt endpoint "long" after the event:
00029204 [548055769520] ccid_usb.c:1517:Multi_PollingProc()
Multi_PollingProc (3/5): OK

The driver waits for 29.204 ms doing nothing before the USB message arrives.

You wrote "The message for the interrupt is sent before the xfrblock answer." but that is not what I see from the logs.

Bye

--
 Dr. Ludovic Rousseau
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: log.txt
URL: <http://lists.infradead.org/pipermail/pcsclite-muscle/attachments/20200831/5196d679/attachment-0001.txt>