AM5726: High network latency when connecting USB device

Hello Richard,

Could you please share some more information as to what your environment is:

• What OS are you using?
• What SDK version are you using?
• Are you using a custom board or a TI EVM?

Regards,

Josue

Hello,

Kernel 4.19.79

Custom board utilizing the AM5726

regards,

Richard

Hello Richard,

Does this happen on the SDK default image included on the release? 

Do you have a TI EVM? 

Which USB are you using? 2.0 or 3.0?

-Josue

Hi,

Yes we have an EVM. Please allow me a couple days to verify the behavior on the EVM.

We are currently using the THUD release at commit https://git.yoctoproject.org/meta-ti/commit/?h=thud&id=e5da84ec50a46ca73c2efbdaa376d30183562986

We are using USB1 but pinned up for USB 2.0 only

Richard,

Thank you for the update.

Best,

Josue

Hello,

Yes, I am able to observe the same spikes with the EVM

Hello Richard, 

Does this mean that USB enumeration process affects CPSW network latency?

-Josue

Hello,

That is what I am able to observe at least. At the time of connecting a USB device, the ping latencies spike and then return to "normal". I have to ping with an interval of .001 seconds to see this reliably on the command line, but our application dealing with RTP streams sees spikes to around 20ms by the time the packets reach the DSP.

We have a user space application that forwards the packets to the DSP. Timestamp debugging with a test application showed some interesting results. In testing we send packets in a loop at intervals of 1000us, with the send and receive times being (more or less) the same interval. In the below table you can see that starting at packet #2940 the round trip packet time spikes, as well as the delta received time (delta to the receive time of the previous packet). The delta receive times then drop substantially to sub 20us times (they eventually return to 1000us times). This may be indicative that the kernel is buffering the packets while the USB enumeration is being performed, before later emptying the buffer "as fast as possible".

         round    

         trip     snd        rcv     delta      delta

pkt#     usec     time       time    snd prev   rcv prev

2931 ;    290 s:  307280 r:  307571 ds:  1001 dr:  1001  

2932 ;    295 s:  308280 r:  308575 ds:  1000 dr:  1004  

2933 ;    293 s:  309279 r:  309573 ds:   999 dr:   998  

2934 ;    305 s:  310281 r:  310586 ds:  1002 dr:  1013  

2935 ;    297 s:  311277 r:  311575 ds:   996 dr:   989  

2936 ;    314 s:  312276 r:  312591 ds:   999 dr:  1016  

2937 ;    310 s:  313276 r:  313587 ds:  1000 dr:   996  

2938 ;    294 s:  314276 r:  314570 ds:  1000 dr:   983  

2939 ;    292 s:  315276 r:  315568 ds:  1000 dr:   998  

2940 ;   7912 s:  316279 r:  324192 ds:  1003 dr:  8624  

2941 ;   6932 s:  317278 r:  324211 ds:   999 dr:    19  

2942 ;   6077 s:  318279 r:  324356 ds:  1001 dr:   145  

2943 ;   5095 s:  319278 r:  324374 ds:   999 dr:    18  

2944 ;   4109 s:  320281 r:  324390 ds:  1003 dr:    16  

2945 ;   3125 s:  321280 r:  324405 ds:   999 dr:    15  

2946 ;   2142 s:  322277 r:  324420 ds:   997 dr:    15  

2947 ;   1157 s:  323277 r:  324434 ds:  1000 dr:    14  

My assumption is that since the kernel is not RT, socket/network work is being rescheduled during the USB enumeration process.

Hello Richard, 

Is it possible to test this on the latest SDK? SDK 8.2.1?

It could be what you suspect or it could be a USB driver bug.

-Josue

Hello,

No, unfortunately this is not a realistic option. The effort would be non-negligible

Hello Richard,

In this case, lets look at what the changes are  on the USB driver for the newer SDK and we can also look into doing some kernel latency profiling to try to figure out which code in the USB drivers hold on the preemption.

Please keep in mind this will take a bit longer on my side to debug since our support model for SDKs is only guaranteed for a year from release. 

I appreciate your patience. 

-Josue