Re: [BUG] xhci: repeated URB cancel on UVC status interrupt EP (0x83) loops for ~15s, stalls camera - Intel Cannon Point-LP [8086:9ded]

[Дмитрий <senior.joker2009@yandex.ru>]

[-- Attachment #1: Type: text/plain, Size: 4146 bytes --]

Hi Michal,

Thanks, and sorry about the previous HTML message. This reply is plain
text.

I enabled the IOMMU using:

|intel_iommu=on iommu.passthrough=0 iommu.strict=1 |

The boot log confirms:

|DMAR: IOMMU enabled iommu: Default domain type: Translated iommu: DMA 
domain TLB invalidation policy: strict mode pci 0000:00:14.0: Adding to 
iommu group 5 |

There were no DMAR or IOMMU fault reports. The camera problem still
reproduces.

I also built Fedora kernel 7.1.8 with commit
7c0c31c66a7f9daace156bac427aafb2f4bbb5fc applied:

|xhci: move dequeue to next valid td instead of past cancelled one |

The resulting kernel is:

|7.1.8-200.xhci7c0c31c.fc44.x86_64 |

The COPR build is available here:

|https://copr.fedorainfracloud.org/coprs/vertigo-red/kernel-xhci-deq/build/10873745/ 
|

The patch does not fix the problem on this machine.

On a fresh boot of the patched kernel, with the same IOMMU parameters,
seven completed iterations of the restart test all reached the 45-second
timeout. Capturing 120 frames at 30 fps should normally take about four
seconds, but each iteration delivered only zero or a few frames.

The non-dynamic-debug kernel log from that test contains:

|3922 Event dma ... not part of TD 28 Event TRB ... with no TDs queued |

Seven iterations completed before I stopped the test. The manually added
stop marker at the end of patched-40-runs.log says "after_run=06" by
mistake; run 07 has a complete result line.

I then rebooted the patched kernel again and repeated five iterations
with xhci_hcd dynamic debug enabled. All five iterations again timed out.
During the captured interval the log contains:

|27664 Miss service interval error 8131 Event dma ... not part of TD 
7976 with status 13 155 with status 1 39 Event TRB ... with no TDs queued |

The first ring errors appeared less than one second after starting the
first stream.

The VideoControl status URB behavior is still visible. The same URB:

|00000000e0807de4, dev 5, ep 0x83 |

was cancelled 115 times during the five-run capture. In the first batch
it was cancelled 22 times in about 1.9 ms. Each successful Set TR Deq Ptr
advanced the dequeue pointer by one TRB, for example:

|0xfff57660 -> 0xfff57670 0xfff57670 -> 0xfff57680 ... 0xfff577b0 -> 
0xfff577c0 |

All 126 Set TR Deq Ptr commands in the capture reported success. There
were no failed Set TR Deq commands, Host System Errors, kernel warnings,
or IOMMU faults.

The isochronous endpoint 0x81 was cancelled 25 times during the same
capture. Its ring then produced the missed-service and stale transfer
events listed above.

I do not know whether the repeated status-URB cancellation is causal.
It may be related to UVC status endpoint stop/resume behavior. However,
the patch clearly does not prevent the isochronous ring from becoming
desynchronized.

I also tested a Logitech Webcam C170 (046d:082b) connected to external
USB port 1-6 on the same USB 2.0 bus. It appeared as /dev/video2 and was
tested at its default 640x480 YUYV, 30 fps setting.

All 16 completed restart attempts timed out after 45 seconds. The
external camera used slot 6 / xHCI ep 4, and its log contains:

|9336 Event dma ... not part of TD 9176 with status 13 160 with status 1 
64 Event TRB ... with no TDs queued |

Thus a different USB 2.0 webcam can trigger the same class of ring
corruption on a separate slot and endpoint.

One caveat is that the external-camera test was performed in the same
boot after testing the internal camera, so the controller had already
produced ring errors earlier in that boot. The errors are associated
with the C170's own slot 6 / ep 4 ring, but this was not a completely
clean external-camera-only boot.

I have attached:

|iommu-summary.txt xhci-iommu-group.txt patched-uname.txt 
patched-cmdline.txt patched-40-runs.log patched-kernel-summary.txt.xz 
patched-dyndbg-5-runs.log patched-dyndbg-live.log.xz 
lsusb-tree-external.txt v4l2-external-all.txt external-restart-loop.log 
external-kernel-summary.txt.xz restart-test.sh |

Please let me know what additional tracing would be most useful, or if
there is another patch you would like me to test.

Regards,
Dmitry


[-- Attachment #2: xhci-mail-attachments.tar.gz --]
[-- Type: application/gzip, Size: 414001 bytes --]