This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

PROCESSOR-SDK-AM335X: USB Packet delays in Lowest Level

Part Number: PROCESSOR-SDK-AM335X


Hi,

I am using USB CDC ACM class for data transfer from sensor device. In my configuration Am335x is acting as USB Host and MCU acts as USB device where in sensor is connected.

I am using USB data transfer type as Bulk transfer in FullSpeed mode. Host will request sensor data every 30 ms from Device. The data transfer size is more than 4K around approx 4236 Bytes.

In the lowest physical layer of USB Host will always request for Data from Device in following fashion.

Host try to get 4236 Bytes of Data from Device as mentioned below,  Will receive 64 Bytes of data for 66 times and last transfer remaining left over 12 Bytes. i.e 66 *64 Bytes +12 Bytes = 4236 Bytes.

But some times the gap or delay for next 64 Bytes request from Host is taking more time. i.e eg: Delay or Gap between Transfer 5 and Transfer 6 is more. Not sure Why?

for some transfers Host is taking more time to request for next 64 Bytes? Is there any Max limit or expected values related to delay between 64 Bytes Transfers?

Data Transfer Format in physical layer:

Transfer 1:             ||Sync|| PID IN|| ADDR || ENDP|| CRC5|| EOP||       ||Sync|| PID Data0|| Data64 Bytes|| CRC16|| EOP||     ||Sync|| PID ACK|| EOP||

      :

Transfer 5:             ||Sync|| PID IN|| ADDR || ENDP|| CRC5|| EOP||       ||Sync|| PID Data0|| Data64 Bytes|| CRC16|| EOP||      ||Sync|| PID ACK|| EOP||

Transfer 6:             ||Sync|| PID IN|| ADDR || ENDP|| CRC5|| EOP||       ||Sync|| PID Data0|| Data64 Bytes|| CRC16|| EOP||      ||Sync|| PID ACK|| EOP||

      :

Transfer 66:           ||Sync|| PID IN|| ADDR || ENDP|| CRC5|| EOP||        ||Sync|| PID Data0|| Data64 Bytes|| CRC16|| EOP||     ||Sync|| PID ACK|| EOP||

Last Transfer 67:   ||Sync|| PID IN|| ADDR || ENDP|| CRC5|| EOP||        ||Sync|| PID Data0|| Data12 Bytes|| CRC16|| EOP||     ||Sync|| PID ACK|| EOP||

Thanks & Regards

Durga Prasad.

  • Hi Durga,

    Is this a followup to the e2e thread https://e2e.ti.com/support/processors/f/791/t/908153? If not what is the OS do you use?

    Durga Prasad Reddy B said:
    But some times the gap or delay for next 64 Bytes request from Host is taking more time. i.e eg: Delay or Gap between Transfer 5 and Transfer 6 is more. Not sure Why?

    Did you observe the delay from a USB bus analyzer trace? If so, can you please share the trace file in the original format?

  • Hi Bin Liu,

    Its the same follow up for previous task 908153. Ported Debian in our target i.e am335x. Kernel version  4.19.67. We are not using TI SDK. we are following Debian buster Linux Package.

    In analyzer file check in between 7th sec to 8th sec and one more before 9th sec capture. You will observer this behavior. In most of the time usb read trigger will happen every 30 ms. i.e Host will request for data every 30ms. But in some case it is taking more time for data transfer, which in turn the delay is created by 64 Bytes packet delays.Attached the picture for your reference from where to start looking into.

    Unable to attach the analyzer file due to big file size. Is there any way I can upload the analyzer file.The file size is coming to be around 158 MB.

    Can You share any shared folder path or portal link to upload captured analyzer file. It would help a lot.

    Thanks & Regards,

    Durga Prasad.

  • Hi Bin Liu,

    Captured and attached the logic analyzer related to delays. Refer below screenshot for largest delay. Please let me know if You need some more captures.This capture is taken with DMA enabled.

    In general CMD request will be issued every 30 ms from Host. Most of the time the read is successful and able to receive 4236 Bytes in time approx in less than 10ms. But some times like as I mentioned below. It took more than 30ms  i.e incase of 45ms delays between 64Bytes read took more. Not sure Why?

    Thanks & Regards,

    Durga Prasad

    2sec_capture1.zip

  • Hi Durga,

    I reviewed the logic analyzer capture, but don't see any obvious issue in the DP/DM transactions. In the begining of every "Data Read Trigger" cycle there is about 5~6ms period while data packets are received then followed by IN/NAK transactions until the end of the "Data Read Trigger" cycle. The "45.35ms" cycle you highlighted in your screenshot is the same - Data packets are received for about 5~6ms, then the USB device NAKs all the IN tokens until the next "Data Read Trigger" cycle starts.

    So I don't see any issue in the controller transaction level. But what is the "Data Read Trigger" signal in your capture? How it works? What controls it? How does it generate signals in 30ms interval? Please explain it in more details.

  • Hi Bin Liu,

    Data Read Trigger is nothing but starting of First successful data read packet from MCU, just a reference signal. 30 ms is nothing to do with Data Read Trigger. 30ms is something to do with PID OUT triggers(i.e delay between Consecutive PID OUT is 30ms) from HOST. i,e every 30 ms HOST will expect the data from MCU.

    Most of the time data is getting received with in less than 30 ms. But some cases it is taking more time as mentioned in the case of 45.35 ms case. check for delays between 64 Bytes packets after data read trigger you can observe more delay between 64bytes packets. But where as it is not the case for other transactions.

    Is there any expected time delay or limits between consecutive 64Bytes Packets?

     ||Sync|| PID IN|| ADDR || ENDP|| CRC5|| EOP||       ||Sync|| PID Data0|| Data64 Bytes|| CRC16|| EOP||      ||Sync|| PID ACK|| EOP||

    {Expeceted delay}

    ||Sync|| PID IN|| ADDR || ENDP|| CRC5|| EOP||       ||Sync|| PID Data0|| Data64 Bytes|| CRC16|| EOP||      ||Sync|| PID ACK|| EOP||

    Thanks & Regards,

    Durga Prasad.

  • Durga,

    I don't see 64bytes packets delayed in the analyzer trace, maybe the delay happened in the kernel usb stack. Can you please following the instruction below to capture a kernel ftrace log, which would show the timing of the usb transactions.

    - Build the kernel with MUSB CPPI DMA and FTRACE enabled in menuconfig.

    - Run the following commands on AM335x linux console to enable and capture the debug log. It is recommended to run the command in a telnet session instead of the UART console if possible, because the UART would be slow to dump a big amount of messages.

    # cd /sys/kernel/debug/tracing/events/musb/
    # for f in musb_cppi41_*; do echo 1 > $f/enable; done
    # for f in musb_urb_*; do echo 1 > $f/enable; done
    # echo 1 > musb_isr/enable
    # cat ../../trace_pipe