Bug 218695

Summary: Datadump for error `ERROR Transfer event TRB DMA ptr not part of current TD ep_index 1 comp_code 1`
Product: Drivers Reporter: Paul Menzel (pmenzel+bugzilla.kernel.org)
Component: USBAssignee: Default virtual assignee for Drivers/USB (drivers_usb)
Status: NEW ---    
Severity: normal CC: mathias.nyman, michal.pecio
Priority: P3    
Hardware: All   
OS: Linux   
Kernel Version: Subsystem:
Regression: No Bisected commit-id:
Attachments: Linux 6.9-rc2+ messages debug v2 patch (output of `dmesg`)
Compressed trace `/sys/kernel/debug/tracing/trace`
Output of `git grep -l 'ERROR Transfer event TRB DMA'`

Description Paul Menzel 2024-04-08 16:31:45 UTC
Created attachment 306106 [details]
Linux 6.9-rc2+ messages debug v2 patch (output of `dmesg`)

https://lore.kernel.org/linux-usb/1f64af9a-0618-a7da-4acc-f043b6580308@linux.intel.com/T/#t

This is just for attaching trace files and Linux messages.

```
echo 'module xhci_hcd =p' >/sys/kernel/debug/dynamic_debug/control
echo 'module xhci_hcd =p' | sudo tee /sys/kernel/debug/dynamic_debug/control
echo 'module usbcore =p' | sudo tee /sys/kernel/debug/dynamic_debug/control 
echo 81920 | sudo tee /sys/kernel/debug/tracing/buffer_size_kb
echo 1 | sudo tee /sys/kernel/debug/tracing/events/xhci-hcd/enable 
echo 1 | sudo tee /sys/kernel/debug/tracing/tracing_on
echo 0 | sudo tee /sys/kernel/debug/tracing/tracing_on
echo 'module usbcore -p' | sudo tee /sys/kernel/debug/dynamic_debug/control
echo 0 | sudo tee /sys/kernel/debug/tracing/events/xhci-hcd/enable
echo 'module xhci_hcd -p' | sudo tee /sys/kernel/debug/dynamic_debug/control
```
Comment 1 Paul Menzel 2024-04-08 16:34:17 UTC
Created attachment 306107 [details]
Compressed trace `/sys/kernel/debug/tracing/trace`

Command for compression:

    7z a -t7z -m0=lzma -mx=9 -mfb=64 -md=32m -ms=on trace.7z trace
Comment 2 Mathias Nyman 2024-04-09 11:24:52 UTC
The trace shows hosts sends duplicate transfer events for ISOC TRBs
after a Transaction error on same device. This transaction error is probably
due to device disconnect. 

Transfer events for TRB ..a1c0 twice, with a transaction error in between:

 <idle>-0       [000] d.h2. 33819.709897: xhci_handle_event: EVENT: TRB 00000032959a1c0 status 'Success' len 0 slot 6 ep 2 type 'Transfer Event' flags e:c
 <idle>-0       [000] d.h2. 33819.709904: xhci_handle_event: EVENT: TRB 000000041547d010 status 'USB Transaction Error' len 4 slot 6 ep 15 type 'Transfer Event' flags e:c
 systemd-journal-395     [000] d.H1. 33819.711886: xhci_handle_event: EVENT: TRB 000000032959a1c0 status 'Success' len 0 slot 6 ep 2 type 'Transfer Event' flags e:c

Transfer events for TRB ..a1d0 twice (the next TRB)
 systemd-journal-395     [000] d.H1. 33819.712001: xhci_handle_event: EVENT: TRB 000000032959a1d0 status 'Success' len 0 slot 6 ep 2 type 'Transfer Event' flags e:c
 systemd-journal-395     [000] d.H1. 33819.712059: xhci_handle_event: EVENT: TRB 000000032959a1d0 status 'Success' len 0 slot 6 ep 2 type 'Transfer Event' flags e:c

Transfer events for TRB ..a1e0 twice
 systemd-journal-395     [000] d.H1. 33819.712139: xhci_handle_event: EVENT: TRB 000000032959a1e0 status 'Success' len 0 slot 6 ep 2 type 'Transfer Event' flags e:c
 systemd-journal-395     [000] d.h1. 33819.712871: xhci_handle_event: EVENT: TRB 000000032959a1e0 status 'Success' len 0 slot 6 ep 2 type 'Transfer Event' flags e:c

etc..

Driver can cope with these extra events, but if this is common we should
probably handle it silently and not concern users with that ERROR message.
Comment 3 Paul Menzel 2024-04-12 07:40:30 UTC
Created attachment 306135 [details]
Output of `git grep -l 'ERROR Transfer event TRB DMA'`

The Linux messages collected by *Hardware for Linux*, dated May 9th, 2023, contain 287 probes (uploads) with that error.

[1]: https://github.com/linuxhw/Dmesg