HID Report Transfer Taking FAR TOo Long

[nobbyv]

I've got one project that uses a STMicro 'F205 (clocked at 120MHz), running as a USB FS device. I send a HID report packet every ~7mS, which takes ~50uS to transmit. All is good; this is about right at 12Mbps.

I've got another project that uses a STMicro '427 (which is clocked at 168MHz), also running as a FS device. The exact same HID report packet is taking over an order of magnitude longer: ~650uS.

I've done comparisons between these two projects, and everything looks identical. I hooked up the two devices with a USB analyzer, and everything looks identical as far as timing. I am stumped; I don't understand what could be slowing this down.

[Jan Axelson]

By "packet", do you mean "HID report that requires multiple transactions to transfer"?

If so, for both projects:

How many bytes is the report?
What is the interrupt endpoint's max packet size?
What is bInterval?
What is the delay you are seeing between transactions?

[nobbyv]

Thanks for the reply! See answers in blue below.

By "packet", do you mean "HID report that requires multiple transactions to transfer"? Yes

If so, for both projects:

How many bytes is the report? 64
What is the interrupt endpoint's max packet size? 64
What is bInterval? 1
What is the delay you are seeing between transactions? Hope this answers that question.

[Jan Axelson]

If the max packet size is 64 and the report is 64 bytes, the report will transfer in one transaction (unless using report IDs).

As I interpret it, the screen capture shows an IN transction with data, followed by 7 SOFs (not sure why no IN transactions in these frames), followed by 6 IN transactions with NAK, followed by an IN transaction with data. The NAKed transactions are 1 millisec apart, followed by the ACKed transaction 1 millisec later.

I don't know what you mean by 50us/650uS to transmit. With bInterval = 1, the HID driver on the host should poll the interrupt IN endpoint once/millisec. The endpoint can return data or NAK on each poll.

In the expanded transaction, I see that the ACK is 50 microsecs. after the IN token packet. Are you saying that one device shows 650 microsecs? If so, does it have any effect on the throughput (1 IN token packet/millisec)?

[nobbyv]

To monitor this time, I simply toggle a GPIO pin immediately before and immediately after calling the ST Micro library function "USBD_HID_SendReport" (which subsequently simply calls "DCD_EP_Tx") and viewing the pin on a scope. On most of my devices, when sending a single 64-byte HID report packet, this takes 30-50uS. However, on my latest device, this takes 600-1000uS to execute the sending of the exact same packet. So my issue isn't a delay in between sending these reports (I execute a bunch of other code that takes 5-6mS, so the polling rate of 1mS is fine), it's that the sending of a SINGLE report is taking too long. The sniffer capture I show is actually for the "slow" device; the "normal" device looks identical, with virtually identical time signatures.

[Jan Axelson]

A USB 2.0 transaction is a single event; there is no other traffic between the phases of the transaction.

The capture you posted shows the ACK status phase occurring 49 microsecs after the IN token phase.

Possibly the delay you're seeing is a delay in toggling the pin.

What problem is this delay causing in the operation of the device?

[nobbyv]

The device needs to cycle through the superloop of firmware as fast as possible (customer requirement). This isn't an issue with the toggling of the pin; I toggle a pin on the "working" board in the exact same way.

EDIT: Your statement about a delay in toggling the pin may indeed be correct (i.e., something else may be preventing the pin from toggling, or occurring before the pin can toggle back off). However, what I was trying to say is that it isn't an issue of the toggling pin routine itself. 

I do have a few ISRs in this code, but one is a 1mS tick timer that even if it happened to hit during the packet transfer only takes 10-12uS. The other occurs every ~100uS or so and takes longer, but no where near as much as 600uS.

[Tsuneo]

Hi nobbyv,

To monitor this time, I simply toggle a GPIO pin immediately before and immediately after calling the ST Micro library function "USBD_HID_SendReport" (which subsequently simply calls "DCD_EP_Tx") and viewing the pin on a scope.

Sound like you are working on ST’s STM32_USB-Host-Device_Lib_V2.1.0 (STSW-STM32046). This library has a bug around the TX FIFO code for IN endpoints, in which it doesn’t mask FIFO empty interrupt, until the IN transfer completes. By this bug, flooded interrupt makes your code crawl. I posted a fix to the ST’s forum.

Flooded "empty FIFO" interrupts still make USB devices crawl
https://my.st.com/public/STe2ecommunities/mcu/Lists/cortex_mx_stm32/Flat.aspx?RootFolder=/public/STe2ecommunities/mcu/Lists/cortex_mx_stm32/Flooded%20empty%20FIFO%20interrupts%20still%20make%20USB%20devices%20crawl

I’m not sure why the bug impacts just 'F427, not on 'F205.
You may have applied one of fixes to the bug for the 'F205 code.

Here is another fix for this issue, which works just for single-packet transfer, like your case.

Known bugs in the OTG / USB library v2.1.0
https://my.st.com/public/STe2ecommunities/mcu/Lists/cortex_mx_stm32/Flat.aspx?RootFolder=%2Fpublic%2FSTe2ecommunities%2Fmcu%2FLists%2Fcortex%5Fmx%5Fstm32%2FKnown%20bugs%20in%20the%20OTG%20%20USB%20library%20v2%2E1%2E0

Tsuneo

[nobbyv]

Tsuneo-
Thank you so, so much! That was indeed the fix I needed. I implemented the fix you posted from bil.til's solution, and the time to send this HID packet has dropped to ~50uS!

One question: did you have any thoughts on the additional correction posted by user cisar.ivo.001 in the post regarding the "flood" of interrupts? I have tried both with this suggestion and without, and cannot see any difference.

Thanks again!

[Tsuneo]

did you have any thoughts on the additional correction posted by user cisar.ivo.001 in the post regarding the "flood" of interrupts? I have tried both with this suggestion and without, and cannot see any difference.

While "USBD_HID_SendReport()" (ie. "DCD_EP_Tx()") is called for a single-packet transfer (64 bytes or less), like your case, there is no difference between both fixes.

But DCD_EP_Tx() is capable to send a transfer of greater size (more than 64 bytes), by splitting the transfer into two or more transactions. When your firmware passes greater transfer size to DCD_EP_Tx(), which spans three or more transactions, cisar.ivo.001's fix should fail. In his fix, the first FIFO empty interrupt masks this interrupt. Though the second transaction is filled to the FIFO by the first FIFO empty interrupt, the third and latter transactions are not passed to the FIFO, because no more interrupt occurs.

As cisar.ivo.001 pointed out in his above topic,
CLEAR_IN_EP_INTR(1, emptyintr) line does nothing, because this flag is read-only.
As this line is just redunant, you may delete this line.
But when this line is replaced as cisar.ivo.001 said, it introduces another bug, as explained above.

Tsuneo