USB transaction errors causing RCU stalls and kernel panics

USB transaction errors causing RCU stalls and kernel panics

[Jonas Karlsson]

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

Hi,

We have a board with an NXP i.MX8 SoC. We are running Linux 4.19.35 from NXP on the SoC.

There is a modem connected to the SoC via USB through a USB hub. 
The modem presents it self as a cdc-acm device with 4 tty:s.

Sometimes we end up in a situation where all transfers over USB generetes 'USB transaction Errors". 
It is likely that the modem is misbehaving. When this happens we get a lot of "xhci-cdns3: ERROR unknown event type 37" 
in the terminal indicating that the xhci event ring is full. This often leads to RCU stalls and sometimes Kernel panics.

If I enable dynamic debug on xhci_hcd and cdc-acm I can see that all transfers have error code -71 
(-EPROTO which in xhci translates to 'USB transaction error"). When this happens it seems 
like xhci resets the ep, sets TR Deq Ptr to unstall the ep and then a new transfer is started 
which also fails. This behavior generates a lot of events on the event ring which causes 
'ERROR unknown event type 37'. This loop of failing transfers seems to continue until we either unbind
the USB driver or get a kernel panic. The SoC almost becomes unresponsive since it spends most of the 
time executing usb interrupts. 

If I pull the reset pin of the USB hub and keep it in reset state at this point, the event loop of failing 
transfers continues despite there is nothing on the USB bus any longer. The only way to get out of 
that loop is to either unbind the usb driver or power cycle the board.

Is this the expected behavior when USB transaction error happens for all transfers when using cdc-acm class driver?
Or could there be something wrong in the low level USB driver (Cadence in our case)? We need to figure out why we 
get all the transaction errors but we also need to make sure the kernel does not die on us when we have a misbehaving USB device. 
Does anyone have a suggestion on what we could do to improve the stability of the kernel in this situation?

There is a small extract from the dynamic debug log in the attached text file.

Thanks in advance!
BR,
Jonas



[-- Attachment #2: USB_logt.txt --]
[-- Type: text/plain, Size: 17072 bytes --]

[ 1441.993575] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - nonzero urb status received: -71
[ 1441.993583]  xhci-cdns3: Transfer error for slot 4 ep 10 on endpoint
[ 1441.993592]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1441.993598]  xhci-cdns3: Finding endpoint context
[ 1441.993603]  xhci-cdns3: Cycle state = 0x1
[ 1441.993609]  xhci-cdns3: New dequeue segment = 000000000c9bcd9e (virtual)
[ 1441.993615]  xhci-cdns3: New dequeue pointer = 0x960d57a0 (DMA)
[ 1441.993618]  xhci-cdns3: Queueing new dequeue state
[ 1441.993628]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000000c9bcd9e (0x960d5000 dma), new deq ptr = 00000000517b4ddd (0x960d57a0 dma), new cycle = 1
[ 1441.993632]  xhci-cdns3: // Ding dong!
[ 1441.993638]  xhci-cdns3: Giveback URB 0000000088e15531, len = 0, expected = 1024, status = -71
[ 1441.993646] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - nonzero urb status received: -71
[ 1441.993653]  xhci-cdns3: Transfer error for slot 4 ep 2 on endpoint
[ 1441.993660]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1441.993666]  xhci-cdns3: Finding endpoint context
[ 1441.993670]  xhci-cdns3: Cycle state = 0x1
[ 1441.993674]  xhci-cdns3: New dequeue segment = 00000000f8498859 (virtual)
[ 1441.993682]  xhci-cdns3: New dequeue pointer = 0x960e1790 (DMA)
[ 1441.993686]  xhci-cdns3: Queueing new dequeue state
[ 1441.993693]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000f8498859 (0x960e1000 dma), new deq ptr = 00000000859578a2 (0x960e1790 dma), new cycle = 1
[ 1441.993697]  xhci-cdns3: // Ding dong!
[ 1441.993704]  xhci-cdns3: Giveback URB 00000000b4b1f8f0, len = 0, expected = 1024, status = -71
[ 1441.993713] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - nonzero urb status received: -71
[ 1441.993720]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1441.993728]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960db780
[ 1441.993737]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1441.993744]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cf790
[ 1441.993752]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1441.993760]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d57a0
[ 1441.993768]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1441.993776]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960e1790
[ 1441.993783]  xhci-cdns3: Transfer error for slot 4 ep 6 on endpoint
[ 1441.993791]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1441.993795]  xhci-cdns3: Finding endpoint context
[ 1441.993800]  xhci-cdns3: Cycle state = 0x1
[ 1441.993804]  xhci-cdns3: New dequeue segment = 00000000ee417449 (virtual)
[ 1441.993812]  xhci-cdns3: New dequeue pointer = 0x960db790 (DMA)
[ 1441.993817]  xhci-cdns3: Queueing new dequeue state
[ 1441.993826]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000ee417449 (0x960db000 dma), new deq ptr = 00000000fb2a5379 (0x960db790 dma), new cycle = 1
[ 1441.993830]  xhci-cdns3: // Ding dong!
[ 1441.993837]  xhci-cdns3: Giveback URB 00000000df81c243, len = 0, expected = 1024, status = -71
[ 1441.993844] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - nonzero urb status received: -71
[ 1441.993851]  xhci-cdns3: ERROR unknown event type 37
[ 1441.998892]  xhci-cdns3: Transfer error for slot 4 ep 14 on endpoint
[ 1441.998904]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1441.998909]  xhci-cdns3: Finding endpoint context
[ 1441.998914]  xhci-cdns3: Cycle state = 0x1
[ 1441.998919]  xhci-cdns3: New dequeue segment = 00000000ac1d2602 (virtual)
[ 1441.998923]  xhci-cdns3: New dequeue pointer = 0x960cf7a0 (DMA)
[ 1441.998927]  xhci-cdns3: Queueing new dequeue state
[ 1441.998935]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000ac1d2602 (0x960cf000 dma), new deq ptr = 0000000065ceabc8 (0x960cf7a0 dma), new cycle = 1
[ 1441.998940]  xhci-cdns3: // Ding dong!
[ 1441.998947]  xhci-cdns3: Giveback URB 00000000ceb7124e, len = 0, expected = 1024, status = -71
[ 1441.998963]  xhci-cdns3: Cancel URB 0000000008a0c978, dev 1.1, ep 0x81, starting at offset 0x960e1790
[ 1441.998966] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - nonzero urb status received: -71
[ 1441.998975]  xhci-cdns3: // Ding dong!
[ 1441.998982]  xhci-cdns3: Transfer error for slot 4 ep 10 on endpoint
[ 1441.998990]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1441.998994]  xhci-cdns3: Finding endpoint context
[ 1441.998999]  xhci-cdns3: Cycle state = 0x1
[ 1441.999004]  xhci-cdns3: New dequeue segment = 000000000c9bcd9e (virtual)
[ 1441.999008]  xhci-cdns3: New dequeue pointer = 0x960d57b0 (DMA)
[ 1441.999011]  xhci-cdns3: Queueing new dequeue state
[ 1441.999019]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000000c9bcd9e (0x960d5000 dma), new deq ptr = 00000000a1dba0e6 (0x960d57b0 dma), new cycle = 1
[ 1441.999023]  xhci-cdns3: // Ding dong!
[ 1441.999029]  xhci-cdns3: Giveback URB 00000000bc5e4e6f, len = 0, expected = 1024, status = -71
[ 1441.999036] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - nonzero urb status received: -71
[ 1441.999043]  xhci-cdns3: Transfer error for slot 4 ep 2 on endpoint
[ 1441.999050]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1441.999056]  xhci-cdns3: Finding endpoint context
[ 1441.999060]  xhci-cdns3: Cycle state = 0x1
[ 1441.999067]  xhci-cdns3: New dequeue segment = 00000000f8498859 (virtual)
[ 1441.999071]  xhci-cdns3: New dequeue pointer = 0x960e17a0 (DMA)
[ 1441.999078]  xhci-cdns3: Queueing new dequeue state
[ 1441.999087]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000f8498859 (0x960e1000 dma), new deq ptr = 000000006daa01a0 (0x960e17a0 dma), new cycle = 1
[ 1441.999091]  xhci-cdns3: // Ding dong!
[ 1441.999097]  xhci-cdns3: Giveback URB 0000000008a0c978, len = 0, expected = 1024, status = -71
[ 1441.999106] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - urb shutting down with status: -2
[ 1441.999122]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1441.999136]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960db790
[ 1441.999144]  xhci-cdns3: Transfer error for slot 4 ep 8 on endpoint
[ 1441.999153]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1441.999157]  xhci-cdns3: Finding endpoint context
[ 1441.999161]  xhci-cdns3: Cycle state = 0x1
[ 1441.999168]  xhci-cdns3: New dequeue segment = 000000001a60a203 (virtual)
[ 1441.999174]  xhci-cdns3: New dequeue pointer = 0x960dd100 (DMA)
[ 1441.999178]  xhci-cdns3: Queueing new dequeue state
[ 1441.999187]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000001a60a203 (0x960dd000 dma), new deq ptr = 00000000d1422a78 (0x960dd100 dma), new cycle = 1
[ 1441.999191]  xhci-cdns3: // Ding dong!
[ 1441.999199]  xhci-cdns3: Giveback URB 00000000345763b1, len = 0, expected = 64, status = -71
[ 1441.999207] cdc_acm 1-1.1:1.2: acm_ctrl_irq - nonzero urb status received: -71
[ 1441.999213] cdc_acm 1-1.1:1.2: acm_ctrl_irq - usb_submit_urb failed: -19
[ 1441.999525]  xhci-cdns3: Cancel URB 00000000a6a6ab1e, dev 1.1, ep 0x81, starting at offset 0x960e17a0
[ 1442.005923]  xhci-cdns3: Transfer error for slot 4 ep 12 on endpoint
[ 1442.005931]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1442.005937]  xhci-cdns3: Finding endpoint context
[ 1442.005941]  xhci-cdns3: Cycle state = 0x1
[ 1442.005946]  xhci-cdns3: New dequeue segment = 0000000025ea4691 (virtual)
[ 1442.005950]  xhci-cdns3: New dequeue pointer = 0x960d7100 (DMA)
[ 1442.005954]  xhci-cdns3: Queueing new dequeue state
[ 1442.005961]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000025ea4691 (0x960d7000 dma), new deq ptr = 000000009395bf33 (0x960d7100 dma), new cycle = 1
[ 1442.005966]  xhci-cdns3: // Ding dong!
[ 1442.005972]  xhci-cdns3: Giveback URB 000000006bef3965, len = 0, expected = 64, status = -71
[ 1442.005979] cdc_acm 1-1.1:1.4: acm_ctrl_irq - nonzero urb status received: -71
[ 1442.005985] cdc_acm 1-1.1:1.4: acm_ctrl_irq - usb_submit_urb failed: -19
[ 1442.012694]  xhci-cdns3: Transfer error for slot 4 ep 16 on endpoint
[ 1442.012706]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1442.012710]  xhci-cdns3: Finding endpoint context
[ 1442.012716]  xhci-cdns3: Cycle state = 0x1
[ 1442.012721]  xhci-cdns3: New dequeue segment = 0000000059d8bf74 (virtual)
[ 1442.012726]  xhci-cdns3: New dequeue pointer = 0x960d1100 (DMA)
[ 1442.012730]  xhci-cdns3: Queueing new dequeue state
[ 1442.012737]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000059d8bf74 (0x960d1000 dma), new deq ptr = 00000000bb418036 (0x960d1100 dma), new cycle = 1
[ 1442.012743]  xhci-cdns3: // Ding dong!
[ 1442.012750]  xhci-cdns3: Giveback URB 00000000a1d029a3, len = 0, expected = 64, status = -71
[ 1442.012762] cdc_acm 1-1.1:1.6: acm_ctrl_irq - nonzero urb status received: -71
[ 1442.012768] cdc_acm 1-1.1:1.6: acm_ctrl_irq - usb_submit_urb failed: -19
[ 1442.019481]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1442.019495]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cf7a0
[ 1442.019507]  xhci-cdns3: Removing canceled TD starting at 0x960e17a0 (dma).
[ 1442.019513]  xhci-cdns3: Finding endpoint context
[ 1442.019518]  xhci-cdns3: Cycle state = 0x1
[ 1442.019524]  xhci-cdns3: New dequeue segment = 00000000f8498859 (virtual)
[ 1442.019528]  xhci-cdns3: New dequeue pointer = 0x960e17b0 (DMA)
[ 1442.019537]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000f8498859 (0x960e1000 dma), new deq ptr = 00000000ab4e2e42 (0x960e17b0 dma), new cycle = 1
[ 1442.019542]  xhci-cdns3: WARN Cannot submit Set TR Deq Ptr
[ 1442.025032]  xhci-cdns3: A Set TR Deq Ptr command is pending.
[ 1442.030784]  xhci-cdns3: // Ding dong!
[ 1442.030797] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - urb shutting down with status: -2
[ 1442.030829]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1442.030840]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d57b0
[ 1442.030849]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1442.030857]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960e17a0
[ 1442.030866]  xhci-cdns3: Transfer error for slot 4 ep 6 on endpoint
[ 1442.030878]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1442.030883]  xhci-cdns3: Finding endpoint context
[ 1442.030888]  xhci-cdns3: Cycle state = 0x1
[ 1442.030894]  xhci-cdns3: New dequeue segment = 00000000ee417449 (virtual)
[ 1442.030899]  xhci-cdns3: New dequeue pointer = 0x960db7a0 (DMA)
[ 1442.030902]  xhci-cdns3: Queueing new dequeue state
[ 1442.030910]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000ee417449 (0x960db000 dma), new deq ptr = 00000000a776aa38 (0x960db7a0 dma), new cycle = 1
[ 1442.030915]  xhci-cdns3: // Ding dong!
[ 1442.030923]  xhci-cdns3: Giveback URB 00000000a65996b7, len = 0, expected = 1024, status = -71
[ 1442.030934] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - nonzero urb status received: -71
[ 1442.030944]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1442.030953]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd100
[ 1442.030962]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1442.030970]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d7100
[ 1442.030977]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1442.030986]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d1100
[ 1442.030993]  xhci-cdns3: Transfer error for slot 4 ep 14 on endpoint
[ 1442.031001]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1442.031007]  xhci-cdns3: Finding endpoint context
[ 1442.031011]  xhci-cdns3: Cycle state = 0x1
[ 1442.031018]  xhci-cdns3: New dequeue segment = 00000000ac1d2602 (virtual)
[ 1442.031024]  xhci-cdns3: New dequeue pointer = 0x960cf7b0 (DMA)
[ 1442.031028]  xhci-cdns3: Queueing new dequeue state
[ 1442.031035]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000ac1d2602 (0x960cf000 dma), new deq ptr = 00000000af71c4e0 (0x960cf7b0 dma), new cycle = 1
[ 1442.031039]  xhci-cdns3: // Ding dong!
[ 1442.031047]  xhci-cdns3: Giveback URB 000000001c7f9bc2, len = 0, expected = 1024, status = -71
[ 1442.031055] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - nonzero urb status received: -71
[ 1442.031064]  xhci-cdns3: Cancel URB 000000002c66c1ab, dev 1.1, ep 0x81, starting at offset 0x960e17b0
[ 1442.031076]  xhci-cdns3: // Ding dong!
[ 1442.031083]  xhci-cdns3: Transfer error for slot 4 ep 10 on endpoint
[ 1442.031092]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1442.031096]  xhci-cdns3: Finding endpoint context
[ 1442.031100]  xhci-cdns3: Cycle state = 0x1
[ 1442.031105]  xhci-cdns3: New dequeue segment = 000000000c9bcd9e (virtual)
[ 1442.031109]  xhci-cdns3: New dequeue pointer = 0x960d57c0 (DMA)
[ 1442.031113]  xhci-cdns3: Queueing new dequeue state
[ 1442.031120]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000000c9bcd9e (0x960d5000 dma), new deq ptr = 00000000499e04fe (0x960d57c0 dma), new cycle = 1
[ 1442.031124]  xhci-cdns3: // Ding dong!
[ 1442.031131]  xhci-cdns3: Giveback URB 00000000706d0623, len = 0, expected = 1024, status = -71
[ 1442.031139] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - nonzero urb status received: -71
[ 1442.031146]  xhci-cdns3: Transfer error for slot 4 ep 2 on endpoint
[ 1442.031153]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1442.031157]  xhci-cdns3: Finding endpoint context
[ 1442.031162]  xhci-cdns3: Cycle state = 0x1
[ 1442.031166]  xhci-cdns3: New dequeue segment = 00000000f8498859 (virtual)
[ 1442.031171]  xhci-cdns3: New dequeue pointer = 0x960e17c0 (DMA)
[ 1442.031174]  xhci-cdns3: Queueing new dequeue state
[ 1442.031182]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000f8498859 (0x960e1000 dma), new deq ptr = 0000000095491dfe (0x960e17c0 dma), new cycle = 1
[ 1442.031191]  xhci-cdns3: // Ding dong!
[ 1442.031197]  xhci-cdns3: Giveback URB 000000002c66c1ab, len = 0, expected = 1024, status = -71
[ 1442.031204] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - urb shutting down with status: -2
[ 1442.031221]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1442.031232]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960db7a0
[ 1442.031240]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1442.031248]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cf7b0
[ 1442.031260]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1442.031268]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d57c0
[ 1442.031276]  xhci-cdns3: Ignoring reset ep completion code of 1
[ 1442.031283]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960e17c0
[ 1442.031290]  xhci-cdns3: Transfer error for slot 4 ep 6 on endpoint
[ 1442.031298]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1442.031302]  xhci-cdns3: Finding endpoint context
[ 1442.031307]  xhci-cdns3: Cycle state = 0x1
[ 1442.031311]  xhci-cdns3: New dequeue segment = 00000000ee417449 (virtual)
[ 1442.031319]  xhci-cdns3: New dequeue pointer = 0x960db7b0 (DMA)
[ 1442.031325]  xhci-cdns3: Queueing new dequeue state
[ 1442.031334]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000ee417449 (0x960db000 dma), new deq ptr = 00000000f5afdb5d (0x960db7b0 dma), new cycle = 1
[ 1442.031338]  xhci-cdns3: // Ding dong!
[ 1442.031346]  xhci-cdns3: Giveback URB 0000000037b702d9, len = 0, expected = 1024, status = -71
[ 1442.031355]  xhci-cdns3: Cancel URB 00000000994cb7b8, dev 1.1, ep 0x81, starting at offset 0x960e17c0
[ 1442.031358] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - nonzero urb status received: -71
[ 1442.031365]  xhci-cdns3: // Ding dong!
[ 1442.031371]  xhci-cdns3: Transfer error for slot 4 ep 14 on endpoint
[ 1442.031378]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1442.031382]  xhci-cdns3: Finding endpoint context
[ 1442.031387]  xhci-cdns3: Cycle state = 0x1
[ 1442.031391]  xhci-cdns3: New dequeue segment = 00000000ac1d2602 (virtual)
[ 1442.031396]  xhci-cdns3: New dequeue pointer = 0x960cf7c0 (DMA)
[ 1442.031406]  xhci-cdns3: Queueing new dequeue state
[ 1442.031413]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000ac1d2602 (0x960cf000 dma), new deq ptr = 0000000095b33802 (0x960cf7c0 dma), new cycle = 1
[ 1442.031418]  xhci-cdns3: // Ding dong!
[ 1442.031425]  xhci-cdns3: Giveback URB 00000000603b8c7f, len = 0, expected = 1024, status = -71
[ 1442.031432] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - nonzero urb status received: -71
[ 1442.031439]  xhci-cdns3: Transfer error for slot 4 ep 10 on endpoint
[ 1442.031446]  xhci-cdns3: Cleaning up stalled endpoint ring
[ 1442.031449]  xhci-cdns3: Finding endpoint context
[ 1442.031454]  xhci-cdns3: Cycle state = 0x1
[ 1442.031459]  xhci-cdns3: New dequeue segment = 000000000c9bcd9e (virtual)
[ 1442.031463]  xhci-cdns3: New dequeue pointer = 0x960d57d0 (DMA)
[ 1442.031467]  xhci-cdns3: Queueing new dequeue state
[ 1442.031476]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000000c9bcd9e (0x960d5000 dma), new deq ptr = 0000000045f279ed (0x960d57d0 dma), new cycle = 1
[ 1442.031480]  xhci-cdns3: // Ding dong!
[ 1442.031486]  xhci-cdns3: Giveback URB 00000000bcdb9296, len = 0, expected = 1024, status = -71

Re: USB transaction errors causing RCU stalls and kernel panics

[Greg KH]

On Tue, Mar 03, 2020 at 03:05:50PM +0000, Jonas Karlsson wrote:
> Hi,
> 
> We have a board with an NXP i.MX8 SoC. We are running Linux 4.19.35 from NXP on the SoC.
> 
> There is a modem connected to the SoC via USB through a USB hub. 
> The modem presents it self as a cdc-acm device with 4 tty:s.
> 
> Sometimes we end up in a situation where all transfers over USB generetes 'USB transaction Errors". 
> It is likely that the modem is misbehaving. When this happens we get a lot of "xhci-cdns3: ERROR unknown event type 37" 
> in the terminal indicating that the xhci event ring is full. This often leads to RCU stalls and sometimes Kernel panics.
> 
> If I enable dynamic debug on xhci_hcd and cdc-acm I can see that all transfers have error code -71 
> (-EPROTO which in xhci translates to 'USB transaction error"). When this happens it seems 
> like xhci resets the ep, sets TR Deq Ptr to unstall the ep and then a new transfer is started 
> which also fails. This behavior generates a lot of events on the event ring which causes 
> 'ERROR unknown event type 37'. This loop of failing transfers seems to continue until we either unbind
> the USB driver or get a kernel panic. The SoC almost becomes unresponsive since it spends most of the 
> time executing usb interrupts. 
> 
> If I pull the reset pin of the USB hub and keep it in reset state at this point, the event loop of failing 
> transfers continues despite there is nothing on the USB bus any longer. The only way to get out of 
> that loop is to either unbind the usb driver or power cycle the board.
> 
> Is this the expected behavior when USB transaction error happens for all transfers when using cdc-acm class driver?
> Or could there be something wrong in the low level USB driver (Cadence in our case)? We need to figure out why we 
> get all the transaction errors but we also need to make sure the kernel does not die on us when we have a misbehaving USB device. 
> Does anyone have a suggestion on what we could do to improve the stability of the kernel in this situation?

I would blame the xhci-cdns driver as it is the one controlling all of
this.

I don't see this driver in the 4.19 tree, so I think you are going to
have to get support from the company that provided you with that driver
as you are already paying for that support from them :)

good luck!

greg k-h

RE: USB transaction errors causing RCU stalls and kernel panics

[Jonas Karlsson]

> 
> On Tue, Mar 03, 2020 at 03:05:50PM +0000, Jonas Karlsson wrote:
> > Hi,
> >
> > We have a board with an NXP i.MX8 SoC. We are running Linux 4.19.35 from
> NXP on the SoC.
> >
> > There is a modem connected to the SoC via USB through a USB hub.
> > The modem presents it self as a cdc-acm device with 4 tty:s.
> >
> > Sometimes we end up in a situation where all transfers over USB generetes
> 'USB transaction Errors".
> > It is likely that the modem is misbehaving. When this happens we get a lot of
> "xhci-cdns3: ERROR unknown event type 37"
> > in the terminal indicating that the xhci event ring is full. This often leads to RCU
> stalls and sometimes Kernel panics.
> >
> > If I enable dynamic debug on xhci_hcd and cdc-acm I can see that all
> > transfers have error code -71 (-EPROTO which in xhci translates to
> > 'USB transaction error"). When this happens it seems like xhci resets
> > the ep, sets TR Deq Ptr to unstall the ep and then a new transfer is
> > started which also fails. This behavior generates a lot of events on
> > the event ring which causes 'ERROR unknown event type 37'. This loop
> > of failing transfers seems to continue until we either unbind the USB driver or
> get a kernel panic. The SoC almost becomes unresponsive since it spends most
> of the time executing usb interrupts.
> >
> > If I pull the reset pin of the USB hub and keep it in reset state at
> > this point, the event loop of failing transfers continues despite
> > there is nothing on the USB bus any longer. The only way to get out of that
> loop is to either unbind the usb driver or power cycle the board.
> >
> > Is this the expected behavior when USB transaction error happens for all
> transfers when using cdc-acm class driver?
> > Or could there be something wrong in the low level USB driver (Cadence
> > in our case)? We need to figure out why we get all the transaction errors but
> we also need to make sure the kernel does not die on us when we have a
> misbehaving USB device.
> > Does anyone have a suggestion on what we could do to improve the stability
> of the kernel in this situation?
> 
> I would blame the xhci-cdns driver as it is the one controlling all of this.
> 
> I don't see this driver in the 4.19 tree, so I think you are going to have to get
> support from the company that provided you with that driver as you are already
> paying for that support from them :)
> 
> good luck!
> 
> greg k-h

Thanks for the feedback! If the cadence driver is the main suspect I totally agree with you.

The reason I posted on this mailing list was that I was afraid that the cdc-acm driver could
be causing new transfers to be started when the previous fails due to USB transaction errors and
then trigger this event storm.
The acm_ctrl_irq() function seems to submit a new urb directly if the previous fails, but I cannot 
say that I understand that code very well yet. The acm_read_bulk_callback() function also seem
to submit a new read urb on USB transaction Errors. But If you think this could not cause this
behavior I will ask our supplier to fix the cdns driver.

BR,
Jonas

Re: USB transaction errors causing RCU stalls and kernel panics

[Greg KH]

On Tue, Mar 03, 2020 at 08:08:38PM +0000, Jonas Karlsson wrote:
> > 
> > On Tue, Mar 03, 2020 at 03:05:50PM +0000, Jonas Karlsson wrote:
> > > Hi,
> > >
> > > We have a board with an NXP i.MX8 SoC. We are running Linux 4.19.35 from
> > NXP on the SoC.
> > >
> > > There is a modem connected to the SoC via USB through a USB hub.
> > > The modem presents it self as a cdc-acm device with 4 tty:s.
> > >
> > > Sometimes we end up in a situation where all transfers over USB generetes
> > 'USB transaction Errors".
> > > It is likely that the modem is misbehaving. When this happens we get a lot of
> > "xhci-cdns3: ERROR unknown event type 37"
> > > in the terminal indicating that the xhci event ring is full. This often leads to RCU
> > stalls and sometimes Kernel panics.
> > >
> > > If I enable dynamic debug on xhci_hcd and cdc-acm I can see that all
> > > transfers have error code -71 (-EPROTO which in xhci translates to
> > > 'USB transaction error"). When this happens it seems like xhci resets
> > > the ep, sets TR Deq Ptr to unstall the ep and then a new transfer is
> > > started which also fails. This behavior generates a lot of events on
> > > the event ring which causes 'ERROR unknown event type 37'. This loop
> > > of failing transfers seems to continue until we either unbind the USB driver or
> > get a kernel panic. The SoC almost becomes unresponsive since it spends most
> > of the time executing usb interrupts.
> > >
> > > If I pull the reset pin of the USB hub and keep it in reset state at
> > > this point, the event loop of failing transfers continues despite
> > > there is nothing on the USB bus any longer. The only way to get out of that
> > loop is to either unbind the usb driver or power cycle the board.
> > >
> > > Is this the expected behavior when USB transaction error happens for all
> > transfers when using cdc-acm class driver?
> > > Or could there be something wrong in the low level USB driver (Cadence
> > > in our case)? We need to figure out why we get all the transaction errors but
> > we also need to make sure the kernel does not die on us when we have a
> > misbehaving USB device.
> > > Does anyone have a suggestion on what we could do to improve the stability
> > of the kernel in this situation?
> > 
> > I would blame the xhci-cdns driver as it is the one controlling all of this.
> > 
> > I don't see this driver in the 4.19 tree, so I think you are going to have to get
> > support from the company that provided you with that driver as you are already
> > paying for that support from them :)
> > 
> > good luck!
> > 
> > greg k-h
> 
> Thanks for the feedback! If the cadence driver is the main suspect I totally agree with you.
> 
> The reason I posted on this mailing list was that I was afraid that the cdc-acm driver could
> be causing new transfers to be started when the previous fails due to USB transaction errors and
> then trigger this event storm.

Yes, it could, but the host controller should handle that just fine.

> The acm_ctrl_irq() function seems to submit a new urb directly if the previous fails, but I cannot 
> say that I understand that code very well yet. The acm_read_bulk_callback() function also seem
> to submit a new read urb on USB transaction Errors. But If you think this could not cause this
> behavior I will ask our supplier to fix the cdns driver.

Please ask them to fix the driver and get it merged upstream :)

thanks,

greg k-h

Re: USB transaction errors causing RCU stalls and kernel panics

[Oliver Neukum]

Am Dienstag, den 03.03.2020, 20:08 +0000 schrieb Jonas Karlsson:

Hi,

> > > If I pull the reset pin of the USB hub and keep it in reset state at
> > > this point, the event loop of failing transfers continues despite
> > > there is nothing on the USB bus any longer. The only way to get out of that

Well, if nothing is on the bus, CDC-ACM's disconnect() should be
called. Is the HC so broken, that even that does not work?

> > loop is to either unbind the usb driver or power cycle the board.
> > > 
> > > Is this the expected behavior when USB transaction error happens for all
> > 
> > transfers when using cdc-acm class driver?

Well, it will happen on a lot of drivers. Generally the higher level
drivers are written under the assumption that you can submit URBs as
often as you want.

> The reason I posted on this mailing list was that I was afraid that the cdc-acm driver could
> be causing new transfers to be started when the previous fails due to USB transaction errors and
> then trigger this event storm.

It does. However it does so in a way that the lower layers
should survive. You may argue that cdc_acm should do error handling.
The question is which handling. If a reset does not help as you
said, I do not see what cdc_acm can do.

> The acm_ctrl_irq() function seems to submit a new urb directly if the previous fails, but I cannot

Yes. There is no error handling in the CDC specification.
Unless you want to reset the whole device you are stuck.
The device is free to respond with a control message any time
it wants. You need to keep that URB running if you want the
device to remain fully functional.

> say that I understand that code very well yet. The acm_read_bulk_callback() function also seem
> to submit a new read urb on USB transaction Errors. But If you think this could not cause this
> behavior I will ask our supplier to fix the cdns driver.

This has the same issue as the irq endpoint. We need to keep the data
pump running while the device is operational.

	Regards
		Oliver

Re: USB transaction errors causing RCU stalls and kernel panics

[Mathias Nyman]

On 3.3.2020 22.08, Jonas Karlsson wrote:
>>
>> On Tue, Mar 03, 2020 at 03:05:50PM +0000, Jonas Karlsson wrote:
>>> Hi,
>>>
>>> We have a board with an NXP i.MX8 SoC. We are running Linux 4.19.35 from
>> NXP on the SoC.
>>>
>>> There is a modem connected to the SoC via USB through a USB hub.
>>> The modem presents it self as a cdc-acm device with 4 tty:s.
>>>
>>> Sometimes we end up in a situation where all transfers over USB generetes
>> 'USB transaction Errors".
>>> It is likely that the modem is misbehaving. When this happens we get a lot of
>> "xhci-cdns3: ERROR unknown event type 37"
>>> in the terminal indicating that the xhci event ring is full. This often leads to RCU
>> stalls and sometimes Kernel panics.
>>>
>>> If I enable dynamic debug on xhci_hcd and cdc-acm I can see that all
>>> transfers have error code -71 (-EPROTO which in xhci translates to
>>> 'USB transaction error"). When this happens it seems like xhci resets
>>> the ep, sets TR Deq Ptr to unstall the ep and then a new transfer is
>>> started which also fails.

Note that these are all xhci internal endpoint state operations, the device
(modem) is not seeing any of these changes on its side of the endpoint.

In 4.19  kernel xhci will give back the URB with transaction error with a
-EPROTO status Immediately in the interrupt handler.
A Transaction error, just like a stall error will cause the xHC internal
endpoint state to go to halted, xhci driver needs to reset the "xhci internal"
endpoint state to move it to a stopped state, and move tell xHC controller to
move past that URB in the ring buffer with a Set TR Deq ptr command
(clears xHC controller internal cache as well)

If the ring is not empty when Set TR Deq ptr completes, then driver restarts it.
In this case it appears cdc_acm managed to queue back the URB before this,
restarting the ring. This was repeated over and over again.

>>> This behavior generates a lot of events on
>>> the event ring which causes 'ERROR unknown event type 37'. This loop
>>> of failing transfers seems to continue until we either unbind the USB driver or
>> get a kernel panic. The SoC almost becomes unresponsive since it spends most
>> of the time executing usb interrupts.
>>>
>>> If I pull the reset pin of the USB hub and keep it in reset state at
>>> this point, the event loop of failing transfers continues despite
>>> there is nothing on the USB bus any longer. The only way to get out of that
>> loop is to either unbind the usb driver or power cycle the board.
>>>
>>> Is this the expected behavior when USB transaction error happens for all
>> transfers when using cdc-acm class driver?
>>> Or could there be something wrong in the low level USB driver (Cadence
>>> in our case)? We need to figure out why we get all the transaction errors but
>> we also need to make sure the kernel does not die on us when we have a
>> misbehaving USB device.
>>> Does anyone have a suggestion on what we could do to improve the stability
>> of the kernel in this situation?
>>
>> I would blame the xhci-cdns driver as it is the one controlling all of this.
>>
>> I don't see this driver in the 4.19 tree, so I think you are going to have to get
>> support from the company that provided you with that driver as you are already
>> paying for that support from them :)
>>
>> good luck!
>>
>> greg k-h
> 
> Thanks for the feedback! If the cadence driver is the main suspect I totally agree with you.
> 
> The reason I posted on this mailing list was that I was afraid that the cdc-acm driver could
> be causing new transfers to be started when the previous fails due to USB transaction errors and
> then trigger this event storm.
> The acm_ctrl_irq() function seems to submit a new urb directly if the previous fails, but I cannot 
> say that I understand that code very well yet. The acm_read_bulk_callback() function also seem
> to submit a new read urb on USB transaction Errors. But If you think this could not cause this
> behavior I will ask our supplier to fix the cdns driver.
> 
> BR,
> Jonas
> 

I recently got a report about a bit similar issue on a 4.4 stable kernel, so this
might not be xhci-cdns specific.

That case involved autosuspend of the cdc-acm, and there was only a short burst of
transaction erros and resubmitted URBs even if the device was supposed to be suspended.
It looks like cdc_acm autosuspended even if it had URBs pending.

I'm guessing that in that case the transfer ring restarted even if link was already "suspeded",
causing transaction errors. Ring could be restarted if URBs were resubmitted
by the class driver when usb core suspends all interfaces, flushing all pending URBs which
calls the URB completion handler.

-Mathias

Re: USB transaction errors causing RCU stalls and kernel panics

[Oliver Neukum]

Am Mittwoch, den 04.03.2020, 14:11 +0200 schrieb Mathias Nyman:
> On 3.3.2020 22.08, Jonas Karlsson wrote:

> 
> I recently got a report about a bit similar issue on a 4.4 stable kernel, so this
> might not be xhci-cdns specific.
> 
> That case involved autosuspend of the cdc-acm, and there was only a short burst of
> transaction erros and resubmitted URBs even if the device was supposed to be suspended.
> It looks like cdc_acm autosuspended even if it had URBs pending.

That must not happen. Do you have details?

> I'm guessing that in that case the transfer ring restarted even if link was already "suspeded",
> causing transaction errors. Ring could be restarted if URBs were resubmitted
> by the class driver when usb core suspends all interfaces, flushing all pending URBs which
> calls the URB completion handler.

How should a class driver do that? It gets -EPROTO and that's it,

	Regards
		Oliver

Re: USB transaction errors causing RCU stalls and kernel panics

[Mathias Nyman]

On 4.3.2020 16.12, Oliver Neukum wrote:
> Am Mittwoch, den 04.03.2020, 14:11 +0200 schrieb Mathias Nyman:
>> On 3.3.2020 22.08, Jonas Karlsson wrote:
> 
>>
>> I recently got a report about a bit similar issue on a 4.4 stable kernel, so this
>> might not be xhci-cdns specific.
>>
>> That case involved autosuspend of the cdc-acm, and there was only a short burst of
>> transaction erros and resubmitted URBs even if the device was supposed to be suspended.
>> It looks like cdc_acm autosuspended even if it had URBs pending.
> 
> That must not happen. Do you have details?

Shared what I got in:
https://drive.google.com/open?id=1PjwmIK97bIfugWL697lJCe65yuDVOZhx

cdc-acm is unfortunately not traced, but usb core and xhci is.
grep for "MATTU" to find the relevant places. 

> 
>> I'm guessing that in that case the transfer ring restarted even if link was already "suspeded",
>> causing transaction errors. Ring could be restarted if URBs were resubmitted
>> by the class driver when usb core suspends all interfaces, flushing all pending URBs which
>> calls the URB completion handler.
> 
> How should a class driver do that? It gets -EPROTO and that's it,
> 
> 	Regards
> 		Oliver
> 

This is just my speculation, I haven't checked details yet.

It's not just the class driver that causes this, but a combination of
the following gaps in xhci, cdc-acm, and usb core.

A class driver autosuspending with URBs pending,
and not killing all URBs synchronously when usb core calls suspend for the interface drivers.

xhci restarting an endpoint ring due to a race between xhci_stop_device(), handling 
a Transaction error, and having pending URB (unhandled trb) on the ring. [1]

Sleeping between setting port to U3 link state, and clearing udev->can_submit.
allowing URBs to be submitted during that gap when link is in U3 already.
URBs will complete with -EPROTO, and resubmitted until udev->can_submit is cleared.

usb_runtime_suspend()      
  usb_suspend_both() // suspend a device and its interfaces
    for (each udev->actconfig->interface)
      usb_suspend_interface(udev, intf, msg);
	driver = to_usb_driver(intf->dev.driver);
	status = driver->suspend(intf, msg);  // URBs shuold be killed, sync, miss one??
    usb_suspend_device()
      generic_suspend()
        usb_port_suspend()
          hub_set_port_link_state(USB_SS_PORT_LS_U3)
            xhci_stop_device()
            xhci_set_link_state(USB_SS_PORT_LS_U3)  // port link is in U3
            msleep()       // during this URBs can be resubmitteded and complete with -EPROTO loop       
    udev->can_submit = 0;  // we can submit URBs until here (except the killed ones, they are flagged).
    for (each endpoint)
      usb_hcd_flush_endpoint(udev, udev->ep_out[i]);
      usb_hcd_flush_endpoint(udev, udev->ep_in[i]);

[1]
xhci_stop_device()
  xhci_queue_stop_endpoint()
-> interrupt (transfer event, ring has not stopped yet)
  handle_tx_event()  // bulk transfer with Transaction error
    process_bulk_intr_td()
      finish_td()
	xhci_cleanup_halted_endpoint()
          xhci_queue_reset_ep()
          xhci_queue_new_dequeue_state()
-> interupt, command completion event for stop endpoint, 
-> interrupt handle reset_ep command, xhci_handle_cmd_stop_ep()
-> interrupt handle new deq state
      xhci_handle_cmd_set_deq()
	ring_doorbell_for_active_rings(xhci, slot_id, ep_index)  - this restarts the ring.

-Mathias

RE: USB transaction errors causing RCU stalls and kernel panics

[Peter Chen]

 
> >>
> >> I recently got a report about a bit similar issue on a 4.4 stable
> >> kernel, so this might not be xhci-cdns specific.
> >>
> >> That case involved autosuspend of the cdc-acm, and there was only a
> >> short burst of transaction erros and resubmitted URBs even if the device was
> supposed to be suspended.
> >> It looks like cdc_acm autosuspended even if it had URBs pending.
> >
> > That must not happen. Do you have details?
> 
> Shared what I got in:
> https://eur01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fdrive.google.
> com%2Fopen%3Fid%3D1PjwmIK97bIfugWL697lJCe65yuDVOZhx&data=02%
> 7C01%7Cpeter.chen%40nxp.com%7C3c5815ca5ec345be017508d7c057cc6d%7C6
> 86ea1d3bc2b4c6fa92cd99c5c301635%7C0%7C0%7C637189355630062080&
> sdata=O146bkkswCyFhoBTy92uDtMY%2Bn43ho78%2F69IxjuXE2M%3D&res
> erved=0
> 
> cdc-acm is unfortunately not traced, but usb core and xhci is.
> grep for "MATTU" to find the relevant places.
> 
> >
> >> I'm guessing that in that case the transfer ring restarted even if
> >> link was already "suspeded", causing transaction errors. Ring could
> >> be restarted if URBs were resubmitted by the class driver when usb
> >> core suspends all interfaces, flushing all pending URBs which calls the URB
> completion handler.
> >
> > How should a class driver do that? It gets -EPROTO and that's it,
> >
> > 	Regards
> > 		Oliver
> >
> 
> This is just my speculation, I haven't checked details yet.
> 
> It's not just the class driver that causes this, but a combination of the following gaps
> in xhci, cdc-acm, and usb core.
> 
> A class driver autosuspending with URBs pending, and not killing all URBs
> synchronously when usb core calls suspend for the interface drivers.
> 
> xhci restarting an endpoint ring due to a race between xhci_stop_device(), handling
> a Transaction error, and having pending URB (unhandled trb) on the ring. [1]
> 
> Sleeping between setting port to U3 link state, and clearing udev->can_submit.
> allowing URBs to be submitted during that gap when link is in U3 already.
> URBs will complete with -EPROTO, and resubmitted until udev->can_submit is
> cleared.
> 
> usb_runtime_suspend()
>   usb_suspend_both() // suspend a device and its interfaces
>     for (each udev->actconfig->interface)
>       usb_suspend_interface(udev, intf, msg);
> 	driver = to_usb_driver(intf->dev.driver);
> 	status = driver->suspend(intf, msg);  // URBs shuold be killed, sync, miss
> one??
>     usb_suspend_device()
>       generic_suspend()
>         usb_port_suspend()
>           hub_set_port_link_state(USB_SS_PORT_LS_U3)
>             xhci_stop_device()
>             xhci_set_link_state(USB_SS_PORT_LS_U3)  // port link is in U3
>             msleep()       // during this URBs can be resubmitteded and complete with -
> EPROTO loop
>     udev->can_submit = 0;  // we can submit URBs until here (except the killed ones,
> they are flagged).
>     for (each endpoint)
>       usb_hcd_flush_endpoint(udev, udev->ep_out[i]);
>       usb_hcd_flush_endpoint(udev, udev->ep_in[i]);
> 
> [1]
> xhci_stop_device()
>   xhci_queue_stop_endpoint()
> -> interrupt (transfer event, ring has not stopped yet)
>   handle_tx_event()  // bulk transfer with Transaction error
>     process_bulk_intr_td()
>       finish_td()
> 	xhci_cleanup_halted_endpoint()
>           xhci_queue_reset_ep()
>           xhci_queue_new_dequeue_state()
> -> interupt, command completion event for stop endpoint, interrupt
> -> handle reset_ep command, xhci_handle_cmd_stop_ep() interrupt handle
> -> new deq state
>       xhci_handle_cmd_set_deq()
> 	ring_doorbell_for_active_rings(xhci, slot_id, ep_index)  - this restarts the ring.
> 

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

RE: USB transaction errors causing RCU stalls and kernel panics

[Jonas Karlsson]

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

> 
> 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.

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

[-- Attachment #2: usb_transaction_errors.txt --]
[-- Type: text/plain, Size: 3863 bytes --]

[  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

Re: USB transaction errors causing RCU stalls and kernel panics

[Peter Chen]

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

RE: USB transaction errors causing RCU stalls and kernel panics

[Jonas Karlsson]

> 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
>

Yes, I have applied that commit. The logs I have attached so far have had that commit applied.
It reduces the amount of Unknown event type 37 messages significantly.
 
> @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

Re: USB transaction errors causing RCU stalls and kernel panics

[Oliver Neukum]

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

Am Dienstag, den 10.03.2020, 10:04 +0000 schrieb Jonas Karlsson:

> Yes, I have applied that commit. The logs I have attached so far have had that commit applied.
> It reduces the amount of Unknown event type 37 messages significantly.

I am a bit confused. If this still happens after you disabled
autosuspend, the initial diagnosis can't be right. It looks
like we are entering some kind of busy loop. Can you test
the attached patches?

	Regards
		Oliver

[-- Attachment #2: 0001-cdc-acm-close-race-betrween-suspend-and-acm_softint.patch --]
[-- Type: text/x-patch, Size: 1396 bytes --]

From e5f91fa32e5294b764ed93615c20834ee3ba690e Mon Sep 17 00:00:00 2001
From: Oliver Neukum <oneukum@suse.com>
Date: Thu, 5 Mar 2020 11:16:02 +0100
Subject: [PATCH 1/2] cdc-acm: close race betrween suspend() and acm_softint

Suspend increments a counter, then kills the URBs,
then kills the scheduled work. The scheduled work, however,
may reschedule the URBs. Fix this by having the work
check the counter.

Signed-off-by: Oliver Neukum <oneukum@suse.com>
---
 drivers/usb/class/cdc-acm.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/drivers/usb/class/cdc-acm.c b/drivers/usb/class/cdc-acm.c
index 62f4fb9b362f..7d0167382c87 100644
--- a/drivers/usb/class/cdc-acm.c
+++ b/drivers/usb/class/cdc-acm.c
@@ -557,14 +557,14 @@ static void acm_softint(struct work_struct *work)
 	struct acm *acm = container_of(work, struct acm, work);
 
 	if (test_bit(EVENT_RX_STALL, &acm->flags)) {
-		if (!(usb_autopm_get_interface(acm->data))) {
+		smp_mb(); /* against acm_suspend() */
+		if (!acm->susp_count) {
 			for (i = 0; i < acm->rx_buflimit; i++)
 				usb_kill_urb(acm->read_urbs[i]);
 			usb_clear_halt(acm->dev, acm->in);
 			acm_submit_read_urbs(acm, GFP_KERNEL);
-			usb_autopm_put_interface(acm->data);
+			clear_bit(EVENT_RX_STALL, &acm->flags);
 		}
-		clear_bit(EVENT_RX_STALL, &acm->flags);
 	}
 
 	if (test_and_clear_bit(EVENT_TTY_WAKEUP, &acm->flags))
-- 
2.16.4


[-- Attachment #3: 0002-cdc-acm-introduce-a-cool-down.patch --]
[-- Type: text/x-patch, Size: 4603 bytes --]

From 46f8fe7dbc51d6476bd8589dcbf0fc8a76e94102 Mon Sep 17 00:00:00 2001
From: Oliver Neukum <oneukum@suse.com>
Date: Tue, 10 Mar 2020 11:55:21 +0100
Subject: [PATCH 2/2] cdc-acm: introduce a cool down

Immediate submission in case of a babbling device can lead
to a busy loop. Introducing a delayed work.

Signed-off-by: Oliver Neukum <oneukum@suse.com>
---
 drivers/usb/class/cdc-acm.c | 29 +++++++++++++++++++++++++++--
 drivers/usb/class/cdc-acm.h |  5 ++++-
 2 files changed, 31 insertions(+), 3 deletions(-)

diff --git a/drivers/usb/class/cdc-acm.c b/drivers/usb/class/cdc-acm.c
index 7d0167382c87..a1fbf6bf5cf4 100644
--- a/drivers/usb/class/cdc-acm.c
+++ b/drivers/usb/class/cdc-acm.c
@@ -412,9 +412,12 @@ static void acm_ctrl_irq(struct urb *urb)
 
 exit:
 	retval = usb_submit_urb(urb, GFP_ATOMIC);
-	if (retval && retval != -EPERM)
+	if (retval && retval != -EPERM && retval != -ENODEV)
 		dev_err(&acm->control->dev,
 			"%s - usb_submit_urb failed: %d\n", __func__, retval);
+	else
+		dev_vdbg(&acm->control->dev,
+			"control resubmission terminated %d\n", retval);
 }
 
 static int acm_submit_read_urb(struct acm *acm, int index, gfp_t mem_flags)
@@ -430,6 +433,8 @@ static int acm_submit_read_urb(struct acm *acm, int index, gfp_t mem_flags)
 			dev_err(&acm->data->dev,
 				"urb %d failed submission with %d\n",
 				index, res);
+		} else {
+			dev_vdbg(&acm->data->dev, "intended failure %d\n", res);
 		}
 		set_bit(index, &acm->read_urbs_free);
 		return res;
@@ -471,6 +476,7 @@ static void acm_read_bulk_callback(struct urb *urb)
 	int status = urb->status;
 	bool stopped = false;
 	bool stalled = false;
+	bool cooldown = false;
 
 	dev_vdbg(&acm->data->dev, "got urb %d, len %d, status %d\n",
 		rb->index, urb->actual_length, status);
@@ -497,6 +503,13 @@ static void acm_read_bulk_callback(struct urb *urb)
 			__func__, status);
 		stopped = true;
 		break;
+	case -EOVERFLOW:
+		dev_dbg(&acm->data->dev,
+			"%s - cooling babbling device\n", __func__);
+		usb_mark_last_busy(acm->dev);
+		set_bit(rb->index, &acm->urbs_in_error_delay);
+		cooldown = true;
+		break;
 	default:
 		dev_dbg(&acm->data->dev,
 			"%s - nonzero urb status received: %d\n",
@@ -518,9 +531,11 @@ static void acm_read_bulk_callback(struct urb *urb)
 	 */
 	smp_mb__after_atomic();
 
-	if (stopped || stalled) {
+	if (stopped || stalled || cooldown) {
 		if (stalled)
 			schedule_work(&acm->work);
+		else if (cooldown)
+			schedule_delayed_work(&acm->dwork, HZ / 2);
 		return;
 	}
 
@@ -567,6 +582,12 @@ static void acm_softint(struct work_struct *work)
 		}
 	}
 
+	if (test_and_clear_bit(ACM_ERROR_DELAY, &acm->flags)) {
+		for (i = 0; i < ACM_NR; i++) 
+			if (test_and_clear_bit(i, &acm->urbs_in_error_delay))
+					acm_submit_read_urb(acm, i, GFP_NOIO);
+	}
+
 	if (test_and_clear_bit(EVENT_TTY_WAKEUP, &acm->flags))
 		tty_port_tty_wakeup(&acm->port);
 }
@@ -1325,6 +1346,7 @@ static int acm_probe(struct usb_interface *intf,
 	acm->readsize = readsize;
 	acm->rx_buflimit = num_rx_buf;
 	INIT_WORK(&acm->work, acm_softint);
+	INIT_DELAYED_WORK(&acm->dwork, acm_softint);
 	init_waitqueue_head(&acm->wioctl);
 	spin_lock_init(&acm->write_lock);
 	spin_lock_init(&acm->read_lock);
@@ -1534,6 +1556,7 @@ static void acm_disconnect(struct usb_interface *intf)
 
 	acm_kill_urbs(acm);
 	cancel_work_sync(&acm->work);
+	cancel_delayed_work_sync(&acm->dwork);
 
 	tty_unregister_device(acm_tty_driver, acm->minor);
 
@@ -1576,6 +1599,8 @@ static int acm_suspend(struct usb_interface *intf, pm_message_t message)
 
 	acm_kill_urbs(acm);
 	cancel_work_sync(&acm->work);
+	cancel_delayed_work_sync(&acm->dwork);
+	acm->urbs_in_error_delay = 0;
 
 	return 0;
 }
diff --git a/drivers/usb/class/cdc-acm.h b/drivers/usb/class/cdc-acm.h
index ca1c026382c2..cd5e9d8ab237 100644
--- a/drivers/usb/class/cdc-acm.h
+++ b/drivers/usb/class/cdc-acm.h
@@ -109,8 +109,11 @@ struct acm {
 #		define EVENT_TTY_WAKEUP	0
 #		define EVENT_RX_STALL	1
 #		define ACM_THROTTLED	2
+#		define ACM_ERROR_DELAY	3
+	unsigned long urbs_in_error_delay;		/* these need to be restarted after a delay */
 	struct usb_cdc_line_coding line;		/* bits, stop, parity */
-	struct work_struct work;			/* work queue entry for line discipline waking up */
+	struct work_struct work;			/* work queue entry for various purposes*/
+	struct delayed_work dwork;			/* for cool downs needed in error recovery */
 	unsigned int ctrlin;				/* input control lines (DCD, DSR, RI, break, overruns) */
 	unsigned int ctrlout;				/* output control lines (DTR, RTS) */
 	struct async_icount iocount;			/* counters for control line changes */
-- 
2.16.4

Re: USB transaction errors causing RCU stalls and kernel panics

[Oliver Neukum]

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

Am Dienstag, den 10.03.2020, 12:04 +0100 schrieb Oliver Neukum:
> Am Dienstag, den 10.03.2020, 10:04 +0000 schrieb Jonas Karlsson:
> 
> > Yes, I have applied that commit. The logs I have attached so far have had that commit applied.
> > It reduces the amount of Unknown event type 37 messages significantly.
> 
> I am a bit confused. If this still happens after you disabled
> autosuspend, the initial diagnosis can't be right. It looks
> like we are entering some kind of busy loop. Can you test
> the attached patches?

Correction: please test these three patches.

	Regards
		Oliver

[-- Attachment #2: 0001-cdc-acm-close-race-betrween-suspend-and-acm_softint.patch --]
[-- Type: text/x-patch, Size: 1396 bytes --]

From e5f91fa32e5294b764ed93615c20834ee3ba690e Mon Sep 17 00:00:00 2001
From: Oliver Neukum <oneukum@suse.com>
Date: Thu, 5 Mar 2020 11:16:02 +0100
Subject: [PATCH 1/3] cdc-acm: close race betrween suspend() and acm_softint

Suspend increments a counter, then kills the URBs,
then kills the scheduled work. The scheduled work, however,
may reschedule the URBs. Fix this by having the work
check the counter.

Signed-off-by: Oliver Neukum <oneukum@suse.com>
---
 drivers/usb/class/cdc-acm.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/drivers/usb/class/cdc-acm.c b/drivers/usb/class/cdc-acm.c
index 62f4fb9b362f..7d0167382c87 100644
--- a/drivers/usb/class/cdc-acm.c
+++ b/drivers/usb/class/cdc-acm.c
@@ -557,14 +557,14 @@ static void acm_softint(struct work_struct *work)
 	struct acm *acm = container_of(work, struct acm, work);
 
 	if (test_bit(EVENT_RX_STALL, &acm->flags)) {
-		if (!(usb_autopm_get_interface(acm->data))) {
+		smp_mb(); /* against acm_suspend() */
+		if (!acm->susp_count) {
 			for (i = 0; i < acm->rx_buflimit; i++)
 				usb_kill_urb(acm->read_urbs[i]);
 			usb_clear_halt(acm->dev, acm->in);
 			acm_submit_read_urbs(acm, GFP_KERNEL);
-			usb_autopm_put_interface(acm->data);
+			clear_bit(EVENT_RX_STALL, &acm->flags);
 		}
-		clear_bit(EVENT_RX_STALL, &acm->flags);
 	}
 
 	if (test_and_clear_bit(EVENT_TTY_WAKEUP, &acm->flags))
-- 
2.16.4


[-- Attachment #3: 0002-cdc-acm-introduce-a-cool-down.patch --]
[-- Type: text/x-patch, Size: 4603 bytes --]

From 46f8fe7dbc51d6476bd8589dcbf0fc8a76e94102 Mon Sep 17 00:00:00 2001
From: Oliver Neukum <oneukum@suse.com>
Date: Tue, 10 Mar 2020 11:55:21 +0100
Subject: [PATCH 2/3] cdc-acm: introduce a cool down

Immediate submission in case of a babbling device can lead
to a busy loop. Introducing a delayed work.

Signed-off-by: Oliver Neukum <oneukum@suse.com>
---
 drivers/usb/class/cdc-acm.c | 29 +++++++++++++++++++++++++++--
 drivers/usb/class/cdc-acm.h |  5 ++++-
 2 files changed, 31 insertions(+), 3 deletions(-)

diff --git a/drivers/usb/class/cdc-acm.c b/drivers/usb/class/cdc-acm.c
index 7d0167382c87..a1fbf6bf5cf4 100644
--- a/drivers/usb/class/cdc-acm.c
+++ b/drivers/usb/class/cdc-acm.c
@@ -412,9 +412,12 @@ static void acm_ctrl_irq(struct urb *urb)
 
 exit:
 	retval = usb_submit_urb(urb, GFP_ATOMIC);
-	if (retval && retval != -EPERM)
+	if (retval && retval != -EPERM && retval != -ENODEV)
 		dev_err(&acm->control->dev,
 			"%s - usb_submit_urb failed: %d\n", __func__, retval);
+	else
+		dev_vdbg(&acm->control->dev,
+			"control resubmission terminated %d\n", retval);
 }
 
 static int acm_submit_read_urb(struct acm *acm, int index, gfp_t mem_flags)
@@ -430,6 +433,8 @@ static int acm_submit_read_urb(struct acm *acm, int index, gfp_t mem_flags)
 			dev_err(&acm->data->dev,
 				"urb %d failed submission with %d\n",
 				index, res);
+		} else {
+			dev_vdbg(&acm->data->dev, "intended failure %d\n", res);
 		}
 		set_bit(index, &acm->read_urbs_free);
 		return res;
@@ -471,6 +476,7 @@ static void acm_read_bulk_callback(struct urb *urb)
 	int status = urb->status;
 	bool stopped = false;
 	bool stalled = false;
+	bool cooldown = false;
 
 	dev_vdbg(&acm->data->dev, "got urb %d, len %d, status %d\n",
 		rb->index, urb->actual_length, status);
@@ -497,6 +503,13 @@ static void acm_read_bulk_callback(struct urb *urb)
 			__func__, status);
 		stopped = true;
 		break;
+	case -EOVERFLOW:
+		dev_dbg(&acm->data->dev,
+			"%s - cooling babbling device\n", __func__);
+		usb_mark_last_busy(acm->dev);
+		set_bit(rb->index, &acm->urbs_in_error_delay);
+		cooldown = true;
+		break;
 	default:
 		dev_dbg(&acm->data->dev,
 			"%s - nonzero urb status received: %d\n",
@@ -518,9 +531,11 @@ static void acm_read_bulk_callback(struct urb *urb)
 	 */
 	smp_mb__after_atomic();
 
-	if (stopped || stalled) {
+	if (stopped || stalled || cooldown) {
 		if (stalled)
 			schedule_work(&acm->work);
+		else if (cooldown)
+			schedule_delayed_work(&acm->dwork, HZ / 2);
 		return;
 	}
 
@@ -567,6 +582,12 @@ static void acm_softint(struct work_struct *work)
 		}
 	}
 
+	if (test_and_clear_bit(ACM_ERROR_DELAY, &acm->flags)) {
+		for (i = 0; i < ACM_NR; i++) 
+			if (test_and_clear_bit(i, &acm->urbs_in_error_delay))
+					acm_submit_read_urb(acm, i, GFP_NOIO);
+	}
+
 	if (test_and_clear_bit(EVENT_TTY_WAKEUP, &acm->flags))
 		tty_port_tty_wakeup(&acm->port);
 }
@@ -1325,6 +1346,7 @@ static int acm_probe(struct usb_interface *intf,
 	acm->readsize = readsize;
 	acm->rx_buflimit = num_rx_buf;
 	INIT_WORK(&acm->work, acm_softint);
+	INIT_DELAYED_WORK(&acm->dwork, acm_softint);
 	init_waitqueue_head(&acm->wioctl);
 	spin_lock_init(&acm->write_lock);
 	spin_lock_init(&acm->read_lock);
@@ -1534,6 +1556,7 @@ static void acm_disconnect(struct usb_interface *intf)
 
 	acm_kill_urbs(acm);
 	cancel_work_sync(&acm->work);
+	cancel_delayed_work_sync(&acm->dwork);
 
 	tty_unregister_device(acm_tty_driver, acm->minor);
 
@@ -1576,6 +1599,8 @@ static int acm_suspend(struct usb_interface *intf, pm_message_t message)
 
 	acm_kill_urbs(acm);
 	cancel_work_sync(&acm->work);
+	cancel_delayed_work_sync(&acm->dwork);
+	acm->urbs_in_error_delay = 0;
 
 	return 0;
 }
diff --git a/drivers/usb/class/cdc-acm.h b/drivers/usb/class/cdc-acm.h
index ca1c026382c2..cd5e9d8ab237 100644
--- a/drivers/usb/class/cdc-acm.h
+++ b/drivers/usb/class/cdc-acm.h
@@ -109,8 +109,11 @@ struct acm {
 #		define EVENT_TTY_WAKEUP	0
 #		define EVENT_RX_STALL	1
 #		define ACM_THROTTLED	2
+#		define ACM_ERROR_DELAY	3
+	unsigned long urbs_in_error_delay;		/* these need to be restarted after a delay */
 	struct usb_cdc_line_coding line;		/* bits, stop, parity */
-	struct work_struct work;			/* work queue entry for line discipline waking up */
+	struct work_struct work;			/* work queue entry for various purposes*/
+	struct delayed_work dwork;			/* for cool downs needed in error recovery */
 	unsigned int ctrlin;				/* input control lines (DCD, DSR, RI, break, overruns) */
 	unsigned int ctrlout;				/* output control lines (DTR, RTS) */
 	struct async_icount iocount;			/* counters for control line changes */
-- 
2.16.4


[-- Attachment #4: 0003-cdc-acm-also-cool-doen-for-EPROTO.patch --]
[-- Type: text/x-patch, Size: 714 bytes --]

From c5a8ca0a79adfea9dda5ee51f23cf09891687a24 Mon Sep 17 00:00:00 2001
From: Oliver Neukum <oneukum@suse.com>
Date: Tue, 10 Mar 2020 12:19:53 +0100
Subject: [PATCH 3/3] cdc-acm: also cool doen for EPROTO

---
 drivers/usb/class/cdc-acm.c | 1 +
 1 file changed, 1 insertion(+)

diff --git a/drivers/usb/class/cdc-acm.c b/drivers/usb/class/cdc-acm.c
index a1fbf6bf5cf4..82484cc6c36f 100644
--- a/drivers/usb/class/cdc-acm.c
+++ b/drivers/usb/class/cdc-acm.c
@@ -504,6 +504,7 @@ static void acm_read_bulk_callback(struct urb *urb)
 		stopped = true;
 		break;
 	case -EOVERFLOW:
+	case -EPROTO:
 		dev_dbg(&acm->data->dev,
 			"%s - cooling babbling device\n", __func__);
 		usb_mark_last_busy(acm->dev);
-- 
2.16.4

RE: USB transaction errors causing RCU stalls and kernel panics

[Jonas Karlsson]

> Am Dienstag, den 10.03.2020, 12:04 +0100 schrieb Oliver Neukum:
> > Am Dienstag, den 10.03.2020, 10:04 +0000 schrieb Jonas Karlsson:
> >
> > > Yes, I have applied that commit. The logs I have attached so far have had
> that commit applied.
> > > It reduces the amount of Unknown event type 37 messages significantly.
> >
> > I am a bit confused. If this still happens after you disabled
> > autosuspend, the initial diagnosis can't be right. It looks like we
> > are entering some kind of busy loop. Can you test the attached
> > patches?
> 
> Correction: please test these three patches.
> 
> 	Regards
>
 		Oliver

I can test the patches. However, they do not apply on my NXP 4.19.96 kernel.
The only difference between v4.19.105 and my NXP4.19.96 kernel is that we are lacking
this commit:

commit ae00e1f573f3621ba64110aa994a88ac0b3394c4
Author: Johan Hovold <johan@kernel.org>
Date:   Thu Apr 25 18:05:39 2019 +0200

    USB: cdc-acm: fix unthrottle races


However, the 0002-cdc-acm-introduce-a-cool-down.patch you sent me seem to be based on 
a newer kernel tree. It seems to depend on at least this commit which was introduced in v5.x:

commit 0f02321e4bd1b17eb957e077e868ef1611f5dbbd
Author: Johan Hovold <johan@kernel.org>
Date:   Thu Apr 25 18:05:40 2019 +0200

    USB: cdc-acm: clean up throttle handling

Please advice on how to proceed to make sure I test the code you intend.

BR,
Jonas

RE: USB transaction errors causing RCU stalls and kernel panics

[Jonas Karlsson]

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


> > Am Dienstag, den 10.03.2020, 12:04 +0100 schrieb Oliver Neukum:
> > > Am Dienstag, den 10.03.2020, 10:04 +0000 schrieb Jonas Karlsson:
> > >
> > > > Yes, I have applied that commit. The logs I have attached so far
> > > > have had
> > that commit applied.
> > > > It reduces the amount of Unknown event type 37 messages significantly.
> > >
> > > I am a bit confused. If this still happens after you disabled
> > > autosuspend, the initial diagnosis can't be right. It looks like we
> > > are entering some kind of busy loop. Can you test the attached
> > > patches?
> >
> > Correction: please test these three patches.
> >
> > 	Regards
> >
>  		Oliver
> 
> I can test the patches. However, they do not apply on my NXP 4.19.96 kernel.
> The only difference between v4.19.105 and my NXP4.19.96 kernel is that we are
> lacking this commit:
> 
> commit ae00e1f573f3621ba64110aa994a88ac0b3394c4
> Author: Johan Hovold <johan@kernel.org>
> Date:   Thu Apr 25 18:05:39 2019 +0200
> 
>     USB: cdc-acm: fix unthrottle races
> 
> 
> However, the 0002-cdc-acm-introduce-a-cool-down.patch you sent me seem to
> be based on a newer kernel tree. It seems to depend on at least this commit
> which was introduced in v5.x:
> 
> commit 0f02321e4bd1b17eb957e077e868ef1611f5dbbd
> Author: Johan Hovold <johan@kernel.org>
> Date:   Thu Apr 25 18:05:40 2019 +0200
> 
>     USB: cdc-acm: clean up throttle handling
> 
> Please advice on how to proceed to make sure I test the code you intend.
> 
> BR,
> Jonas

Hi Oliver,

I applied the patches you sent me. They did not apply cleanly, but it was pretty simple. 

I said that we used NXP kernel 4.19.96 which was wrong. Their latest kernel is 4.19.35. Sorry about that.

To summarize, I have applied the following USB related patches on our NXP 4.19.35 kernel:

commit 2337d89627e33c72a44dc3f0a1b7651a657c855e
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

commit 2afd5d96c2564b28987db1a6bdc998b731c7bcbc
Author: Johan Hovold <johan@kernel.org>
Date:   Thu Apr 25 18:05:39 2019 +0200

    USB: cdc-acm: fix unthrottle races

commit 7c8f7af078a4eda73f347667d12584736e613062
Author: Oliver Neukum <oneukum@suse.com>
Date:   Thu Mar 5 11:16:02 2020 +0100

    cdc-acm: close race betrween suspend() and acm_softint

From 46f8fe7dbc51d6476bd8589dcbf0fc8a76e94102 Mon Sep 17 00:00:00 2001
From: Oliver Neukum <oneukum@suse.com>
Date: Tue, 10 Mar 2020 11:55:21 +0100
Subject: [PATCH 2/3] cdc-acm: introduce a cool down

From c5a8ca0a79adfea9dda5ee51f23cf09891687a24 Mon Sep 17 00:00:00 2001
From: Oliver Neukum <oneukum@suse.com>
Date: Tue, 10 Mar 2020 12:19:53 +0100
Subject: [PATCH 3/3] cdc-acm: also cool doen for EPROTO

I have also _reverted_ this patch after recommendation from NXP to avoid RCU stall
crashes:

commit 077506972ba23772b752e08b1ab7052cf5f04511
Author: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
Date:   Mon Jul 9 13:47:30 2018 -0700

    rcu: Make need_resched() respond to urgent RCU-QS needs


Now I'm able to to pull the reset on the hub and/or disable vusb to the modem without
any event spam. The usb device is disconnected as you would expect.

Attached you find a log from when I disabled the vusb supply to the modem which previously
caused endless event loop.

I will try to get hold of a temp chamber to test the original problem where the modem misbehaved as well.

Thanks for all the help!

BR,
Jonas

[-- Attachment #2: log_from_cdc_acm_patches.txt --]
[-- Type: text/plain, Size: 86390 bytes --]

[  275.726479]  xhci-cdns3: // Setting command ring address to 0x96049001
[  275.726513]  xhci-cdns3: Port Status Change Event for port 1
[  275.726519]  xhci-cdns3: resume root hub
[  275.726528]  xhci-cdns3: port resume event for port 1
[  275.726534]  xhci-cdns3: resume HS port 1
[  275.726555]  xhci-cdns3: xhci_resume: starting port polling.
[  275.726563]  xhci-cdns3: xhci_hub_status_data: stopping port polling.
[  275.726612]  xhci-cdns3: get port status, actual port 0 status  = 0xfe3
[  275.726618]  xhci-cdns3: Get port status returned 0x507
[  275.726692]  xhci-cdns3: get port status, actual port 0 status  = 0x2a0
[  275.726697]  xhci-cdns3: Get port status returned 0x2a0
[  275.726768]  xhci-cdns3: set port remote wake mask, actual port 0 status  = 0xe0002a0
[  275.726843]  xhci-cdns3: xhci_hub_status_data: stopping port polling.
[  275.791220]  xhci-cdns3: Resume USB2 port 1
[  275.791243]  xhci-cdns3: Port Status Change Event for port 1
[  275.791276]  xhci-cdns3: get port status, actual port 0 status  = 0xfe3
[  275.791283]  xhci-cdns3: Get port status returned 0x40503
[  275.791323]  xhci-cdns3: clear port suspend/resume change, actual port 0 status  = 0xe03
[  275.811115]  xhci-cdns3: get port status, actual port 0 status  = 0xe03
[  275.811128]  xhci-cdns3: Get port status returned 0x503
[  275.919290]  xhci-cdns3: // Ding dong!
[  275.919358]  xhci-cdns3: Slot 5 output ctx = 0x96004000 (dma)
[  275.919367]  xhci-cdns3: Slot 5 input ctx = 0x960b6000 (dma)
[  275.919389]  xhci-cdns3: Set slot id 5 dcbaa entry 0000000080087af5 to 0x96004000
[  275.999179] usb 1-1.1: new high-speed USB device number 6 using cdns-usb3
[  276.006600]  xhci-cdns3: Set root hub portnum to 1
[  276.006607]  xhci-cdns3: Set fake root hub portnum to 1
[  276.006614]  xhci-cdns3: udev->tt =           (null)
[  276.006619]  xhci-cdns3: udev->ttport = 0x0
[  276.006635]  xhci-cdns3: // Ding dong!
[  276.006708]  xhci-cdns3: Successful setup context command
[  276.006717]  xhci-cdns3: Op regs DCBAA ptr = 0x00000096048000
[  276.006727]  xhci-cdns3: Slot ID 5 dcbaa entry @0000000080087af5 = 0x00000096004000
[  276.006732]  xhci-cdns3: Output Context DMA address = 0x96004000
[  276.006738]  xhci-cdns3: Internal device address = 0
[  276.006911]  xhci-cdns3: Waiting for status stage event
[  276.039025]  xhci-cdns3: xhci_hub_status_data: stopping port polling.
[  276.087111]  xhci-cdns3: Resetting device with slot ID 5
[  276.087135]  xhci-cdns3: // Ding dong!
[  276.087168]  xhci-cdns3: Completed reset device command.
[  276.087185]  xhci-cdns3: Can't reset device (slot ID 5) in default state
[  276.087190]  xhci-cdns3: Not freeing device rings.
[  276.087207]  xhci-cdns3: // Ding dong!
[  276.087441]  xhci-cdns3: Successful setup address command
[  276.087450]  xhci-cdns3: Op regs DCBAA ptr = 0x00000096048000
[  276.087461]  xhci-cdns3: Slot ID 5 dcbaa entry @0000000080087af5 = 0x00000096004000
[  276.087467]  xhci-cdns3: Output Context DMA address = 0x96004000
[  276.087472]  xhci-cdns3: Internal device address = 0
[  276.108584]  xhci-cdns3: Waiting for status stage event
[  276.108992]  xhci-cdns3: Waiting for status stage event
[  276.109377]  xhci-cdns3: Waiting for status stage event
[  276.109795]  xhci-cdns3: Waiting for status stage event
[  276.109996] usb 1-1.1: New USB device found, idVendor=1e2d, idProduct=0065, bcdDevice= 3.18
[  276.119125] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  276.128201] usb 1-1.1: Product: LTE Modem
[  276.132821] usb 1-1.1: Manufacturer: Cinterion
[  276.137791] usb 1-1.1: SerialNumber: 1b7ff837
[  276.145688]  xhci-cdns3: add ep 0x82, slot id 5, new drop flags = 0x0, new add flags = 0x20
[  276.145736]  xhci-cdns3: add ep 0x81, slot id 5, new drop flags = 0x0, new add flags = 0x28
[  276.145775]  xhci-cdns3: add ep 0x1, slot id 5, new drop flags = 0x0, new add flags = 0x2c
[  276.145815]  xhci-cdns3: add ep 0x84, slot id 5, new drop flags = 0x0, new add flags = 0x22c
[  276.145886]  xhci-cdns3: add ep 0x83, slot id 5, new drop flags = 0x0, new add flags = 0x2ac
[  276.145936]  xhci-cdns3: add ep 0x2, slot id 5, new drop flags = 0x0, new add flags = 0x2bc
[  276.145976]  xhci-cdns3: add ep 0x86, slot id 5, new drop flags = 0x0, new add flags = 0x22bc
[  276.146016]  xhci-cdns3: add ep 0x85, slot id 5, new drop flags = 0x0, new add flags = 0x2abc
[  276.146089]  xhci-cdns3: add ep 0x3, slot id 5, new drop flags = 0x0, new add flags = 0x2afc
[  276.146140]  xhci-cdns3: add ep 0x88, slot id 5, new drop flags = 0x0, new add flags = 0x22afc
[  276.146180]  xhci-cdns3: add ep 0x87, slot id 5, new drop flags = 0x0, new add flags = 0x2aafc
[  276.146228]  xhci-cdns3: add ep 0x4, slot id 5, new drop flags = 0x0, new add flags = 0x2abfc
[  276.146273]  xhci-cdns3: add ep 0x8a, slot id 5, new drop flags = 0x0, new add flags = 0x22abfc
[  276.146313]  xhci-cdns3: add ep 0x89, slot id 5, new drop flags = 0x0, new add flags = 0x2aabfc
[  276.146374]  xhci-cdns3: add ep 0x5, slot id 5, new drop flags = 0x0, new add flags = 0x2aaffc
[  276.146413]  xhci-cdns3: add ep 0x8b, slot id 5, new drop flags = 0x0, new add flags = 0xaaaffc
[  276.146421]  xhci-cdns3: xhci_check_bandwidth called for udev 00000000c343539e
[  276.146442]  xhci-cdns3: // Ding dong!
[  276.146571]  xhci-cdns3: Successful Endpoint Configure command
[  276.146608]  xhci-cdns3: // Ding dong!
[  276.146629]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 4
[  276.146651]  xhci-cdns3: // Ding dong!
[  276.146763]  xhci-cdns3: // Ding dong!
[  276.146776]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 2
[  276.146792]  xhci-cdns3: // Ding dong!
[  276.146885]  xhci-cdns3: // Ding dong!
[  276.146898]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 1
[  276.146914]  xhci-cdns3: // Ding dong!
[  276.147877]  xhci-cdns3: // Ding dong!
[  276.147899]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 8
[  276.147921]  xhci-cdns3: // Ding dong!
[  276.148062]  xhci-cdns3: // Ding dong!
[  276.148076]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 6
[  276.148146]  xhci-cdns3: // Ding dong!
[  276.148325]  xhci-cdns3: // Ding dong!
[  276.148339]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 3
[  276.148357]  xhci-cdns3: // Ding dong!
[  276.148455]  xhci-cdns3: // Ding dong!
[  276.148467]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 12
[  276.148487]  xhci-cdns3: // Ding dong!
[  276.148582]  xhci-cdns3: // Ding dong!
[  276.148596]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 10
[  276.148616]  xhci-cdns3: // Ding dong!
[  276.148702]  xhci-cdns3: // Ding dong!
[  276.148716]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 5
[  276.148732]  xhci-cdns3: // Ding dong!
[  276.148830]  xhci-cdns3: // Ding dong!
[  276.148846]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 16
[  276.148864]  xhci-cdns3: // Ding dong!
[  276.148960]  xhci-cdns3: // Ding dong!
[  276.148973]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 14
[  276.148992]  xhci-cdns3: // Ding dong!
[  276.149085]  xhci-cdns3: // Ding dong!
[  276.149105]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 7
[  276.149139]  xhci-cdns3: // Ding dong!
[  276.149322]  xhci-cdns3: // Ding dong!
[  276.149337]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 20
[  276.149387]  xhci-cdns3: // Ding dong!
[  276.149479]  xhci-cdns3: // Ding dong!
[  276.149492]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 18
[  276.149508]  xhci-cdns3: // Ding dong!
[  276.149588]  xhci-cdns3: // Ding dong!
[  276.149600]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 9
[  276.149621]  xhci-cdns3: // Ding dong!
[  276.149707]  xhci-cdns3: // Ding dong!
[  276.149719]  xhci-cdns3: Stopped on No-op or Link TRB for slot 5 ep 22
[  276.149739]  xhci-cdns3: // Ding dong!
[  276.152414]  xhci-cdns3: Waiting for status stage event
[  276.153319] cdc_acm 1-1.1:1.0: interfaces are valid
[  276.177479] cdc_acm 1-1.1:1.0: ttyACM0: USB ACM device
[  276.184230] cdc_acm 1-1.1:1.0: acm_ctrl_msg - rq 0x20, val 0x0, len 0x7, result 7
[  276.190215]  xhci-cdns3: Waiting for status stage event
[  276.191704]  xhci-cdns3: Waiting for status stage event
[  276.192368] cdc_acm 1-1.1:1.2: interfaces are valid
[  276.229056] cdc_acm 1-1.1:1.2: ttyACM1: USB ACM device
[  276.236281] cdc_acm 1-1.1:1.2: acm_ctrl_msg - rq 0x20, val 0x0, len 0x7, result 7
[  276.238934]  xhci-cdns3: Waiting for status stage event
[  276.241626]  xhci-cdns3: Waiting for status stage event
[  276.243191] cdc_acm 1-1.1:1.4: interfaces are valid
[  276.280722] cdc_acm 1-1.1:1.4: ttyACM2: USB ACM device
[  276.286670] cdc_acm 1-1.1:1.4: acm_ctrl_msg - rq 0x20, val 0x0, len 0x7, result 7
[  276.288260]  xhci-cdns3: Waiting for status stage event
[  276.289604]  xhci-cdns3: Waiting for status stage event
[  276.290366] cdc_acm 1-1.1:1.6: interfaces are valid
[  276.321212] cdc_acm 1-1.1:1.6: ttyACM3: USB ACM device
[  276.328106] cdc_acm 1-1.1:1.6: acm_ctrl_msg - rq 0x20, val 0x0, len 0x7, result 7
[  276.329475]  xhci-cdns3: Waiting for status stage event
[  276.330619]  xhci-cdns3: Waiting for status stage event
[  276.331338] cdc_acm 1-1.1:1.8: Separate call control interface. That is not fully supported.
[  276.331348] cdc_acm 1-1.1:1.8: interfaces are valid
[  276.356686] cdc_acm 1-1.1:1.8: ttyACM4: USB ACM device
[  276.362245]  xhci-cdns3: Stalled endpoint for slot 5 ep 0
[  276.362271]  xhci-cdns3: Cleaning up stalled endpoint ring
[  276.362276]  xhci-cdns3: Finding endpoint context
[  276.362282]  xhci-cdns3: Cycle state = 0x1
[  276.362288]  xhci-cdns3: New dequeue segment = 000000003183b8fa (virtual)
[  276.362293]  xhci-cdns3: New dequeue pointer = 0x960e3440 (DMA)
[  276.362297]  xhci-cdns3: Queueing new dequeue state
[  276.362305]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000003183b8fa (0x960e3000 dma), new deq ptr = 000000006d2b156c (0x960e3440 dma), new cycle = 1
[  276.362311]  xhci-cdns3: // Ding dong!
[  276.362320]  xhci-cdns3: Giveback URB 00000000a969eeeb, len = 0, expected = 7, status = -32
[  276.362340]  xhci-cdns3: Ignoring reset ep completion code of 1
[  276.362351]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960e3440
[  276.362420] cdc_acm 1-1.1:1.8: acm_ctrl_msg - rq 0x20, val 0x0, len 0x7, result -32
[  276.363891]  xhci-cdns3: Waiting for status stage event
[  276.365031]  xhci-cdns3: Waiting for status stage event
[  276.949805] cdc_acm 1-1.1:1.4: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0
[  277.368443] cdc_acm 1-1.1:1.0: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0
[  277.368711] cdc_acm 1-1.1:1.0: acm_ctrl_msg - rq 0x22, val 0x2, len 0x0, result 0
[  277.368984] cdc_acm 1-1.1:1.0: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0
[  277.369571] cdc_acm 1-1.1:1.2: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0
[  277.369839] cdc_acm 1-1.1:1.2: acm_ctrl_msg - rq 0x22, val 0x2, len 0x0, result 0
[  277.370115] cdc_acm 1-1.1:1.2: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0
[  277.370863] cdc_acm 1-1.1:1.6: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0
[  277.378124] cdc_acm 1-1.1:1.6: acm_ctrl_msg - rq 0x22, val 0x2, len 0x0, result 0
[  277.378404] cdc_acm 1-1.1:1.6: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0
[  287.421097]  xhci-cdns3: Transfer error for slot 5 ep 5 on endpoint
[  287.421129]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.421135]  xhci-cdns3: Finding endpoint context
[  287.421143]  xhci-cdns3: Cycle state = 0x1
[  287.421151]  xhci-cdns3: New dequeue segment = 000000002c1981c7 (virtual)
[  287.421157]  xhci-cdns3: New dequeue pointer = 0x960cf010 (DMA)
[  287.421163]  xhci-cdns3: Queueing new dequeue state
[  287.421173]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000002c1981c7 (0x960cf000 dma), new deq ptr = 000000008609ff97 (0x960cf010 dma), new cycle = 1
[  287.421182]  xhci-cdns3: // Ding dong!
[  287.421192]  xhci-cdns3: Giveback URB 0000000044b695ce, len = 0, expected = 16, status = -71
[  287.421223]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.421236]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.421241]  xhci-cdns3: Finding endpoint context
[  287.421247]  xhci-cdns3: Cycle state = 0x1
[  287.421255]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.421262]  xhci-cdns3: New dequeue pointer = 0x960d7010 (DMA)
[  287.421270]  xhci-cdns3: Queueing new dequeue state
[  287.421279]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 00000000b5c28959 (0x960d7010 dma), new cycle = 1
[  287.421287]  xhci-cdns3: // Ding dong!
[  287.421295]  xhci-cdns3: Giveback URB 00000000eb08ffa6, len = 0, expected = 1024, status = -71
[  287.421309] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.421321]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.421333]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.421340]  xhci-cdns3: Finding endpoint context
[  287.421346]  xhci-cdns3: Cycle state = 0x1
[  287.421352]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.421359]  xhci-cdns3: New dequeue pointer = 0x960d1010 (DMA)
[  287.421366]  xhci-cdns3: Queueing new dequeue state
[  287.421377]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 00000000abe64d05 (0x960d1010 dma), new cycle = 1
[  287.421384]  xhci-cdns3: // Ding dong!
[  287.421393]  xhci-cdns3: Giveback URB 00000000b23efa8e, len = 0, expected = 1024, status = -71
[  287.421402] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.421414]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.421426]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.421432]  xhci-cdns3: Finding endpoint context
[  287.421438]  xhci-cdns3: Cycle state = 0x1
[  287.421444]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.421454]  xhci-cdns3: New dequeue pointer = 0x960cb010 (DMA)
[  287.421460]  xhci-cdns3: Queueing new dequeue state
[  287.421471]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 000000006125270d (0x960cb010 dma), new cycle = 1
[  287.421477]  xhci-cdns3: // Ding dong!
[  287.421487]  xhci-cdns3: Giveback URB 00000000d85a56f9, len = 0, expected = 1024, status = -71
[  287.421496] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.421507]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.421519]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.421524]  xhci-cdns3: Finding endpoint context
[  287.421530]  xhci-cdns3: Cycle state = 0x1
[  287.421537]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.421545]  xhci-cdns3: New dequeue pointer = 0x960dd010 (DMA)
[  287.421551]  xhci-cdns3: Queueing new dequeue state
[  287.421562]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 00000000093cf6ec (0x960dd010 dma), new cycle = 1
[  287.421570]  xhci-cdns3: // Ding dong!
[  287.421578]  xhci-cdns3: Giveback URB 00000000cda671b5, len = 0, expected = 1024, status = -71
[  287.421588] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.421600]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.421614]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cf010
[  287.421626]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.421637]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d7010
[  287.421649]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.421658]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d1010
[  287.421669]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.421682]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb010
[  287.421693]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.421705]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd010
[  287.421715]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.421727]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.421732]  xhci-cdns3: Finding endpoint context
[  287.421740]  xhci-cdns3: Cycle state = 0x1
[  287.421748]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.421753]  xhci-cdns3: New dequeue pointer = 0x960d7020 (DMA)
[  287.421760]  xhci-cdns3: Queueing new dequeue state
[  287.421771]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 000000001c7bc69b (0x960d7020 dma), new cycle = 1
[  287.421779]  xhci-cdns3: // Ding dong!
[  287.421787]  xhci-cdns3: Giveback URB 00000000c7ffb323, len = 0, expected = 1024, status = -71
[  287.421797] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.421807]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.421819]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.421826]  xhci-cdns3: Finding endpoint context
[  287.421833]  xhci-cdns3: Cycle state = 0x1
[  287.421839]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.421849]  xhci-cdns3: New dequeue pointer = 0x960d1020 (DMA)
[  287.421855]  xhci-cdns3: Queueing new dequeue state
[  287.421865]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 00000000a8d24aaa (0x960d1020 dma), new cycle = 1
[  287.421872]  xhci-cdns3: // Ding dong!
[  287.421881]  xhci-cdns3: Giveback URB 000000007875fcbd, len = 0, expected = 1024, status = -71
[  287.421890] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.421899]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.421910]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.421915]  xhci-cdns3: Finding endpoint context
[  287.421922]  xhci-cdns3: Cycle state = 0x1
[  287.421930]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.421937]  xhci-cdns3: New dequeue pointer = 0x960cb020 (DMA)
[  287.421944]  xhci-cdns3: Queueing new dequeue state
[  287.421955]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 0000000046064002 (0x960cb020 dma), new cycle = 1
[  287.421962]  xhci-cdns3: // Ding dong!
[  287.421970]  xhci-cdns3: Giveback URB 00000000bf1050a4, len = 0, expected = 1024, status = -71
[  287.421979] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.421988]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.421997]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.422004]  xhci-cdns3: Finding endpoint context
[  287.422013]  xhci-cdns3: Cycle state = 0x1
[  287.422019]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.422028]  xhci-cdns3: New dequeue pointer = 0x960dd020 (DMA)
[  287.422035]  xhci-cdns3: Queueing new dequeue state
[  287.422046]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 0000000047cad264 (0x960dd020 dma), new cycle = 1
[  287.422052]  xhci-cdns3: // Ding dong!
[  287.422060]  xhci-cdns3: Giveback URB 0000000067c2c4d0, len = 0, expected = 1024, status = -71
[  287.422068] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.422079]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.422091]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d7020
[  287.422103]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.422115]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d1020
[  287.422127]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.422136]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb020
[  287.422146]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.422157]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd020
[  287.422166]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.422177]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.422184]  xhci-cdns3: Finding endpoint context
[  287.422190]  xhci-cdns3: Cycle state = 0x1
[  287.422196]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.422202]  xhci-cdns3: New dequeue pointer = 0x960d7030 (DMA)
[  287.422208]  xhci-cdns3: Queueing new dequeue state
[  287.422219]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 00000000adb787c6 (0x960d7030 dma), new cycle = 1
[  287.422226]  xhci-cdns3: // Ding dong!
[  287.422235]  xhci-cdns3: Giveback URB 00000000bde27586, len = 0, expected = 1024, status = -71
[  287.422243] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.422253]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.422263]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.422270]  xhci-cdns3: Finding endpoint context
[  287.422277]  xhci-cdns3: Cycle state = 0x1
[  287.422285]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.422291]  xhci-cdns3: New dequeue pointer = 0x960d1030 (DMA)
[  287.422298]  xhci-cdns3: Queueing new dequeue state
[  287.422307]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 00000000a0fe5c78 (0x960d1030 dma), new cycle = 1
[  287.422312]  xhci-cdns3: // Ding dong!
[  287.422321]  xhci-cdns3: Giveback URB 00000000f4df9d04, len = 0, expected = 1024, status = -71
[  287.422329] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.422337]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.422346]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.422351]  xhci-cdns3: Finding endpoint context
[  287.422357]  xhci-cdns3: Cycle state = 0x1
[  287.422363]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.422368]  xhci-cdns3: New dequeue pointer = 0x960cb030 (DMA)
[  287.422373]  xhci-cdns3: Queueing new dequeue state
[  287.422382]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 00000000b6b7e98d (0x960cb030 dma), new cycle = 1
[  287.422389]  xhci-cdns3: // Ding dong!
[  287.422398]  xhci-cdns3: Giveback URB 000000006d2be1c5, len = 0, expected = 1024, status = -71
[  287.422406] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.422416]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.422426]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.422433]  xhci-cdns3: Finding endpoint context
[  287.422440]  xhci-cdns3: Cycle state = 0x1
[  287.422448]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.422454]  xhci-cdns3: New dequeue pointer = 0x960dd030 (DMA)
[  287.422460]  xhci-cdns3: Queueing new dequeue state
[  287.422471]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 0000000066af300b (0x960dd030 dma), new cycle = 1
[  287.422479]  xhci-cdns3: // Ding dong!
[  287.422487]  xhci-cdns3: Giveback URB 00000000c0357838, len = 0, expected = 1024, status = -71
[  287.422497] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.422506]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.422520]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d7030
[  287.422532]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.422542]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d1030
[  287.422553]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.422563]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb030
[  287.422574]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.422586]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd030
[  287.422594]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.422605]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.422612]  xhci-cdns3: Finding endpoint context
[  287.422618]  xhci-cdns3: Cycle state = 0x1
[  287.422628]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.422634]  xhci-cdns3: New dequeue pointer = 0x960d7040 (DMA)
[  287.422642]  xhci-cdns3: Queueing new dequeue state
[  287.422652]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 00000000a688e6ef (0x960d7040 dma), new cycle = 1
[  287.422659]  xhci-cdns3: // Ding dong!
[  287.422668]  xhci-cdns3: Giveback URB 000000003ce8b4d6, len = 0, expected = 1024, status = -71
[  287.422677] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.422686]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.422697]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.422702]  xhci-cdns3: Finding endpoint context
[  287.422708]  xhci-cdns3: Cycle state = 0x1
[  287.422714]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.422720]  xhci-cdns3: New dequeue pointer = 0x960d1040 (DMA)
[  287.422725]  xhci-cdns3: Queueing new dequeue state
[  287.422736]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 000000006c5dd5c2 (0x960d1040 dma), new cycle = 1
[  287.422743]  xhci-cdns3: // Ding dong!
[  287.422751]  xhci-cdns3: Giveback URB 00000000e7df2a0e, len = 0, expected = 1024, status = -71
[  287.422761] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.422771]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.422782]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.422789]  xhci-cdns3: Finding endpoint context
[  287.422797]  xhci-cdns3: Cycle state = 0x1
[  287.422803]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.422812]  xhci-cdns3: New dequeue pointer = 0x960cb040 (DMA)
[  287.422819]  xhci-cdns3: Queueing new dequeue state
[  287.422830]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 00000000fa0257f0 (0x960cb040 dma), new cycle = 1
[  287.422835]  xhci-cdns3: // Ding dong!
[  287.422844]  xhci-cdns3: Giveback URB 00000000c75ea73d, len = 0, expected = 1024, status = -71
[  287.422853] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.422862]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.422873]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.422879]  xhci-cdns3: Finding endpoint context
[  287.422887]  xhci-cdns3: Cycle state = 0x1
[  287.422895]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.422902]  xhci-cdns3: New dequeue pointer = 0x960dd040 (DMA)
[  287.422909]  xhci-cdns3: Queueing new dequeue state
[  287.422919]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 000000008c7af6f9 (0x960dd040 dma), new cycle = 1
[  287.422926]  xhci-cdns3: // Ding dong!
[  287.422935]  xhci-cdns3: Giveback URB 000000007e380bad, len = 0, expected = 1024, status = -71
[  287.422943] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.422955]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.422966]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d7040
[  287.422978]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.422989]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d1040
[  287.422999]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.423009]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb040
[  287.423019]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.423028]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd040
[  287.423036]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.423047]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.423052]  xhci-cdns3: Finding endpoint context
[  287.423058]  xhci-cdns3: Cycle state = 0x1
[  287.423064]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.423069]  xhci-cdns3: New dequeue pointer = 0x960d7050 (DMA)
[  287.423074]  xhci-cdns3: Queueing new dequeue state
[  287.423084]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 00000000120ab9bb (0x960d7050 dma), new cycle = 1
[  287.423089]  xhci-cdns3: // Ding dong!
[  287.423097]  xhci-cdns3: Giveback URB 00000000fa9d0474, len = 0, expected = 1024, status = -71
[  287.423106] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.423114]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.423125]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.423130]  xhci-cdns3: Finding endpoint context
[  287.423138]  xhci-cdns3: Cycle state = 0x1
[  287.423145]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.423152]  xhci-cdns3: New dequeue pointer = 0x960d1050 (DMA)
[  287.423159]  xhci-cdns3: Queueing new dequeue state
[  287.423170]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 00000000f50439ca (0x960d1050 dma), new cycle = 1
[  287.423177]  xhci-cdns3: // Ding dong!
[  287.423185]  xhci-cdns3: Giveback URB 00000000f5b2a4e5, len = 0, expected = 1024, status = -71
[  287.423194] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.423203]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.423214]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.423219]  xhci-cdns3: Finding endpoint context
[  287.423226]  xhci-cdns3: Cycle state = 0x1
[  287.423233]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.423239]  xhci-cdns3: New dequeue pointer = 0x960cb050 (DMA)
[  287.423246]  xhci-cdns3: Queueing new dequeue state
[  287.423255]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 0000000069711eaf (0x960cb050 dma), new cycle = 1
[  287.423261]  xhci-cdns3: // Ding dong!
[  287.423269]  xhci-cdns3: Giveback URB 0000000041599246, len = 0, expected = 1024, status = -71
[  287.423279] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.423286]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.423297]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.423302]  xhci-cdns3: Finding endpoint context
[  287.423310]  xhci-cdns3: Cycle state = 0x1
[  287.423317]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.423325]  xhci-cdns3: New dequeue pointer = 0x960dd050 (DMA)
[  287.423331]  xhci-cdns3: Queueing new dequeue state
[  287.423342]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 000000003e82421c (0x960dd050 dma), new cycle = 1
[  287.423350]  xhci-cdns3: // Ding dong!
[  287.423359]  xhci-cdns3: Giveback URB 0000000037e86c61, len = 0, expected = 1024, status = -71
[  287.423367] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.423376]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.423391]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d7050
[  287.423403]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.423414]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d1050
[  287.423424]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.423438]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb050
[  287.423448]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.423458]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd050
[  287.423466]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.423478]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.423483]  xhci-cdns3: Finding endpoint context
[  287.423490]  xhci-cdns3: Cycle state = 0x1
[  287.423498]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.423504]  xhci-cdns3: New dequeue pointer = 0x960d7060 (DMA)
[  287.423510]  xhci-cdns3: Queueing new dequeue state
[  287.423521]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 0000000046330bb5 (0x960d7060 dma), new cycle = 1
[  287.423529]  xhci-cdns3: // Ding dong!
[  287.423537]  xhci-cdns3: Giveback URB 000000001b74836c, len = 0, expected = 1024, status = -71
[  287.423548] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.423557]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.423566]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.423573]  xhci-cdns3: Finding endpoint context
[  287.423581]  xhci-cdns3: Cycle state = 0x1
[  287.423587]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.423594]  xhci-cdns3: New dequeue pointer = 0x960d1060 (DMA)
[  287.423601]  xhci-cdns3: Queueing new dequeue state
[  287.423611]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 000000002f82accd (0x960d1060 dma), new cycle = 1
[  287.423618]  xhci-cdns3: // Ding dong!
[  287.423627]  xhci-cdns3: Giveback URB 0000000002d5d03e, len = 0, expected = 1024, status = -71
[  287.423635] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.423645]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.423656]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.423661]  xhci-cdns3: Finding endpoint context
[  287.423668]  xhci-cdns3: Cycle state = 0x1
[  287.423676]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.423684]  xhci-cdns3: New dequeue pointer = 0x960cb060 (DMA)
[  287.423690]  xhci-cdns3: Queueing new dequeue state
[  287.423701]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 0000000021c0193c (0x960cb060 dma), new cycle = 1
[  287.423708]  xhci-cdns3: // Ding dong!
[  287.423716]  xhci-cdns3: Giveback URB 00000000f2626b3c, len = 0, expected = 1024, status = -71
[  287.423725] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.423736]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.423745]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.423752]  xhci-cdns3: Finding endpoint context
[  287.423761]  xhci-cdns3: Cycle state = 0x1
[  287.423767]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.423776]  xhci-cdns3: New dequeue pointer = 0x960dd060 (DMA)
[  287.423782]  xhci-cdns3: Queueing new dequeue state
[  287.423793]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 00000000f173de77 (0x960dd060 dma), new cycle = 1
[  287.423798]  xhci-cdns3: // Ding dong!
[  287.423806]  xhci-cdns3: Giveback URB 00000000a08fd24b, len = 0, expected = 1024, status = -71
[  287.423815] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.423825]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.423839]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d7060
[  287.423851]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.423862]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d1060
[  287.423873]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.423883]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb060
[  287.423893]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.423904]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd060
[  287.423912]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.423924]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.423929]  xhci-cdns3: Finding endpoint context
[  287.423937]  xhci-cdns3: Cycle state = 0x1
[  287.423943]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.423950]  xhci-cdns3: New dequeue pointer = 0x960d7070 (DMA)
[  287.423957]  xhci-cdns3: Queueing new dequeue state
[  287.423968]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 000000009fab4948 (0x960d7070 dma), new cycle = 1
[  287.423975]  xhci-cdns3: // Ding dong!
[  287.423983]  xhci-cdns3: Giveback URB 0000000031507e01, len = 0, expected = 1024, status = -71
[  287.423992] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.424002]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.424012]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.424019]  xhci-cdns3: Finding endpoint context
[  287.424026]  xhci-cdns3: Cycle state = 0x1
[  287.424034]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.424040]  xhci-cdns3: New dequeue pointer = 0x960d1070 (DMA)
[  287.424046]  xhci-cdns3: Queueing new dequeue state
[  287.424058]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 0000000041e3d96d (0x960d1070 dma), new cycle = 1
[  287.424063]  xhci-cdns3: // Ding dong!
[  287.424071]  xhci-cdns3: Giveback URB 00000000827e3429, len = 0, expected = 1024, status = -71
[  287.424080] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.424090]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.424099]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.424106]  xhci-cdns3: Finding endpoint context
[  287.424113]  xhci-cdns3: Cycle state = 0x1
[  287.424121]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.424128]  xhci-cdns3: New dequeue pointer = 0x960cb070 (DMA)
[  287.424135]  xhci-cdns3: Queueing new dequeue state
[  287.424145]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 000000007384d3d5 (0x960cb070 dma), new cycle = 1
[  287.424151]  xhci-cdns3: // Ding dong!
[  287.424159]  xhci-cdns3: Giveback URB 000000006338c28b, len = 0, expected = 1024, status = -71
[  287.424167] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.424176]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.424185]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.424190]  xhci-cdns3: Finding endpoint context
[  287.424198]  xhci-cdns3: Cycle state = 0x1
[  287.424206]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.424211]  xhci-cdns3: New dequeue pointer = 0x960dd070 (DMA)
[  287.424218]  xhci-cdns3: Queueing new dequeue state
[  287.424229]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 000000008c8cb919 (0x960dd070 dma), new cycle = 1
[  287.424236]  xhci-cdns3: // Ding dong!
[  287.424245]  xhci-cdns3: Giveback URB 00000000c896abd4, len = 0, expected = 1024, status = -71
[  287.424255] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.424264]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.424278]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d7070
[  287.424290]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.424300]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d1070
[  287.424311]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.424320]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb070
[  287.424330]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.424341]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd070
[  287.424350]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.424361]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.424368]  xhci-cdns3: Finding endpoint context
[  287.424374]  xhci-cdns3: Cycle state = 0x1
[  287.424382]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.424389]  xhci-cdns3: New dequeue pointer = 0x960d7080 (DMA)
[  287.424398]  xhci-cdns3: Queueing new dequeue state
[  287.424407]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 00000000e4ed889d (0x960d7080 dma), new cycle = 1
[  287.424414]  xhci-cdns3: // Ding dong!
[  287.424424]  xhci-cdns3: Giveback URB 00000000c537cbbe, len = 0, expected = 1024, status = -71
[  287.424432] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.424442]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.424452]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.424459]  xhci-cdns3: Finding endpoint context
[  287.424466]  xhci-cdns3: Cycle state = 0x1
[  287.424474]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.424481]  xhci-cdns3: New dequeue pointer = 0x960d1080 (DMA)
[  287.424488]  xhci-cdns3: Queueing new dequeue state
[  287.424499]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 00000000bc44bd8f (0x960d1080 dma), new cycle = 1
[  287.424506]  xhci-cdns3: // Ding dong!
[  287.424514]  xhci-cdns3: Giveback URB 00000000ab41362e, len = 0, expected = 1024, status = -71
[  287.424523] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.424531]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.424542]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.424547]  xhci-cdns3: Finding endpoint context
[  287.424556]  xhci-cdns3: Cycle state = 0x1
[  287.424562]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.424571]  xhci-cdns3: New dequeue pointer = 0x960cb080 (DMA)
[  287.424578]  xhci-cdns3: Queueing new dequeue state
[  287.424589]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 000000002a6415aa (0x960cb080 dma), new cycle = 1
[  287.424594]  xhci-cdns3: // Ding dong!
[  287.424604]  xhci-cdns3: Giveback URB 00000000e8b76816, len = 0, expected = 1024, status = -71
[  287.424612] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.424621]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.424631]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.424638]  xhci-cdns3: Finding endpoint context
[  287.424645]  xhci-cdns3: Cycle state = 0x1
[  287.424653]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.424660]  xhci-cdns3: New dequeue pointer = 0x960dd080 (DMA)
[  287.424667]  xhci-cdns3: Queueing new dequeue state
[  287.424678]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 00000000d71863c9 (0x960dd080 dma), new cycle = 1
[  287.424685]  xhci-cdns3: // Ding dong!
[  287.424693]  xhci-cdns3: Giveback URB 00000000ee239573, len = 0, expected = 1024, status = -71
[  287.424701] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.424712]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.424724]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d7080
[  287.424736]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.424747]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d1080
[  287.424756]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.424767]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb080
[  287.424777]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.424788]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd080
[  287.424798]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.424808]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.424815]  xhci-cdns3: Finding endpoint context
[  287.424824]  xhci-cdns3: Cycle state = 0x1
[  287.424830]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.424838]  xhci-cdns3: New dequeue pointer = 0x960d7090 (DMA)
[  287.424843]  xhci-cdns3: Queueing new dequeue state
[  287.424852]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 000000005023595c (0x960d7090 dma), new cycle = 1
[  287.424859]  xhci-cdns3: // Ding dong!
[  287.424868]  xhci-cdns3: Giveback URB 000000004c764c2e, len = 0, expected = 1024, status = -71
[  287.424876] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.424886]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.424896]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.424903]  xhci-cdns3: Finding endpoint context
[  287.424911]  xhci-cdns3: Cycle state = 0x1
[  287.424918]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.424925]  xhci-cdns3: New dequeue pointer = 0x960d1090 (DMA)
[  287.424932]  xhci-cdns3: Queueing new dequeue state
[  287.424943]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 0000000091ecc05e (0x960d1090 dma), new cycle = 1
[  287.424950]  xhci-cdns3: // Ding dong!
[  287.424959]  xhci-cdns3: Giveback URB 0000000001d1e083, len = 0, expected = 1024, status = -71
[  287.424968] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.424976]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.424987]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.424993]  xhci-cdns3: Finding endpoint context
[  287.425001]  xhci-cdns3: Cycle state = 0x1
[  287.425008]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.425014]  xhci-cdns3: New dequeue pointer = 0x960cb090 (DMA)
[  287.425021]  xhci-cdns3: Queueing new dequeue state
[  287.425032]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 00000000638de49d (0x960cb090 dma), new cycle = 1
[  287.425039]  xhci-cdns3: // Ding dong!
[  287.425047]  xhci-cdns3: Giveback URB 000000001bf781dc, len = 0, expected = 1024, status = -71
[  287.425057] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.425065]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.425078]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.425084]  xhci-cdns3: Finding endpoint context
[  287.425090]  xhci-cdns3: Cycle state = 0x1
[  287.425098]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.425105]  xhci-cdns3: New dequeue pointer = 0x960dd090 (DMA)
[  287.425112]  xhci-cdns3: Queueing new dequeue state
[  287.425123]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 000000001888640a (0x960dd090 dma), new cycle = 1
[  287.425131]  xhci-cdns3: // Ding dong!
[  287.425140]  xhci-cdns3: Giveback URB 000000004997564e, len = 0, expected = 1024, status = -71
[  287.425148] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.425159]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.425171]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d7090
[  287.425182]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.425194]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d1090
[  287.425204]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.425215]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb090
[  287.425227]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.425237]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd090
[  287.425245]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.425257]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.425262]  xhci-cdns3: Finding endpoint context
[  287.425269]  xhci-cdns3: Cycle state = 0x1
[  287.425277]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.425282]  xhci-cdns3: New dequeue pointer = 0x960d70a0 (DMA)
[  287.425289]  xhci-cdns3: Queueing new dequeue state
[  287.425300]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 0000000060b0f4a3 (0x960d70a0 dma), new cycle = 1
[  287.425308]  xhci-cdns3: // Ding dong!
[  287.425316]  xhci-cdns3: Giveback URB 00000000824fcc69, len = 0, expected = 1024, status = -71
[  287.425325] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.425334]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.425345]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.425352]  xhci-cdns3: Finding endpoint context
[  287.425360]  xhci-cdns3: Cycle state = 0x1
[  287.425366]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.425375]  xhci-cdns3: New dequeue pointer = 0x960d10a0 (DMA)
[  287.425381]  xhci-cdns3: Queueing new dequeue state
[  287.425391]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 000000004cfe041d (0x960d10a0 dma), new cycle = 1
[  287.425398]  xhci-cdns3: // Ding dong!
[  287.425406]  xhci-cdns3: Giveback URB 00000000ec643222, len = 0, expected = 1024, status = -71
[  287.425415] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.425424]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.425435]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.425442]  xhci-cdns3: Finding endpoint context
[  287.425449]  xhci-cdns3: Cycle state = 0x1
[  287.425457]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.425463]  xhci-cdns3: New dequeue pointer = 0x960cb0a0 (DMA)
[  287.425470]  xhci-cdns3: Queueing new dequeue state
[  287.425480]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 000000002099db3b (0x960cb0a0 dma), new cycle = 1
[  287.425487]  xhci-cdns3: // Ding dong!
[  287.425495]  xhci-cdns3: Giveback URB 00000000897c1e4a, len = 0, expected = 1024, status = -71
[  287.425504] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.425515]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.425524]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.425531]  xhci-cdns3: Finding endpoint context
[  287.425540]  xhci-cdns3: Cycle state = 0x1
[  287.425546]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.425555]  xhci-cdns3: New dequeue pointer = 0x960dd0a0 (DMA)
[  287.425562]  xhci-cdns3: Queueing new dequeue state
[  287.425573]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 000000009b64d135 (0x960dd0a0 dma), new cycle = 1
[  287.425578]  xhci-cdns3: // Ding dong!
[  287.425587]  xhci-cdns3: Giveback URB 0000000061231269, len = 0, expected = 1024, status = -71
[  287.425595] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.425605]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.425617]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d70a0
[  287.425628]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.425640]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d10a0
[  287.425650]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.425659]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb0a0
[  287.425669]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.425680]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd0a0
[  287.425690]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.425700]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.425706]  xhci-cdns3: Finding endpoint context
[  287.425713]  xhci-cdns3: Cycle state = 0x1
[  287.425720]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.425728]  xhci-cdns3: New dequeue pointer = 0x960d70b0 (DMA)
[  287.425735]  xhci-cdns3: Queueing new dequeue state
[  287.425746]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 000000004e7e2bf2 (0x960d70b0 dma), new cycle = 1
[  287.425753]  xhci-cdns3: // Ding dong!
[  287.425761]  xhci-cdns3: Giveback URB 00000000a27ef103, len = 0, expected = 1024, status = -71
[  287.425770] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.425779]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.425790]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.425797]  xhci-cdns3: Finding endpoint context
[  287.425804]  xhci-cdns3: Cycle state = 0x1
[  287.425812]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.425817]  xhci-cdns3: New dequeue pointer = 0x960d10b0 (DMA)
[  287.425824]  xhci-cdns3: Queueing new dequeue state
[  287.425835]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 0000000081a3b0ed (0x960d10b0 dma), new cycle = 1
[  287.425841]  xhci-cdns3: // Ding dong!
[  287.425849]  xhci-cdns3: Giveback URB 000000004bb09df5, len = 0, expected = 1024, status = -71
[  287.425858] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.425867]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.425878]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.425885]  xhci-cdns3: Finding endpoint context
[  287.425892]  xhci-cdns3: Cycle state = 0x1
[  287.425900]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.425907]  xhci-cdns3: New dequeue pointer = 0x960cb0b0 (DMA)
[  287.425914]  xhci-cdns3: Queueing new dequeue state
[  287.425924]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 00000000d637b6b7 (0x960cb0b0 dma), new cycle = 1
[  287.425932]  xhci-cdns3: // Ding dong!
[  287.425941]  xhci-cdns3: Giveback URB 000000003dc15094, len = 0, expected = 1024, status = -71
[  287.425949] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.425958]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.425969]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.425974]  xhci-cdns3: Finding endpoint context
[  287.425981]  xhci-cdns3: Cycle state = 0x1
[  287.425989]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.425994]  xhci-cdns3: New dequeue pointer = 0x960dd0b0 (DMA)
[  287.426001]  xhci-cdns3: Queueing new dequeue state
[  287.426012]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 000000003bbed6f2 (0x960dd0b0 dma), new cycle = 1
[  287.426020]  xhci-cdns3: // Ding dong!
[  287.426028]  xhci-cdns3: Giveback URB 000000000c2c3637, len = 0, expected = 1024, status = -71
[  287.426038] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.426047]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.426062]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d70b0
[  287.426076]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.426086]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d10b0
[  287.426097]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.426109]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb0b0
[  287.426118]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.426130]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd0b0
[  287.426138]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.426150]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.426157]  xhci-cdns3: Finding endpoint context
[  287.426162]  xhci-cdns3: Cycle state = 0x1
[  287.426170]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.426177]  xhci-cdns3: New dequeue pointer = 0x960d70c0 (DMA)
[  287.426186]  xhci-cdns3: Queueing new dequeue state
[  287.426195]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 00000000bf6949a6 (0x960d70c0 dma), new cycle = 1
[  287.426202]  xhci-cdns3: // Ding dong!
[  287.426212]  xhci-cdns3: Giveback URB 00000000447ee77e, len = 0, expected = 1024, status = -71
[  287.426220] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.426230]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.426241]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.426248]  xhci-cdns3: Finding endpoint context
[  287.426255]  xhci-cdns3: Cycle state = 0x1
[  287.426263]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.426270]  xhci-cdns3: New dequeue pointer = 0x960d10c0 (DMA)
[  287.426277]  xhci-cdns3: Queueing new dequeue state
[  287.426288]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 000000008441ca07 (0x960d10c0 dma), new cycle = 1
[  287.426295]  xhci-cdns3: // Ding dong!
[  287.426303]  xhci-cdns3: Giveback URB 00000000795f8e84, len = 0, expected = 1024, status = -71
[  287.426312] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.426322]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.426331]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.426338]  xhci-cdns3: Finding endpoint context
[  287.426346]  xhci-cdns3: Cycle state = 0x1
[  287.426352]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.426361]  xhci-cdns3: New dequeue pointer = 0x960cb0c0 (DMA)
[  287.426368]  xhci-cdns3: Queueing new dequeue state
[  287.426379]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 0000000057bfab12 (0x960cb0c0 dma), new cycle = 1
[  287.426385]  xhci-cdns3: // Ding dong!
[  287.426394]  xhci-cdns3: Giveback URB 00000000323a4af8, len = 0, expected = 1024, status = -71
[  287.426402] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.426411]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.426422]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.426429]  xhci-cdns3: Finding endpoint context
[  287.426436]  xhci-cdns3: Cycle state = 0x1
[  287.426444]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.426451]  xhci-cdns3: New dequeue pointer = 0x960dd0c0 (DMA)
[  287.426458]  xhci-cdns3: Queueing new dequeue state
[  287.426468]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 00000000cd6bdd27 (0x960dd0c0 dma), new cycle = 1
[  287.426475]  xhci-cdns3: // Ding dong!
[  287.426483]  xhci-cdns3: Giveback URB 00000000fdd07bdd, len = 0, expected = 1024, status = -71
[  287.426492] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.426504]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.426516]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d70c0
[  287.426528]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.426539]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d10c0
[  287.426549]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.426560]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb0c0
[  287.426571]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.426582]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd0c0
[  287.426592]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.426602]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.426607]  xhci-cdns3: Finding endpoint context
[  287.426616]  xhci-cdns3: Cycle state = 0x1
[  287.426622]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.426632]  xhci-cdns3: New dequeue pointer = 0x960d70d0 (DMA)
[  287.426636]  xhci-cdns3: Queueing new dequeue state
[  287.426646]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 00000000ecbab705 (0x960d70d0 dma), new cycle = 1
[  287.426653]  xhci-cdns3: // Ding dong!
[  287.426661]  xhci-cdns3: Giveback URB 0000000012a6f9ca, len = 0, expected = 1024, status = -71
[  287.426669] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.426679]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.426690]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.426695]  xhci-cdns3: Finding endpoint context
[  287.426702]  xhci-cdns3: Cycle state = 0x1
[  287.426710]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.426717]  xhci-cdns3: New dequeue pointer = 0x960d10d0 (DMA)
[  287.426723]  xhci-cdns3: Queueing new dequeue state
[  287.426734]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 0000000008f74464 (0x960d10d0 dma), new cycle = 1
[  287.426742]  xhci-cdns3: // Ding dong!
[  287.426750]  xhci-cdns3: Giveback URB 0000000011c2ba88, len = 0, expected = 1024, status = -71
[  287.426758] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.426768]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.426778]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.426785]  xhci-cdns3: Finding endpoint context
[  287.426793]  xhci-cdns3: Cycle state = 0x1
[  287.426800]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.426806]  xhci-cdns3: New dequeue pointer = 0x960cb0d0 (DMA)
[  287.426813]  xhci-cdns3: Queueing new dequeue state
[  287.426824]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 000000006811ed79 (0x960cb0d0 dma), new cycle = 1
[  287.426831]  xhci-cdns3: // Ding dong!
[  287.426839]  xhci-cdns3: Giveback URB 00000000b870f799, len = 0, expected = 1024, status = -71
[  287.426849] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.426857]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.426868]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.426875]  xhci-cdns3: Finding endpoint context
[  287.426881]  xhci-cdns3: Cycle state = 0x1
[  287.426888]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.426896]  xhci-cdns3: New dequeue pointer = 0x960dd0d0 (DMA)
[  287.426903]  xhci-cdns3: Queueing new dequeue state
[  287.426913]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 0000000001e2ff1e (0x960dd0d0 dma), new cycle = 1
[  287.426921]  xhci-cdns3: // Ding dong!
[  287.426930]  xhci-cdns3: Giveback URB 000000004f9669aa, len = 0, expected = 1024, status = -71
[  287.426938] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.426949]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.426963]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d70d0
[  287.426975]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.426987]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d10d0
[  287.426996]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.427006]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb0d0
[  287.427016]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.427026]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd0d0
[  287.427034]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.427045]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.427050]  xhci-cdns3: Finding endpoint context
[  287.427055]  xhci-cdns3: Cycle state = 0x1
[  287.427061]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.427067]  xhci-cdns3: New dequeue pointer = 0x960d70e0 (DMA)
[  287.427072]  xhci-cdns3: Queueing new dequeue state
[  287.427081]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 0000000052d3b80a (0x960d70e0 dma), new cycle = 1
[  287.427087]  xhci-cdns3: // Ding dong!
[  287.427096]  xhci-cdns3: Giveback URB 00000000399c6266, len = 0, expected = 1024, status = -71
[  287.427104] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.427112]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.427122]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.427129]  xhci-cdns3: Finding endpoint context
[  287.427136]  xhci-cdns3: Cycle state = 0x1
[  287.427142]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.427151]  xhci-cdns3: New dequeue pointer = 0x960d10e0 (DMA)
[  287.427158]  xhci-cdns3: Queueing new dequeue state
[  287.427167]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 000000008cdf0794 (0x960d10e0 dma), new cycle = 1
[  287.427174]  xhci-cdns3: // Ding dong!
[  287.427183]  xhci-cdns3: Giveback URB 000000006ceddeec, len = 0, expected = 1024, status = -71
[  287.427192] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.427201]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.427212]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.427219]  xhci-cdns3: Finding endpoint context
[  287.427226]  xhci-cdns3: Cycle state = 0x1
[  287.427234]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.427241]  xhci-cdns3: New dequeue pointer = 0x960cb0e0 (DMA)
[  287.427248]  xhci-cdns3: Queueing new dequeue state
[  287.427259]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 000000009e4f1d33 (0x960cb0e0 dma), new cycle = 1
[  287.427266]  xhci-cdns3: // Ding dong!
[  287.427274]  xhci-cdns3: Giveback URB 0000000042bf2c63, len = 0, expected = 1024, status = -71
[  287.427283] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.427294]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.427303]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.427310]  xhci-cdns3: Finding endpoint context
[  287.427319]  xhci-cdns3: Cycle state = 0x1
[  287.427325]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.427334]  xhci-cdns3: New dequeue pointer = 0x960dd0e0 (DMA)
[  287.427341]  xhci-cdns3: Queueing new dequeue state
[  287.427352]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 00000000379eded5 (0x960dd0e0 dma), new cycle = 1
[  287.427358]  xhci-cdns3: // Ding dong!
[  287.427366]  xhci-cdns3: Giveback URB 000000003ee07308, len = 0, expected = 1024, status = -71
[  287.427374] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.427383]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.427396]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d70e0
[  287.427407]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.427421]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d10e0
[  287.427430]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.427440]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb0e0
[  287.427451]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.427463]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd0e0
[  287.427471]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.427482]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.427487]  xhci-cdns3: Finding endpoint context
[  287.427495]  xhci-cdns3: Cycle state = 0x1
[  287.427502]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.427509]  xhci-cdns3: New dequeue pointer = 0x960d70f0 (DMA)
[  287.427516]  xhci-cdns3: Queueing new dequeue state
[  287.427527]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 000000004d3bbadb (0x960d70f0 dma), new cycle = 1
[  287.427535]  xhci-cdns3: // Ding dong!
[  287.427543]  xhci-cdns3: Giveback URB 00000000eefbec95, len = 0, expected = 1024, status = -71
[  287.427551] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.427561]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.427571]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.427576]  xhci-cdns3: Finding endpoint context
[  287.427584]  xhci-cdns3: Cycle state = 0x1
[  287.427592]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.427597]  xhci-cdns3: New dequeue pointer = 0x960d10f0 (DMA)
[  287.427604]  xhci-cdns3: Queueing new dequeue state
[  287.427615]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 00000000a39fecc9 (0x960d10f0 dma), new cycle = 1
[  287.427620]  xhci-cdns3: // Ding dong!
[  287.427628]  xhci-cdns3: Giveback URB 000000005b068b66, len = 0, expected = 1024, status = -71
[  287.427637] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.427646]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.427657]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.427664]  xhci-cdns3: Finding endpoint context
[  287.427672]  xhci-cdns3: Cycle state = 0x1
[  287.427679]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.427686]  xhci-cdns3: New dequeue pointer = 0x960cb0f0 (DMA)
[  287.427693]  xhci-cdns3: Queueing new dequeue state
[  287.427704]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 00000000d0907010 (0x960cb0f0 dma), new cycle = 1
[  287.427711]  xhci-cdns3: // Ding dong!
[  287.427720]  xhci-cdns3: Giveback URB 000000002d96c239, len = 0, expected = 1024, status = -71
[  287.427729] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.427737]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.427746]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.427751]  xhci-cdns3: Finding endpoint context
[  287.427758]  xhci-cdns3: Cycle state = 0x1
[  287.427766]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.427771]  xhci-cdns3: New dequeue pointer = 0x960dd0f0 (DMA)
[  287.427778]  xhci-cdns3: Queueing new dequeue state
[  287.427789]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 0000000079269ebe (0x960dd0f0 dma), new cycle = 1
[  287.427796]  xhci-cdns3: // Ding dong!
[  287.427805]  xhci-cdns3: Giveback URB 000000007c3a15f6, len = 0, expected = 1024, status = -71
[  287.427813] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.427822]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.427836]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d70f0
[  287.427848]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.427858]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d10f0
[  287.427867]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.427879]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb0f0
[  287.427888]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.427900]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd0f0
[  287.427908]  xhci-cdns3: Transfer error for slot 5 ep 6 on endpoint
[  287.427920]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.427927]  xhci-cdns3: Finding endpoint context
[  287.427933]  xhci-cdns3: Cycle state = 0x1
[  287.427939]  xhci-cdns3: New dequeue segment = 000000004a03712f (virtual)
[  287.427946]  xhci-cdns3: New dequeue pointer = 0x960d7100 (DMA)
[  287.427954]  xhci-cdns3: Queueing new dequeue state
[  287.427964]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 000000004a03712f (0x960d7000 dma), new deq ptr = 00000000993242b0 (0x960d7100 dma), new cycle = 1
[  287.427972]  xhci-cdns3: // Ding dong!
[  287.427980]  xhci-cdns3: Giveback URB 00000000499e8024, len = 0, expected = 1024, status = -71
[  287.427988] cdc_acm 1-1.1:1.3: acm_read_bulk_callback - cooling babbling device
[  287.427998]  xhci-cdns3: Transfer error for slot 5 ep 10 on endpoint
[  287.428006]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.428013]  xhci-cdns3: Finding endpoint context
[  287.428021]  xhci-cdns3: Cycle state = 0x1
[  287.428028]  xhci-cdns3: New dequeue segment = 0000000001b9388c (virtual)
[  287.428036]  xhci-cdns3: New dequeue pointer = 0x960d1100 (DMA)
[  287.428042]  xhci-cdns3: Queueing new dequeue state
[  287.428053]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000001b9388c (0x960d1000 dma), new deq ptr = 00000000a98279ef (0x960d1100 dma), new cycle = 1
[  287.428060]  xhci-cdns3: // Ding dong!
[  287.428068]  xhci-cdns3: Giveback URB 00000000d56d9e44, len = 0, expected = 1024, status = -71
[  287.428078] cdc_acm 1-1.1:1.5: acm_read_bulk_callback - cooling babbling device
[  287.428086]  xhci-cdns3: Transfer error for slot 5 ep 14 on endpoint
[  287.428097]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.428102]  xhci-cdns3: Finding endpoint context
[  287.428111]  xhci-cdns3: Cycle state = 0x1
[  287.428117]  xhci-cdns3: New dequeue segment = 00000000b2431396 (virtual)
[  287.428126]  xhci-cdns3: New dequeue pointer = 0x960cb100 (DMA)
[  287.428133]  xhci-cdns3: Queueing new dequeue state
[  287.428144]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000b2431396 (0x960cb000 dma), new deq ptr = 00000000a0e35b00 (0x960cb100 dma), new cycle = 1
[  287.428149]  xhci-cdns3: // Ding dong!
[  287.428158]  xhci-cdns3: Giveback URB 0000000026c00f9f, len = 0, expected = 1024, status = -71
[  287.428166] cdc_acm 1-1.1:1.7: acm_read_bulk_callback - cooling babbling device
[  287.428176]  xhci-cdns3: Transfer error for slot 5 ep 2 on endpoint
[  287.428185]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.428190]  xhci-cdns3: Finding endpoint context
[  287.428197]  xhci-cdns3: Cycle state = 0x1
[  287.428205]  xhci-cdns3: New dequeue segment = 00000000d3205ec3 (virtual)
[  287.428212]  xhci-cdns3: New dequeue pointer = 0x960dd100 (DMA)
[  287.428219]  xhci-cdns3: Queueing new dequeue state
[  287.428230]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d3205ec3 (0x960dd000 dma), new deq ptr = 00000000cd0fa9bb (0x960dd100 dma), new cycle = 1
[  287.428237]  xhci-cdns3: // Ding dong!
[  287.428245]  xhci-cdns3: Giveback URB 0000000097699bd8, len = 0, expected = 1024, status = -71
[  287.428253] cdc_acm 1-1.1:1.1: acm_read_bulk_callback - cooling babbling device
[  287.428266]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.428279]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d7100
[  287.428290]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.428301]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d1100
[  287.428312]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.428322]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cb100
[  287.428332]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.428346]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960dd100
[  287.507479]  xhci-cdns3: Transfer error for slot 5 ep 4 on endpoint
[  287.507512]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.507519]  xhci-cdns3: Finding endpoint context
[  287.507527]  xhci-cdns3: Cycle state = 0x1
[  287.507535]  xhci-cdns3: New dequeue segment = 00000000da18a55c (virtual)
[  287.507541]  xhci-cdns3: New dequeue pointer = 0x960df010 (DMA)
[  287.507547]  xhci-cdns3: Queueing new dequeue state
[  287.507559]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000da18a55c (0x960df000 dma), new deq ptr = 0000000095b6c215 (0x960df010 dma), new cycle = 1
[  287.507567]  xhci-cdns3: // Ding dong!
[  287.507577]  xhci-cdns3: Giveback URB 000000001f0ac868, len = 0, expected = 64, status = -71
[  287.507594] cdc_acm 1-1.1:1.0: acm_ctrl_irq - nonzero urb status received: -71
[  287.507623]  xhci-cdns3: Transfer error for slot 5 ep 8 on endpoint
[  287.507634]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.507639]  xhci-cdns3: Finding endpoint context
[  287.507645]  xhci-cdns3: Cycle state = 0x1
[  287.507653]  xhci-cdns3: New dequeue segment = 00000000f4e7286e (virtual)
[  287.507660]  xhci-cdns3: New dequeue pointer = 0x960d9010 (DMA)
[  287.507667]  xhci-cdns3: Queueing new dequeue state
[  287.507678]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000f4e7286e (0x960d9000 dma), new deq ptr = 0000000001cb4c69 (0x960d9010 dma), new cycle = 1
[  287.507685]  xhci-cdns3: // Ding dong!
[  287.507694]  xhci-cdns3: Giveback URB 00000000b4e398f8, len = 0, expected = 64, status = -71
[  287.507704] cdc_acm 1-1.1:1.2: acm_ctrl_irq - nonzero urb status received: -71
[  287.507719]  xhci-cdns3: Transfer error for slot 5 ep 12 on endpoint
[  287.507729]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.507736]  xhci-cdns3: Finding endpoint context
[  287.507745]  xhci-cdns3: Cycle state = 0x1
[  287.507751]  xhci-cdns3: New dequeue segment = 00000000d6d33c86 (virtual)
[  287.507760]  xhci-cdns3: New dequeue pointer = 0x960d3010 (DMA)
[  287.507765]  xhci-cdns3: Queueing new dequeue state
[  287.507775]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d6d33c86 (0x960d3000 dma), new deq ptr = 00000000b0efce72 (0x960d3010 dma), new cycle = 1
[  287.507782]  xhci-cdns3: // Ding dong!
[  287.507790]  xhci-cdns3: Giveback URB 00000000bcc6d1bc, len = 0, expected = 64, status = -71
[  287.507800] cdc_acm 1-1.1:1.4: acm_ctrl_irq - nonzero urb status received: -71
[  287.507814]  xhci-cdns3: Transfer error for slot 5 ep 16 on endpoint
[  287.507826]  xhci-cdns3: Cleaning up stalled endpoint ring
[  287.507831]  xhci-cdns3: Finding endpoint context
[  287.507837]  xhci-cdns3: Cycle state = 0x1
[  287.507844]  xhci-cdns3: New dequeue segment = 00000000df6fb1eb (virtual)
[  287.507851]  xhci-cdns3: New dequeue pointer = 0x960cd010 (DMA)
[  287.507858]  xhci-cdns3: Queueing new dequeue state
[  287.507869]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000df6fb1eb (0x960cd000 dma), new deq ptr = 0000000045aaeda1 (0x960cd010 dma), new cycle = 1
[  287.507876]  xhci-cdns3: // Ding dong!
[  287.507884]  xhci-cdns3: Giveback URB 0000000003777f1e, len = 0, expected = 64, status = -71
[  287.507894] cdc_acm 1-1.1:1.6: acm_ctrl_irq - nonzero urb status received: -71
[  287.507911]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.507925]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960df010
[  287.507935]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.507947]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d9010
[  287.507958]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.507969]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d3010
[  287.507981]  xhci-cdns3: Ignoring reset ep completion code of 1
[  287.507994]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cd010
[  287.571624] usb 1-1.1: USB disconnect, device number 6
[  287.577283]  xhci-cdns3: Cancel URB 000000001f0ac868, dev 1.1, ep 0x82, starting at offset 0x960df010
[  287.577301]  xhci-cdns3: // Ding dong!
[  287.577317]  xhci-cdns3: Stopped on Transfer TRB for slot 5 ep 4
[  287.577331]  xhci-cdns3: Removing canceled TD starting at 0x960df010 (dma).
[  287.577339]  xhci-cdns3: Finding endpoint context
[  287.577346]  xhci-cdns3: Cycle state = 0x1
[  287.577354]  xhci-cdns3: New dequeue segment = 00000000da18a55c (virtual)
[  287.577361]  xhci-cdns3: New dequeue pointer = 0x960df020 (DMA)
[  287.577373]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000da18a55c (0x960df000 dma), new deq ptr = 00000000f6b749d9 (0x960df020 dma), new cycle = 1
[  287.577379]  xhci-cdns3: // Ding dong!
[  287.577394] cdc_acm 1-1.1:1.0: acm_ctrl_irq - urb shutting down with status: -108
[  287.577407]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960df020
[  287.578609]  xhci-cdns3: Cancel URB 00000000b4e398f8, dev 1.1, ep 0x84, starting at offset 0x960d9010
[  287.578628]  xhci-cdns3: // Ding dong!
[  287.578647]  xhci-cdns3: Stopped on Transfer TRB for slot 5 ep 8
[  287.578664]  xhci-cdns3: Removing canceled TD starting at 0x960d9010 (dma).
[  287.578673]  xhci-cdns3: Finding endpoint context
[  287.578679]  xhci-cdns3: Cycle state = 0x1
[  287.578686]  xhci-cdns3: New dequeue segment = 00000000f4e7286e (virtual)
[  287.578692]  xhci-cdns3: New dequeue pointer = 0x960d9020 (DMA)
[  287.578703]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000f4e7286e (0x960d9000 dma), new deq ptr = 00000000442895b3 (0x960d9020 dma), new cycle = 1
[  287.578709]  xhci-cdns3: // Ding dong!
[  287.578726] cdc_acm 1-1.1:1.2: acm_ctrl_irq - urb shutting down with status: -108
[  287.578740]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d9020
[  287.588194]  xhci-cdns3: Cancel URB 00000000bcc6d1bc, dev 1.1, ep 0x86, starting at offset 0x960d3010
[  287.588219]  xhci-cdns3: // Ding dong!
[  287.588240]  xhci-cdns3: Stopped on Transfer TRB for slot 5 ep 12
[  287.588259]  xhci-cdns3: Removing canceled TD starting at 0x960d3010 (dma).
[  287.588266]  xhci-cdns3: Finding endpoint context
[  287.588273]  xhci-cdns3: Cycle state = 0x1
[  287.588280]  xhci-cdns3: New dequeue segment = 00000000d6d33c86 (virtual)
[  287.588285]  xhci-cdns3: New dequeue pointer = 0x960d3020 (DMA)
[  287.588297]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000d6d33c86 (0x960d3000 dma), new deq ptr = 00000000e57bb4f5 (0x960d3020 dma), new cycle = 1
[  287.588304]  xhci-cdns3: // Ding dong!
[  287.588321] cdc_acm 1-1.1:1.4: acm_ctrl_irq - urb shutting down with status: -108
[  287.588336]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960d3020
[  287.589450] cdc_acm 1-1.1:1.4: acm_ctrl_msg - rq 0x22, val 0x0, len 0x0, result -19
[  287.589517] cdc_acm 1-1.1:1.4: failed to set dtr/rts
[  287.602663]  xhci-cdns3: Cancel URB 0000000003777f1e, dev 1.1, ep 0x88, starting at offset 0x960cd010
[  287.602683]  xhci-cdns3: // Ding dong!
[  287.602701]  xhci-cdns3: Stopped on Transfer TRB for slot 5 ep 16
[  287.602716]  xhci-cdns3: Removing canceled TD starting at 0x960cd010 (dma).
[  287.602722]  xhci-cdns3: Finding endpoint context
[  287.602727]  xhci-cdns3: Cycle state = 0x1
[  287.602732]  xhci-cdns3: New dequeue segment = 00000000df6fb1eb (virtual)
[  287.602736]  xhci-cdns3: New dequeue pointer = 0x960cd020 (DMA)
[  287.602747]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 00000000df6fb1eb (0x960cd000 dma), new deq ptr = 00000000e48b3bee (0x960cd020 dma), new cycle = 1
[  287.602752]  xhci-cdns3: // Ding dong!
[  287.602767] cdc_acm 1-1.1:1.6: acm_ctrl_irq - urb shutting down with status: -108
[  287.602778]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960cd020
[  287.606285]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.606352]  xhci-cdns3: drop ep 0x1, slot id 5, new drop flags = 0x4, new add flags = 0x0
[  287.606357]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.607698]  xhci-cdns3: drop ep 0x81, slot id 5, new drop flags = 0xc, new add flags = 0x0
[  287.607714]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.607753]  xhci-cdns3: drop ep 0x2, slot id 5, new drop flags = 0x1c, new add flags = 0x0
[  287.607758]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.607796]  xhci-cdns3: drop ep 0x82, slot id 5, new drop flags = 0x3c, new add flags = 0x0
[  287.607801]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.607837]  xhci-cdns3: drop ep 0x3, slot id 5, new drop flags = 0x7c, new add flags = 0x0
[  287.607842]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.607879]  xhci-cdns3: drop ep 0x83, slot id 5, new drop flags = 0xfc, new add flags = 0x0
[  287.607884]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.607921]  xhci-cdns3: drop ep 0x4, slot id 5, new drop flags = 0x1fc, new add flags = 0x0
[  287.607925]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.607958]  xhci-cdns3: drop ep 0x84, slot id 5, new drop flags = 0x3fc, new add flags = 0x0
[  287.607963]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.608000]  xhci-cdns3: drop ep 0x5, slot id 5, new drop flags = 0x7fc, new add flags = 0x0
[  287.608005]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.608041]  xhci-cdns3: drop ep 0x85, slot id 5, new drop flags = 0xffc, new add flags = 0x0
[  287.608046]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.608080]  xhci-cdns3: drop ep 0x86, slot id 5, new drop flags = 0x2ffc, new add flags = 0x0
[  287.608085]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.608117]  xhci-cdns3: drop ep 0x87, slot id 5, new drop flags = 0xaffc, new add flags = 0x0
[  287.608123]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.608156]  xhci-cdns3: drop ep 0x88, slot id 5, new drop flags = 0x2affc, new add flags = 0x0
[  287.608161]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.608198]  xhci-cdns3: drop ep 0x89, slot id 5, new drop flags = 0xaaffc, new add flags = 0x0
[  287.608203]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.611199]  xhci-cdns3: drop ep 0x8a, slot id 5, new drop flags = 0x2aaffc, new add flags = 0x0
[  287.611209]  xhci-cdns3: xhci_drop_endpoint called for udev 00000000c343539e
[  287.611246]  xhci-cdns3: drop ep 0x8b, slot id 5, new drop flags = 0xaaaffc, new add flags = 0x0
[  287.611252]  xhci-cdns3: xhci_check_bandwidth called for udev 00000000c343539e
[  287.611280]  xhci-cdns3: // Ding dong!
[  287.611407]  xhci-cdns3: Successful Endpoint Configure command
[  287.612382]  xhci-cdns3: // Ding dong!
[  287.755217]  xhci-cdns3: Cancel URB 0000000082941f3c, dev 1, ep 0x81, starting at offset 0x960e1040
[  287.755238]  xhci-cdns3: // Ding dong!
[  287.755250]  xhci-cdns3: Stopped on Transfer TRB for slot 3 ep 2
[  287.755262]  xhci-cdns3: Removing canceled TD starting at 0x960e1040 (dma).
[  287.755268]  xhci-cdns3: Finding endpoint context
[  287.755273]  xhci-cdns3: Cycle state = 0x1
[  287.755278]  xhci-cdns3: New dequeue segment = 0000000025bf7477 (virtual)
[  287.755283]  xhci-cdns3: New dequeue pointer = 0x960e1050 (DMA)
[  287.755291]  xhci-cdns3: Set TR Deq Ptr cmd, new deq seg = 0000000025bf7477 (0x960e1000 dma), new deq ptr = 0000000098e74c6d (0x960e1050 dma), new cycle = 1
[  287.755297]  xhci-cdns3: // Ding dong!
[  287.755313]  xhci-cdns3: Successful Set TR Deq Ptr cmd, deq = @960e1050
[  287.755398]  xhci-cdns3: // Ding dong!
[  287.755413]  xhci-cdns3: Stopped on No-op or Link TRB for slot 3 ep 0
[  287.795124]  xhci-cdns3: xhci_hub_status_data: stopping port polling.
[  287.795153]  xhci-cdns3: xhci_suspend: stopping port polling.
[  287.795167]  xhci-cdns3: // Setting command ring address to 0x96049001

Re: USB transaction errors causing RCU stalls and kernel panics

[Fabio Estevam]

Hi Jonas,

On Tue, Mar 10, 2020 at 1:07 PM Jonas Karlsson <jonas.karlsson@actia.se> wrote:

> I have also _reverted_ this patch after recommendation from NXP to avoid RCU stall
> crashes:
>
> commit 077506972ba23772b752e08b1ab7052cf5f04511
> Author: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> Date:   Mon Jul 9 13:47:30 2018 -0700
>
>     rcu: Make need_resched() respond to urgent RCU-QS needs

Could you please test without this revert?

Thanks

RE: USB transaction errors causing RCU stalls and kernel panics

[Jonas Karlsson]

Hi Fabio,

> Hi Jonas,
> 
> On Tue, Mar 10, 2020 at 1:07 PM Jonas Karlsson <jonas.karlsson@actia.se>
> wrote:
> 
> > I have also _reverted_ this patch after recommendation from NXP to avoid
> RCU stall
> > crashes:
> >
> > commit 077506972ba23772b752e08b1ab7052cf5f04511
> > Author: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> > Date:   Mon Jul 9 13:47:30 2018 -0700
> >
> >     rcu: Make need_resched() respond to urgent RCU-QS needs
> 
> Could you please test without this revert?
> 
> Thanks

I removed the revert and it still works fine.

//Jonas

Re: USB transaction errors causing RCU stalls and kernel panics

[Oliver Neukum]

Am Mittwoch, den 11.03.2020, 06:25 +0000 schrieb Jonas Karlsson:
> Hi Fabio,
> 
> > Hi Jonas,
> > 
> > On Tue, Mar 10, 2020 at 1:07 PM Jonas Karlsson <jonas.karlsson@actia.se>
> > wrote:
> > 
> > > I have also _reverted_ this patch after recommendation from NXP to avoid
> > 
> > RCU stall
> > > crashes:
> > > 
> > > commit 077506972ba23772b752e08b1ab7052cf5f04511
> > > Author: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> > > Date:   Mon Jul 9 13:47:30 2018 -0700
> > > 
> > >     rcu: Make need_resched() respond to urgent RCU-QS needs
> > 
> > Could you please test without this revert?
> > 
> > Thanks
> 
> I removed the revert and it still works fine.

Hi,

it is good that we have something that works.
It would be even better if we understood exactly how
it works. In fact that these patches work and are needed
may very well indicate that error handling on at least
some XHCs does not work as expected.

So a question and a request, if I may.
Did you run the test with autosuspend disabled? If so could
you retest with it enabled?
Secondly could you run tests with

commit 7c8f7af078a4eda73f347667d12584736e613062
Author: Oliver Neukum <oneukum@suse.com>
Date:   Thu Mar 5 11:16:02 2020 +0100

    cdc-acm: close race betrween suspend() and acm_softint

not applied (respectively reverted) with and without autosuspend?

	Regards
		Oliver

PS: When I submit upstream, may I add your 'Tested-by'?

RE: USB transaction errors causing RCU stalls and kernel panics

[Jonas Karlsson]

Hi Oliver,

> Hi,
> 
> it is good that we have something that works.
> It would be even better if we understood exactly how it works. In fact that
> these patches work and are needed may very well indicate that error
> handling on at least some XHCs does not work as expected.
> 
> So a question and a request, if I may.
> Did you run the test with autosuspend disabled? If so could you retest with it
> enabled?

I have only tested with autosuspend enabled.

> Secondly could you run tests with
> 
> commit 7c8f7af078a4eda73f347667d12584736e613062
> Author: Oliver Neukum <oneukum@suse.com>
> Date:   Thu Mar 5 11:16:02 2020 +0100
> 
>     cdc-acm: close race betrween suspend() and acm_softint
> 
> not applied (respectively reverted) with and without autosuspend?

I ran a test with this commit reverted and saw no difference in behavior.
i.e we do not get event spam with this commit reverted.
I tested with enabled and disabled autosuspend.

> 
> 	Regards
> 		Oliver
> 
> PS: When I submit upstream, may I add your 'Tested-by'?

Sure, you can add me, but I have only tested that this specific problem
seems to be solved. The normal functionality has not been tested  properly yet
on our side. 

//Jonas

Re: USB transaction errors causing RCU stalls and kernel panics

[Oliver Neukum]

Am Mittwoch, den 11.03.2020, 14:59 +0000 schrieb Jonas Karlsson:
> Hi Oliver,
> 
> > Hi,
> > 
> > it is good that we have something that works.
> > It would be even better if we understood exactly how it works. In fact that
> > these patches work and are needed may very well indicate that error
> > handling on at least some XHCs does not work as expected.
> > 
> > So a question and a request, if I may.
> > Did you run the test with autosuspend disabled? If so could you retest with it
> > enabled?
> 
> I have only tested with autosuspend enabled.
> 
> > Secondly could you run tests with
> > 
> > commit 7c8f7af078a4eda73f347667d12584736e613062
> > Author: Oliver Neukum <oneukum@suse.com>
> > Date:   Thu Mar 5 11:16:02 2020 +0100
> > 
> >     cdc-acm: close race betrween suspend() and acm_softint
> > 
> > not applied (respectively reverted) with and without autosuspend?
> 
> I ran a test with this commit reverted and saw no difference in behavior.
> i.e we do not get event spam with this commit reverted.
> I tested with enabled and disabled autosuspend.
> 
> > 
> > 	Regards
> > 		Oliver
> > 
> > PS: When I submit upstream, may I add your 'Tested-by'?
> 
> Sure, you can add me, but I have only tested that this specific problem
> seems to be solved. The normal functionality has not been tested  properly yet
> on our side. 

Hi,

thank you. In this case it looks like the wisest course is to wait
a few days then. Thank you for thorough testing.

	Regards
		Oliver

RE: USB transaction errors causing RCU stalls and kernel panics

[Jonas Karlsson]

> Hi,
> 
> thank you. In this case it looks like the wisest course is to wait a few days then.
> Thank you for thorough testing.
> 
> 	Regards
> 		Oliver

I will make sure some more testing is done and the get back to you.

Do you intend to push the " cdc-acm: close race betrween suspend() and acm_softint"
commit upstream as well? I wonder since you asked me to test without it.

I want to make sure I run tests with the intended patch set.

BR,
Jonas

Re: USB transaction errors causing RCU stalls and kernel panics

[Oliver Neukum]

Am Donnerstag, den 12.03.2020, 15:37 +0000 schrieb Jonas Karlsson:
> > Hi,
> > 
> > thank you. In this case it looks like the wisest course is to wait a few days then.
> > Thank you for thorough testing.
> > 
> > 	Regards
> > 		Oliver
> 
> I will make sure some more testing is done and the get back to you.
> 
> Do you intend to push the " cdc-acm: close race betrween suspend() and acm_softint"
> commit upstream as well? I wonder since you asked me to test without it.

Yes. I will submit the whole set.
And I will talk to Mathias, as the need for this patch set
means that XHCI does not work as documented.

> I want to make sure I run tests with the intended patch set.

That is optimal. Thank you.

	Regards
		Oliver

RE: USB transaction errors causing RCU stalls and kernel panics

[Jonas Karlsson]

> 
> Hi,
> 
> thank you. In this case it looks like the wisest course is to wait a few days then.
> Thank you for thorough testing.
> 
> 	Regards
> 		Oliver

Hi Oliver,

The apps team ran a couple modem tests with the patches and it looked good.

BR,
Jonas

RE: USB transaction errors causing RCU stalls and kernel panics

[Jonas Karlsson]

Hi Oliver,

Have the patches been reviewed and will be merged?

BR,
Jonas

> -----Original Message-----
> From: linux-usb-owner@vger.kernel.org <linux-usb-owner@vger.kernel.org> On
> Behalf Of Jonas Karlsson
> Sent: den 16 mars 2020 08:07
> To: Oliver Neukum <oneukum@suse.com>; Fabio Estevam
> <festevam@gmail.com>
> Cc: Peter Chen <peter.chen@nxp.com>; Mathias Nyman
> <mathias.nyman@linux.intel.com>; Greg KH <gregkh@linuxfoundation.org>;
> linux-usb@vger.kernel.org; Alan Stern <stern@rowland.harvard.edu>
> Subject: RE: USB transaction errors causing RCU stalls and kernel panics
> 
> >
> > Hi,
> >
> > thank you. In this case it looks like the wisest course is to wait a few days then.
> > Thank you for thorough testing.
> >
> > 	Regards
> > 		Oliver
> 
> Hi Oliver,
> 
> The apps team ran a couple modem tests with the patches and it looked good.
> 
> BR,
> Jonas
>