Re: USB transaction errors causing RCU stalls and kernel panics

[Peter Chen <peter.chen@nxp.com>]

On 20-03-09 14:21:56, Jonas Karlsson wrote:
> > 
> > If autosuspend is suspicious, Jonas, could you please try to disable autosuspend
> > for all USB devices (including the roothub and controller) to see what happens?
> > 
> > Peter
> 
> I have run some tests with autosuspend turned off by doing this:
> for i in $(find /sys -name control | grep usb);do echo on > $i;echo "echo on > $i";done;
> 
> To make our modem misbehave we need to cool it down in a temp chamber which I haven't had
> access to the past days. However we have found two other ways to reproduce the event storm causing
> event ring full messages spamming the logs. The pattern in the attached file repeats itself until I
> unbind the driver.

Hi Jonas,

Do you have below commit at your local tree? If you have, I am puzzled
why you still get "Event Ring Full Error" error, maybe Mathias have the
answer?

commit dc0ffbea5729a3abafa577ebfce87f18b79e294b
Author: Peter Chen <peter.chen@nxp.com>
Date:   Fri Nov 15 18:50:00 2019 +0200

    usb: host: xhci: update event ring dequeue pointer on purpose

@Mathias, could xhci design some software retry limits for transaction
error? It may avoid retry storm due to hardware issue (eg, signal
issue). For EHCI, there is a design to define QH_XACTERR_MAX at
qh_completions for that.

Peter

> 
> 1. If we power up the modem and wait until the modem is enumerated and then turn off the 
> VUSB supply to modem which supplies the USB port on the modem we see a continuous flow 
> of Unknown event type 37.
> 
> Or
> 
> 2. If we power up the modem and wait until the modem is enumerated and then pull the reset
> pin of the USB hub that sits between the modem and the SoC we also see a continuous flow of 
> Unknown event type 37.
> 
> According to the USB hub datasheet this happens when the reset pin is pulled:
> "The PHYs are disabled, and the differential pairs will be in a high-impedance state."
> 
> Having autosuspend enabled or disabled does not seem to make a difference in this case. 
> 
> BR,
> Jonas

> [  674.915892] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - nonzero urb status received: -71
> [  674.915902]  xhci-cdns3: Ignoring reset ep completion code of 1
> [  674.915912]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d4570
> [  674.915968]  xhci-cdns3: Transfer error for slot 2 ep 10 on endpoint
> [  674.915979]  xhci-cdns3: Cleaning up stalled endpoint ring
> [  674.915983]  xhci-cdns3: Finding endpoint context
> [  674.915988]  xhci-cdns3: Cycle state = 0x1
> [  674.915993]  xhci-cdns3: New dequeue segment = 00000000641e49ab (virtual)
> [  674.915998]  xhci-cdns3: New dequeue pointer = 0x960d4580 (DMA)
> [  674.916002]  xhci-cdns3: Queueing new dequeue state
> [  674.916009]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000641e49ab (0x960d4000 dma), new deq ptr = 00000000dae0365c (0x960d4580 dma), new cycle = 1
> [  674.916014]  xhci-cdns3: // Ding dong!
> [  674.916020]  xhci-cdns3: Giveback URB 0000000007a5ed65, len = 0, expected = 1024, status = -71
> [  674.916028] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - nonzero urb status received: -71
> [  674.916035]  xhci-cdns3: Ignoring reset ep completion code of 1
> [  674.916044]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d4580
> [  674.916064]  xhci-cdns3: Transfer error for slot 2 ep 10 on endpoint
> [  674.916073]  xhci-cdns3: Cleaning up stalled endpoint ring
> [  674.916077]  xhci-cdns3: Finding endpoint context
> [  674.916081]  xhci-cdns3: Cycle state = 0x1
> [  674.916086]  xhci-cdns3: New dequeue segment = 00000000641e49ab (virtual)
> [  674.916091]  xhci-cdns3: New dequeue pointer = 0x960d4590 (DMA)
> [  674.916094]  xhci-cdns3: Queueing new dequeue state
> [  674.916102]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000641e49ab (0x960d4000 dma), new deq ptr = 00000000d9f5f1c1 (0x960d4590 dma), new cycle = 1
> [  674.916106]  xhci-cdns3: // Ding dong!
> [  674.916113]  xhci-cdns3: Giveback URB 000000008a0a9417, len = 0, expected = 1024, status = -71
> [  674.916119] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - nonzero urb status received: -71
> [  674.916126]  xhci-cdns3: Ignoring reset ep completion code of 1
> [  674.916135]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d4590
> [  674.916149]  xhci-cdns3: Transfer error for slot 2 ep 10 on endpoint
> [  674.916157]  xhci-cdns3: Cleaning up stalled endpoint ring
> [  674.916161]  xhci-cdns3: Finding endpoint context
> [  674.916166]  xhci-cdns3: Cycle state = 0x1
> [  674.916170]  xhci-cdns3: New dequeue segment = 00000000641e49ab (virtual)
> [  674.916175]  xhci-cdns3: New dequeue pointer = 0x960d45a0 (DMA)
> [  674.916178]  xhci-cdns3: Queueing new dequeue state
> [  674.916186]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000641e49ab (0x960d4000 dma), new deq ptr = 0000000094b88dce (0x960d45a0 dma), new cycle = 1
> [  674.916190]  xhci-cdns3: // Ding dong!
> [  674.916197]  xhci-cdns3: Giveback URB 000000003dad7325, len = 0, expected = 1024, status = -71
> [  674.916204] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - nonzero urb status received: -71
> [  674.916211]  xhci-cdns3: Ignoring reset ep completion code of 1
> [  674.916219]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d45a0
> [  674.916251]  xhci-cdns3: Transfer error for slot 2 ep 10 on endpoint
> [  674.916261]  xhci-cdns3: Cleaning up stalled endpoint ring
> [  674.916265]  xhci-cdns3: Finding endpoint context
> [  674.916270]  xhci-cdns3: Cycle state = 0x1
> [  674.916274]  xhci-cdns3: New dequeue segment = 00000000641e49ab (virtual)
> [  674.916279]  xhci-cdns3: New dequeue pointer = 0x960d45b0 (DMA)
> [  674.916282]  xhci-cdns3: Queueing new dequeue state
> [  674.916290]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000641e49ab (0x960d4000 dma), new deq ptr = 0000000000ad0b83 (0x960d45b0 dma), new cycle = 1
> [  674.916294]  xhci-cdns3: // Ding dong!
> [  674.916301]  xhci-cdns3: Giveback URB 0000000077103065, len = 0, expected = 1024, status = -71


-- 

Thanks,
Peter Chen