Hi,
Plugging and unplugging a USB-OTG adapter with a USB device into a
am437x-gp-evm dual-role port (USB1) causes XHCI to malfunction
and USB device to be no longer detected after a few iterations.
The triggering case is so
1) USB1 in peripheal mode
2) plug OTG adapter with USB device
3) USB1 switches to host mode
4) Detects new USB device
5) unplug OTG adapter
6) OTG core tries to remove host controller while new device
is being processed.
At 6 some races are observed in the XHCI driver causing it to
malfunction. See kernel log at the end of this mail.
This series tries to address some of the issues.
Althouth it is not 100% fool proof yet and XHCI can still get
stuck up for a few seconds occasionally, it did recover always
in a max of 10 seconds and the USB device was enumerated after
that.
During a dual-role switch, usb_remove_hcd() and usb_add_hcd()
will be called consecutively for both Shared and Primary
HCDs. This can happen asynchronously and we have to be prepared
for it.
--
cheers,
-roger
Roger Quadros (5):
usb: xhci: lock mutex on xhci_stop
usb: hcd: Initialize hcd->flags to 0
usb: xhci: Clear XHCI_STATE_DYING on start
usb: xhci: stop everything on the first call to xhci_stop
usb: xhci: exit early in xhci_setup_device() if we're halted or dying
drivers/usb/core/hcd.c | 1 +
drivers/usb/host/xhci.c | 24 +++++++++++-------------
2 files changed, 12 insertions(+), 13 deletions(-)
--
2.1.4
kernel log during dual-role switch.
Platform: am437x-gp-evm.
Test case: Repeatedly plug and unplug a USB-OTG adapter to/from a dual
role port (USB1 in this case) with Mass storage device attached to the
adapter all the while.
Adapter plugged
[ 112.720322] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[ 112.726209] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 3
[ 112.736919] xhci-hcd xhci-hcd.0.auto: hcc params 0x0238f06d hci version 0x100 quirks 0x00010010
[ 112.746162] xhci-hcd xhci-hcd.0.auto: irq 216, io mem 0x48390000
[ 112.754717] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002
[ 112.761815] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 112.769423] usb usb3: Product: xHCI Host Controller
[ 112.774542] usb usb3: Manufacturer: Linux 4.2.0-rc6-00027-g26afc4a xhci-hcd
[ 112.781805] usb usb3: SerialNumber: xhci-hcd.0.auto
[ 112.791761] hub 3-0:1.0: USB hub found
[ 112.796374] hub 3-0:1.0: 1 port detected
[ 112.801893] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[ 112.807786] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 4
[ 112.828676] usb usb4: We don't know the algorithms for LPM for this host, disabling LPM.
[ 112.842572] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003
[ 112.849911] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 112.857537] usb usb4: Product: xHCI Host Controller
[ 112.862640] usb usb4: Manufacturer: Linux 4.2.0-rc6-00027-g26afc4a xhci-hcd
[ 112.869973] usb usb4: SerialNumber: xhci-hcd.0.auto
[ 112.888053] hub 4-0:1.0: USB hub found
[ 112.893454] hub 4-0:1.0: 1 port detected
adapter unplugged
[ 113.114023] usb 3-1: new high-speed USB device number 2 using xhci-hcd
[ 113.254855] usb 3-1: New USB device found, idVendor=0781, idProduct=5539
[ 113.261863] usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 113.269374] usb 3-1: Product: Cruzer Micro
[ 113.273652] usb 3-1: Manufacturer: SanDisk
[ 113.277953] usb 3-1: SerialNumber: 173733160C524A8E
[ 113.288636] usb-storage 3-1:1.0: USB Mass Storage device detected
[ 113.296663] scsi host7: usb-storage 3-1:1.0
[ 113.368620] xhci-hcd xhci-hcd.0.auto: remove, state 4
[ 113.374142] usb usb4: USB disconnect, device number 1
[ 113.382381] usb 3-1: USB disconnect, device number 2
[ 113.405815] xhci-hcd xhci-hcd.0.auto: USB bus 4 deregistered
[ 113.411817] xhci-hcd xhci-hcd.0.auto: remove, state 1
[ 113.417278] usb usb3: USB disconnect, device number 1
[ 113.449219] xhci-hcd xhci-hcd.0.auto: USB bus 3 deregistered
adapter plugged
[ 116.540119] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[ 116.545984] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 3
[ 116.555638] xhci-hcd xhci-hcd.0.auto: hcc params 0x0238f06d hci version 0x100 quirks 0x00010010
[ 116.564863] xhci-hcd xhci-hcd.0.auto: irq 216, io mem 0x48390000
[ 116.571860] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002
[ 116.579005] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 116.586567] usb usb3: Product: xHCI Host Controller
[ 116.591655] usb usb3: Manufacturer: Linux 4.2.0-rc6-00027-g26afc4a xhci-hcd
[ 116.598940] usb usb3: SerialNumber: xhci-hcd.0.auto
[ 116.609018] hub 3-0:1.0: USB hub found
[ 116.613451] hub 3-0:1.0: 1 port detected
[ 116.619814] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[ 116.625711] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 4
[ 116.646673] usb usb4: We don't know the algorithms for LPM for this host, disabling LPM.
[ 116.657195] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003
[ 116.664508] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 116.672055] usb usb4: Product: xHCI Host Controller
[ 116.677213] usb usb4: Manufacturer: Linux 4.2.0-rc6-00027-g26afc4a xhci-hcd
[ 116.684505] usb usb4: SerialNumber: xhci-hcd.0.auto
[ 116.701494] hub 4-0:1.0: USB hub found
[ 116.707150] hub 4-0:1.0: 1 port detected
adapter unplugged
[ 116.934027] usb 3-1: new high-speed USB device number 2 using xhci-hcd
[ 117.059900] xhci-hcd xhci-hcd.0.auto: remove, state 4
[ 117.065290] usb usb4: USB disconnect, device number 1
[ 117.098888] xhci-hcd xhci-hcd.0.auto: Host not halted after 16000 microseconds.
[ 117.106745] xhci-hcd xhci-hcd.0.auto: USB bus 4 deregistered
[ 117.112725] xhci-hcd xhci-hcd.0.auto: remove, state 1
[ 117.118084] usb usb3: USB disconnect, device number 1
we're stuck now.
root@rockdesk:~# [ 127.084066] xhci-hcd xhci-hcd.0.auto: xHCI host not responding to stop endpoint command.
[ 127.092524] xhci-hcd xhci-hcd.0.auto: Assuming host is dying, halting host.
[ 127.100745] xhci-hcd xhci-hcd.0.auto: HC died; cleaning up
[ 127.107143] usb 3-1: device descriptor read/all, error -110
[ 127.113131] usb usb3-port1: couldn't allocate usb_device
[ 127.126927] xhci-hcd xhci-hcd.0.auto: USB bus 3 deregistered
adapter plugged
root@rockdesk:~# [ 139.871074] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[ 139.876974] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 3
[ 139.894434] xhci-hcd xhci-hcd.0.auto: hcc params 0x0238f06d hci version 0x100 quirks 0x00010010
[ 139.903587] xhci-hcd xhci-hcd.0.auto: irq 216, io mem 0x48390000
[ 139.916843] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002
[ 139.923996] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 139.931540] usb usb3: Product: xHCI Host Controller
[ 139.936668] usb usb3: Manufacturer: Linux 4.2.0-rc6-00027-g26afc4a xhci-hcd
[ 139.943922] usb usb3: SerialNumber: xhci-hcd.0.auto
[ 139.954144] hub 3-0:1.0: USB hub found
[ 139.958632] hub 3-0:1.0: 1 port detected
[ 139.969142] xhci-hcd xhci-hcd.0.auto: HC died; cleaning up
[ 139.976289] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[ 139.982065] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 4
[ 140.235596] irq 216: nobody cared (try booting with the "irqpoll" option)
[ 140.242725] CPU: 0 PID: 2293 Comm: getty Not tainted 4.2.0-rc6-00027-g26afc4a #129
[ 140.250644] Hardware name: Generic AM43 (Flattened Device Tree)
[ 140.256869] [<c0016614>] (unwind_backtrace) from [<c0012b10>] (show_stack+0x10/0x14)
[ 140.264977] [<c0012b10>] (show_stack) from [<c05eb9f4>] (dump_stack+0x80/0x9c)
[ 140.272546] [<c05eb9f4>] (dump_stack) from [<c009b3d8>] (__report_bad_irq+0x20/0xc0)
[ 140.280645] [<c009b3d8>] (__report_bad_irq) from [<c009b97c>] (note_interrupt+0x250/0x2b0)
[ 140.289301] [<c009b97c>] (note_interrupt) from [<c009916c>] (handle_irq_event_percpu+0xd4/0x204)
[ 140.298499] [<c009916c>] (handle_irq_event_percpu) from [<c00992dc>] (handle_irq_event+0x40/0x64)
[ 140.307780] [<c00992dc>] (handle_irq_event) from [<c009c1e8>] (handle_fasteoi_irq+0xcc/0x1a8)
[ 140.316693] [<c009c1e8>] (handle_fasteoi_irq) from [<c00989ac>] (generic_handle_irq+0x20/0x30)
[ 140.325697] [<c00989ac>] (generic_handle_irq) from [<c0098ac0>] (__handle_domain_irq+0x64/0xdc)
[ 140.334794] [<c0098ac0>] (__handle_domain_irq) from [<c00094c4>] (gic_handle_irq+0x20/0x60)
[ 140.343534] [<c00094c4>] (gic_handle_irq) from [<c05f2864>] (__irq_svc+0x44/0x5c)
[ 140.351349] Exception stack(0xed2b1d38 to 0xed2b1d80)
[ 140.356630] 1d20: 00000001 00000000
[ 140.365183] 1d40: 00000000 ed6f6dc0 00000000 c08bd5c4 00000202 c096fd6c 00000001 ed2b0000
[ 140.373734] 1d60: ee008800 00000001 00000000 ed2b1d80 c008e870 c00439c8 60000113 ffffffff
[ 140.382274] [<c05f2864>] (__irq_svc) from [<c00439c8>] (__do_softirq+0xb4/0x350)
[ 140.389995] [<c00439c8>] (__do_softirq) from [<c0043f84>] (irq_exit+0xbc/0x130)
[ 140.397622] [<c0043f84>] (irq_exit) from [<c0098ac8>] (__handle_domain_irq+0x6c/0xdc)
[ 140.405785] [<c0098ac8>] (__handle_domain_irq) from [<c00094c4>] (gic_handle_irq+0x20/0x60)
[ 140.414508] [<c00094c4>] (gic_handle_irq) from [<c05f2864>] (__irq_svc+0x44/0x5c)
[ 140.422326] Exception stack(0xed2b1e00 to 0xed2b1e48)
[ 140.427599] 1e00: ed089d04 c0784128 c1156414 ed089d28 ed089cc0 00000000 c08bd7fc 00000005
[ 140.436140] 1e20: ed2b1f74 ed2b0000 00000000 00000001 00000000 ed2b1e48 c0166418 c0088b70
[ 140.444675] 1e40: 60000013 ffffffff
[ 140.448325] [<c05f2864>] (__irq_svc) from [<c0088b70>] (debug_mutex_init+0x0/0x34)
[ 140.456228] [<c0088b70>] (debug_mutex_init) from [<ed2b1f74>] (0xed2b1f74)
[ 140.463409] handlers:
[ 140.465951] [<bf14e7c0>] usb_hcd_irq [usbcore]
[ 140.470601] Disabling IRQ #216
Message from syslogd@rockdesk at Jan 1 00:02:20 ...
kernel:[ 140.470601] Disabling IRQ #216
[ 140.518776] usb usb4: We don't know the algorithms for LPM for this host, disabling LPM.
[ 140.556446] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003
[ 140.563551] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 140.571211] usb usb4: Product: xHCI Host Controller
[ 140.576412] usb usb4: Manufacturer: Linux 4.2.0-rc6-00027-g26afc4a xhci-hcd
[ 140.583669] usb usb4: SerialNumber: xhci-hcd.0.auto
[ 140.619169] hub 4-0:1.0: USB hub found
[ 140.626027] hub 4-0:1.0: 1 port detected
Mass storage device wasn't enumerated.
root@rockdesk:~# [ 146.714445] xhci-hcd xhci-hcd.0.auto: remove, state 4
[ 146.719787] usb usb4: USB disconnect, device number 1
[ 146.753175] xhci-hcd xhci-hcd.0.auto: Host not halted after 16000 microseconds.
[ 146.761035] xhci-hcd xhci-hcd.0.auto: USB bus 4 deregistered
[ 146.767041] xhci-hcd xhci-hcd.0.auto: remove, state 1
[ 146.772353] usb usb3: USB disconnect, device number 1
[ 146.786007] xhci-hcd xhci-hcd.0.auto: USB bus 3 deregistered
Else it races with xhci_setup_device
Signed-off-by: Roger Quadros <[email protected]>
---
drivers/usb/host/xhci.c | 4 ++++
1 file changed, 4 insertions(+)
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index 526ebc0..f998ddf 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -677,8 +677,11 @@ void xhci_stop(struct usb_hcd *hcd)
u32 temp;
struct xhci_hcd *xhci = hcd_to_xhci(hcd);
+ mutex_lock(&xhci->mutex);
+
if (!usb_hcd_is_primary_hcd(hcd)) {
xhci_only_stop_hcd(xhci->shared_hcd);
+ mutex_unlock(&xhci->mutex);
return;
}
@@ -717,6 +720,7 @@ void xhci_stop(struct usb_hcd *hcd)
xhci_dbg_trace(xhci, trace_xhci_dbg_init,
"xhci_stop completed - status = %x",
readl(&xhci->op_regs->status));
+ mutex_unlock(&xhci->mutex);
}
/*
--
2.1.4
When using the OTG/drd library we can call hcd_add/remove
consecutively without and hcd_alloc so flags can be stale.
If the HC dies due to whatever reason then without this
patch we get the below error on next hcd_add.
[ 91.494257] xhci-hcd xhci-hcd.0.auto: HC died; cleaning up
[ 91.502068] hub 3-0:1.0: state 0 ports 1 chg 0000 evt 0000
[ 91.510240] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[ 91.516940] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 4
[ 91.529745] usb usb4: We don't know the algorithms for LPM for this host, disabling LPM.
[ 91.540637] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003
[ 91.757865] irq 254: nobody cared (try booting with the "irqpoll" option)
[ 91.757880] CPU: 0 PID: 68 Comm: kworker/u2:2 Not tainted 4.1.4-00828-g1f0ed8c-dirty #44
[ 91.757885] Hardware name: Generic AM43 (Flattened Device Tree)
[ 91.757914] Workqueue: usb_otg usb_otg_work
[ 91.757921] Backtrace:
[ 91.757954] [<c0012af0>] (dump_backtrace) from [<c0012c8c>] (show_stack+0x18/0x1c)
[ 91.757972] r6:c089d4a4 r5:ffffffff r4:00000000 r3:ee440000
[ 91.757991] [<c0012c74>] (show_stack) from [<c05f7c14>] (dump_stack+0x84/0xd0)
[ 91.758008] [<c05f7b90>] (dump_stack) from [<c0084b30>] (__report_bad_irq+0x28/0xc8)
[ 91.758024] r7:00000000 r6:000000fe r5:00000000 r4:ee514c40
[ 91.758037] [<c0084b08>] (__report_bad_irq) from [<c00850b0>] (note_interrupt+0x24c/0x2ac)
[ 91.758052] r6:000000fe r5:00000000 r4:ee514c40 r3:00000000
[ 91.758065] [<c0084e64>] (note_interrupt) from [<c00828fc>] (handle_irq_event_percpu+0xb0/0x158)
[ 91.758085] r10:ee514c40 r9:c08ce49a r8:000000fe r7:00000000 r6:00000000 r5:00000000
[ 91.758094] r4:00000000 r3:00000000
[ 91.758105] [<c008284c>] (handle_irq_event_percpu) from [<c00829e8>] (handle_irq_event+0x44/0x64)
[ 91.758126] r10:00000001 r9:ee441ab0 r8:ee441bb8 r7:c0858b4c r6:ed174280 r5:ee514ca0
[ 91.758132] r4:ee514c40
[ 91.758144] [<c00829a4>] (handle_irq_event) from [<c0085970>] (handle_fasteoi_irq+0x100/0x1bc)
[ 91.758159] r6:c085dba0 r5:ee514ca0 r4:ee514c40 r3:00000000
[ 91.758171] [<c0085870>] (handle_fasteoi_irq) from [<c0082058>] (generic_handle_irq+0x28/0x38)
[ 91.758186] r7:c0853d40 r6:c0858b4c r5:000000fe r4:000000fe
[ 91.758197] [<c0082030>] (generic_handle_irq) from [<c00821c0>] (__handle_domain_irq+0x98/0x12c)
[ 91.758207] r4:c0853d40 r3:00000100
[ 91.758219] [<c0082128>] (__handle_domain_irq) from [<c00094e0>] (gic_handle_irq+0x28/0x68)
[ 91.758239] r10:00000001 r9:ee441bb8 r8:fa240100 r7:c0858d70 r6:ee441ab0 r5:000000b8
[ 91.758245] r4:fa24010c
[ 91.758264] [<c00094b8>] (gic_handle_irq) from [<c05fd540>] (__irq_svc+0x40/0x74)
[ 91.758271] Exception stack(0xee441ab0 to 0xee441af8)
[ 91.758280] 1aa0: 00000000 c08d2980 ee441ac0 00000000
[ 91.758292] 1ac0: 00000008 00000089 c0858b4c c0858080 00000000 ee441bb8 00000001 ee441b3c
[ 91.758301] 1ae0: 00000101 ee441af8 c02fc418 c0046a1c 20000113 ffffffff
[ 91.758321] r8:00000000 r7:ee441ae4 r6:ffffffff r5:20000113 r4:c0046a1c r3:c02fc418
[ 91.758347] [<c00469a0>] (__do_softirq) from [<c0046eac>] (irq_exit+0xb8/0x104)
[ 91.758367] r10:00000001 r9:ee441bb8 r8:00000000 r7:c0853d40 r6:c0858b4c r5:00000089
[ 91.758373] r4:00000000
[ 91.758386] [<c0046df4>] (irq_exit) from [<c00821c8>] (__handle_domain_irq+0xa0/0x12c)
[ 91.758395] r4:00000000 r3:00000100
[ 91.758406] [<c0082128>] (__handle_domain_irq) from [<c00094e0>] (gic_handle_irq+0x28/0x68)
[ 91.758426] r10:c08e3510 r9:20000013 r8:fa240100 r7:c0858d70 r6:ee441bb8 r5:00000039
[ 91.758433] r4:fa24010c
[ 91.758445] [<c00094b8>] (gic_handle_irq) from [<c05fd540>] (__irq_svc+0x40/0x74)
[ 91.758450] Exception stack(0xee441bb8 to 0xee441c00)
[ 91.758457] 1ba0: 00000000 00000001
[ 91.758468] 1bc0: 00000000 ee440000 c08e2524 0000004d 00000274 00000000 00000000 20000013
[ 91.758479] 1be0: c08e3510 ee441c4c ee441b60 ee441c00 c03acfec c0080d4c 60000013 ffffffff
[ 91.758499] r8:00000000 r7:ee441bec r6:ffffffff r5:60000013 r4:c0080d4c r3:c03acfec
[ 91.758524] [<c0080950>] (console_unlock) from [<c0081670>] (vprintk_emit+0x20c/0x500)
[ 91.758544] r10:ee441cc0 r9:c08d3550 r8:c08e3ea0 r7:00000000 r6:00000001 r5:0000003d
[ 91.758551] r4:c08d3550
[ 91.758573] [<c0081464>] (vprintk_emit) from [<c03f6f70>] (dev_vprintk_emit+0x104/0x1ac)
[ 91.758593] r10:ee441d8c r9:0000000e r8:c07951e0 r7:00000006 r6:ee441cc0 r5:0000000d
[ 91.758599] r4:ee731068
[ 91.758612] [<c03f6e6c>] (dev_vprintk_emit) from [<c03f7040>] (dev_printk_emit+0x28/0x30)
[ 91.758632] r10:00000001 r9:ee5f8410 r8:ee731000 r7:ed429000 r6:00000006 r5:ee441dc0
[ 91.758638] r4:ee731068
[ 91.758651] [<c03f701c>] (dev_printk_emit) from [<c03f7098>] (__dev_printk+0x50/0x70)
[ 91.758660] r3:bf2268cc r2:c07951e0
[ 91.758673] [<c03f7048>] (__dev_printk) from [<c03f70f4>] (_dev_info+0x3c/0x48)
[ 91.758686] r6:00000000 r5:ee731068 r4:ee731000
[ 91.758790] [<c03f70bc>] (_dev_info) from [<bf20ec3c>] (usb_new_device+0x11c/0x518 [usbcore])
[ 91.758804] r3:00000003 r2:00001d6b r1:bf225bc4
[ 91.758881] [<bf20eb20>] (usb_new_device [usbcore]) from [<bf213560>] (usb_otg_add_hcd+0x514/0x7f8 [usbcore])
[ 91.758903] r10:00000001 r9:ee5f8410 r8:ee731000 r7:000000fe r6:ed4290c8 r5:00000000
[ 91.758909] r4:ed429000
[ 91.758957] [<bf21304c>] (usb_otg_add_hcd [usbcore]) from [<c047a238>] (usb_otg_start_host+0xb8/0xf8)
[ 91.758978] r10:00000000 r9:00000002 r8:00000000 r7:ee02b000 r6:ee452808 r5:ee452808
[ 91.758985] r4:ee452808
[ 91.758997] [<c047a180>] (usb_otg_start_host) from [<c047a020>] (drd_set_protocol+0xac/0xd8)
[ 91.759007] r4:00000001 r3:c047a180
[ 91.759018] [<c0479f74>] (drd_set_protocol) from [<c047a2ec>] (drd_set_state+0x74/0x98)
[ 91.759027] r5:ee452808 r4:00000009
[ 91.759039] [<c047a278>] (drd_set_state) from [<c047a3dc>] (usb_otg_work+0xcc/0x154)
[ 91.759054] r6:ee452808 r5:ee4528b8 r4:ee452968 r3:00000000
[ 91.759072] [<c047a310>] (usb_otg_work) from [<c005754c>] (process_one_work+0x128/0x340)
[ 91.759087] r6:ee02ac00 r5:ee452968 r4:ee42b900 r3:c047a310
[ 91.759100] [<c0057424>] (process_one_work) from [<c00578f8>] (worker_thread+0x158/0x49c)
[ 91.759120] r10:ee42b900 r9:00000002 r8:ee02ac00 r7:00000088 r6:ee42b918 r5:ee02ac00
[ 91.759127] r4:ee02ac14
[ 91.759145] [<c00577a0>] (worker_thread) from [<c005cc40>] (kthread+0xdc/0xf8)
[ 91.759165] r10:00000000 r9:00000000 r8:00000000 r7:c00577a0 r6:ee42b900 r5:ee429940
[ 91.759174] r4:00000000 r3:00000000
[ 91.759190] [<c005cb64>] (kthread) from [<c000fc08>] (ret_from_fork+0x14/0x2c)
[ 91.759206] r7:00000000 r6:00000000 r5:c005cb64 r4:ee429940
[ 91.759209] handlers:
[ 91.759255] [<bf211b5c>] usb_hcd_irq [usbcore]
[ 91.759260] Disabling IRQ #254
Signed-off-by: Roger Quadros <[email protected]>
---
drivers/usb/core/hcd.c | 1 +
1 file changed, 1 insertion(+)
diff --git a/drivers/usb/core/hcd.c b/drivers/usb/core/hcd.c
index 636e008..3ac3ec1 100644
--- a/drivers/usb/core/hcd.c
+++ b/drivers/usb/core/hcd.c
@@ -2632,6 +2632,7 @@ static int usb_otg_add_hcd(struct usb_hcd *hcd,
int retval;
struct usb_device *rhdev;
+ hcd->flags = 0;
if (IS_ENABLED(CONFIG_USB_PHY) && !hcd->usb_phy) {
struct usb_phy *phy = usb_get_phy_dev(hcd->self.controller, 0);
--
2.1.4
For whatever reason if XHCI died in the previous instant
then it will never recover on the next xhci_start unless we
clear the DYING flag.
Signed-off-by: Roger Quadros <[email protected]>
---
drivers/usb/host/xhci.c | 3 ++-
1 file changed, 2 insertions(+), 1 deletion(-)
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index f998ddf..d5f44b1 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -146,7 +146,8 @@ static int xhci_start(struct xhci_hcd *xhci)
"waited %u microseconds.\n",
XHCI_MAX_HALT_USEC);
if (!ret)
- xhci->xhc_state &= ~XHCI_STATE_HALTED;
+ xhci->xhc_state &= ~(XHCI_STATE_HALTED | XHCI_STATE_DYING);
+
return ret;
}
--
2.1.4
xhci_stop will be called twice, once for the shared hcd
and again for the primary hcd.
We stop the XHCI controller in any case so clean up
everything on the first call else we can timeout
waiting for pending requests to complete.
Signed-off-by: Roger Quadros <[email protected]>
---
drivers/usb/host/xhci.c | 20 +++++---------------
1 file changed, 5 insertions(+), 15 deletions(-)
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index d5f44b1..9a7f12c 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -655,15 +655,6 @@ int xhci_run(struct usb_hcd *hcd)
}
EXPORT_SYMBOL_GPL(xhci_run);
-static void xhci_only_stop_hcd(struct usb_hcd *hcd)
-{
- struct xhci_hcd *xhci = hcd_to_xhci(hcd);
-
- spin_lock_irq(&xhci->lock);
- xhci_halt(xhci);
- spin_unlock_irq(&xhci->lock);
-}
-
/*
* Stop xHCI driver.
*
@@ -678,15 +669,14 @@ void xhci_stop(struct usb_hcd *hcd)
u32 temp;
struct xhci_hcd *xhci = hcd_to_xhci(hcd);
- mutex_lock(&xhci->mutex);
-
- if (!usb_hcd_is_primary_hcd(hcd)) {
- xhci_only_stop_hcd(xhci->shared_hcd);
- mutex_unlock(&xhci->mutex);
+ if (xhci->xhc_state & XHCI_STATE_HALTED)
return;
- }
+ mutex_lock(&xhci->mutex);
spin_lock_irq(&xhci->lock);
+ xhci->xhc_state |= XHCI_STATE_HALTED;
+ xhci->cmd_ring_state = CMD_RING_STATE_STOPPED;
+
/* Make sure the xHC is halted for a USB3 roothub
* (xhci_stop() could be called as part of failed init).
*/
--
2.1.4
During quick plug/removal of OTG adapter during dual-role testing
it can happen that xhci_alloc_device() is called for the newly
detected device after the DRD library has called xhci_stop to
remove the HCD.
If that is the case, just fail early to prevent the following warning.
[ 154.732649] hub 4-0:1.0: USB hub found
[ 154.742204] hub 4-0:1.0: 1 port detected
[ 154.824458] hub 3-0:1.0: state 7 ports 1 chg 0002 evt 0000
[ 154.854609] hub 4-0:1.0: state 7 ports 1 chg 0000 evt 0000
[ 154.944430] usb 3-1: new high-speed USB device number 2 using xhci-hcd
[ 154.951009] xhci-hcd xhci-hcd.0.auto: xhci_setup_device
[ 155.038191] xhci-hcd xhci-hcd.0.auto: remove, state 4
[ 155.043315] usb usb4: USB disconnect, device number 1
[ 155.055270] xhci-hcd xhci-hcd.0.auto: xhci_stop
[ 155.060094] xhci-hcd xhci-hcd.0.auto: USB bus 4 deregistered
[ 155.066576] xhci-hcd xhci-hcd.0.auto: remove, state 1
[ 155.071710] usb usb3: USB disconnect, device number 1
[ 155.077124] xhci-hcd xhci-hcd.0.auto: xhci_setup_device
[ 155.082389] ------------[ cut here ]------------
[ 155.087690] WARNING: CPU: 0 PID: 72 at drivers/usb/host/xhci.c:3800 xhci_setup_device+0x410/0x484 [xhci_hcd]()
[ 155.097861] Modules linked in: sd_mod usb_storage scsi_mod usb_f_ss_lb g_zero libcomposite ipv6 xhci_plat_hcd xhci_hcd usbcore dwc3 udc_core evdev ti_am335x_adc joydev kfifo_buf industrialio snd_soc_simple_cc
[ 155.146734] CPU: 0 PID: 72 Comm: kworker/0:3 Tainted: G W 4.1.4-00834-gcd9380b-dirty #50
[ 155.156073] Hardware name: Generic AM43 (Flattened Device Tree)
[ 155.162117] Workqueue: usb_hub_wq hub_event [usbcore]
[ 155.167249] Backtrace:
[ 155.169751] [<c0012af0>] (dump_backtrace) from [<c0012c8c>] (show_stack+0x18/0x1c)
[ 155.177390] r6:c089d4a4 r5:ffffffff r4:00000000 r3:ee46c000
[ 155.183137] [<c0012c74>] (show_stack) from [<c05f7c14>] (dump_stack+0x84/0xd0)
[ 155.190446] [<c05f7b90>] (dump_stack) from [<c00439ac>] (warn_slowpath_common+0x80/0xbc)
[ 155.198605] r7:00000009 r6:00000ed8 r5:bf27eb70 r4:00000000
[ 155.204348] [<c004392c>] (warn_slowpath_common) from [<c0043a0c>] (warn_slowpath_null+0x24/0x2c)
[ 155.213202] r8:ee49f000 r7:ee7c0004 r6:00000000 r5:ee7c0158 r4:ee7c0000
[ 155.220051] [<c00439e8>] (warn_slowpath_null) from [<bf27eb70>] (xhci_setup_device+0x410/0x484 [xhci_hcd])
[ 155.229816] [<bf27e760>] (xhci_setup_device [xhci_hcd]) from [<bf27ec10>] (xhci_address_device+0x14/0x18 [xhci_hcd])
[ 155.240415] r10:ee598200 r9:00000001 r8:00000002 r7:00000001 r6:00000003 r5:00000002
[ 155.248363] r4:ee49f000
[ 155.250978] [<bf27ebfc>] (xhci_address_device [xhci_hcd]) from [<bf20cb94>] (hub_port_init+0x1b8/0xa9c [usbcore])
[ 155.261403] [<bf20c9dc>] (hub_port_init [usbcore]) from [<bf2101e0>] (hub_event+0x738/0x1020 [usbcore])
[ 155.270874] r10:ee598200 r9:ee7c0000 r8:ee7c0038 r7:ee518800 r6:ee49f000 r5:00000001
[ 155.278822] r4:00000000
[ 155.281426] [<bf20faa8>] (hub_event [usbcore]) from [<c005754c>] (process_one_work+0x128/0x340)
[ 155.290196] r10:00000000 r9:00000003 r8:00000000 r7:fedfa000 r6:eeec5400 r5:ee598314
[ 155.298151] r4:ee434380
[ 155.300718] [<c0057424>] (process_one_work) from [<c00578f8>] (worker_thread+0x158/0x49c)
[ 155.308963] r10:ee434380 r9:00000003 r8:eeec5400 r7:00000008 r6:ee434398 r5:eeec5400
[ 155.316913] r4:eeec5414
[ 155.319482] [<c00577a0>] (worker_thread) from [<c005cc40>] (kthread+0xdc/0xf8)
[ 155.326765] r10:00000000 r9:00000000 r8:00000000 r7:c00577a0 r6:ee434380 r5:ee4441c0
[ 155.334713] r4:00000000 r3:00000000
[ 155.338341] [<c005cb64>] (kthread) from [<c000fc08>] (ret_from_fork+0x14/0x2c)
[ 155.345626] r7:00000000 r6:00000000 r5:c005cb64 r4:ee4441c0
[ 155.356108] ---[ end trace a58d34c223b190e6 ]---
[ 155.360783] xhci-hcd xhci-hcd.0.auto: Virt dev invalid for slot_id 0x1!
[ 155.574404] xhci-hcd xhci-hcd.0.auto: xhci_setup_device
[ 155.579667] ------------[ cut here ]------------
Signed-off-by: Roger Quadros <[email protected]>
---
drivers/usb/host/xhci.c | 3 +++
1 file changed, 3 insertions(+)
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index 9a7f12c..accfb14 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -3783,6 +3783,9 @@ static int xhci_setup_device(struct usb_hcd *hcd, struct usb_device *udev,
mutex_lock(&xhci->mutex);
+ if (xhci->xhc_state) /* dying or halted */
+ goto out;
+
if (!udev->slot_id) {
xhci_dbg_trace(xhci, trace_xhci_dbg_address,
"Bad Slot ID %d", udev->slot_id);
--
2.1.4
On 18.08.2015 13:39, Roger Quadros wrote:
> Else it races with xhci_setup_device
>
> Signed-off-by: Roger Quadros <[email protected]>
> ---
Thanks.
Applied, will send forward after 4.3-rc1
-Mathias
On 18.08.2015 13:39, Roger Quadros wrote:
> For whatever reason if XHCI died in the previous instant
> then it will never recover on the next xhci_start unless we
> clear the DYING flag.
>
> Signed-off-by: Roger Quadros <[email protected]>
> ---
> drivers/usb/host/xhci.c | 3 ++-
> 1 file changed, 2 insertions(+), 1 deletion(-)
>
> diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
> index f998ddf..d5f44b1 100644
> --- a/drivers/usb/host/xhci.c
> +++ b/drivers/usb/host/xhci.c
> @@ -146,7 +146,8 @@ static int xhci_start(struct xhci_hcd *xhci)
> "waited %u microseconds.\n",
> XHCI_MAX_HALT_USEC);
> if (!ret)
> - xhci->xhc_state &= ~XHCI_STATE_HALTED;
> + xhci->xhc_state &= ~(XHCI_STATE_HALTED | XHCI_STATE_DYING);
> +
> return ret;
> }
>
>
Thanks, applied
-Mathias
On 18.08.2015 13:39, Roger Quadros wrote:
> xhci_stop will be called twice, once for the shared hcd
> and again for the primary hcd.
>
> We stop the XHCI controller in any case so clean up
> everything on the first call else we can timeout
> waiting for pending requests to complete.
>
> Signed-off-by: Roger Quadros <[email protected]>
> ---
> drivers/usb/host/xhci.c | 20 +++++---------------
> 1 file changed, 5 insertions(+), 15 deletions(-)
>
> diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
> index d5f44b1..9a7f12c 100644
> --- a/drivers/usb/host/xhci.c
> +++ b/drivers/usb/host/xhci.c
> @@ -655,15 +655,6 @@ int xhci_run(struct usb_hcd *hcd)
> }
> EXPORT_SYMBOL_GPL(xhci_run);
>
> -static void xhci_only_stop_hcd(struct usb_hcd *hcd)
> -{
> - struct xhci_hcd *xhci = hcd_to_xhci(hcd);
> -
> - spin_lock_irq(&xhci->lock);
> - xhci_halt(xhci);
> - spin_unlock_irq(&xhci->lock);
> -}
> -
> /*
> * Stop xHCI driver.
> *
> @@ -678,15 +669,14 @@ void xhci_stop(struct usb_hcd *hcd)
> u32 temp;
> struct xhci_hcd *xhci = hcd_to_xhci(hcd);
>
> - mutex_lock(&xhci->mutex);
> -
> - if (!usb_hcd_is_primary_hcd(hcd)) {
> - xhci_only_stop_hcd(xhci->shared_hcd);
> - mutex_unlock(&xhci->mutex);
> + if (xhci->xhc_state & XHCI_STATE_HALTED)
> return;
> - }
>
> + mutex_lock(&xhci->mutex);
> spin_lock_irq(&xhci->lock);
> + xhci->xhc_state |= XHCI_STATE_HALTED;
> + xhci->cmd_ring_state = CMD_RING_STATE_STOPPED;
> +
The XHCI_STATE_HALTED and CMD_RING_STATE_STOPPED states will be set in xhci_halt() right
after this.
Well, or, it actually sets them after waiting for the controller to really halt.
I guess setting them here helps the second call to hcd_stop() to return early, not taking the mutex and
trying to stop controller once again.
Applied
-Mathias
On 18.08.2015 13:39, Roger Quadros wrote:
> During quick plug/removal of OTG adapter during dual-role testing
> it can happen that xhci_alloc_device() is called for the newly
> detected device after the DRD library has called xhci_stop to
> remove the HCD.
>
> If that is the case, just fail early to prevent the following warning.
>
Thanks, applied
-Mathias
On 18/08/15 15:14, Mathias Nyman wrote:
> On 18.08.2015 13:39, Roger Quadros wrote:
>> xhci_stop will be called twice, once for the shared hcd
>> and again for the primary hcd.
>>
>> We stop the XHCI controller in any case so clean up
>> everything on the first call else we can timeout
>> waiting for pending requests to complete.
>>
>> Signed-off-by: Roger Quadros <[email protected]>
>> ---
>> drivers/usb/host/xhci.c | 20 +++++---------------
>> 1 file changed, 5 insertions(+), 15 deletions(-)
>>
>> diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
>> index d5f44b1..9a7f12c 100644
>> --- a/drivers/usb/host/xhci.c
>> +++ b/drivers/usb/host/xhci.c
>> @@ -655,15 +655,6 @@ int xhci_run(struct usb_hcd *hcd)
>> }
>> EXPORT_SYMBOL_GPL(xhci_run);
>>
>> -static void xhci_only_stop_hcd(struct usb_hcd *hcd)
>> -{
>> - struct xhci_hcd *xhci = hcd_to_xhci(hcd);
>> -
>> - spin_lock_irq(&xhci->lock);
>> - xhci_halt(xhci);
>> - spin_unlock_irq(&xhci->lock);
>> -}
>> -
>> /*
>> * Stop xHCI driver.
>> *
>> @@ -678,15 +669,14 @@ void xhci_stop(struct usb_hcd *hcd)
>> u32 temp;
>> struct xhci_hcd *xhci = hcd_to_xhci(hcd);
>>
>> - mutex_lock(&xhci->mutex);
>> -
>> - if (!usb_hcd_is_primary_hcd(hcd)) {
>> - xhci_only_stop_hcd(xhci->shared_hcd);
>> - mutex_unlock(&xhci->mutex);
>> + if (xhci->xhc_state & XHCI_STATE_HALTED)
>> return;
>> - }
>>
>> + mutex_lock(&xhci->mutex);
>> spin_lock_irq(&xhci->lock);
>> + xhci->xhc_state |= XHCI_STATE_HALTED;
>> + xhci->cmd_ring_state = CMD_RING_STATE_STOPPED;
>> +
>
> The XHCI_STATE_HALTED and CMD_RING_STATE_STOPPED states will be set in xhci_halt() right
> after this.
> Well, or, it actually sets them after waiting for the controller to really halt.
>
> I guess setting them here helps the second call to hcd_stop() to return early, not taking the mutex and
> trying to stop controller once again.
Yes, that was my intention :)
cheers,
-roger
Hi Mathias,
On 18/08/15 13:39, Roger Quadros wrote:
> Hi,
>
> Plugging and unplugging a USB-OTG adapter with a USB device into a
> am437x-gp-evm dual-role port (USB1) causes XHCI to malfunction
> and USB device to be no longer detected after a few iterations.
>
> The triggering case is so
> 1) USB1 in peripheal mode
> 2) plug OTG adapter with USB device
> 3) USB1 switches to host mode
> 4) Detects new USB device
> 5) unplug OTG adapter
> 6) OTG core tries to remove host controller while new device
> is being processed.
>
> At 6 some races are observed in the XHCI driver causing it to
> malfunction. See kernel log at the end of this mail.
>
> This series tries to address some of the issues.
> Althouth it is not 100% fool proof yet and XHCI can still get
> stuck up for a few seconds occasionally, it did recover always
> in a max of 10 seconds and the USB device was enumerated after
> that.
>
> During a dual-role switch, usb_remove_hcd() and usb_add_hcd()
> will be called consecutively for both Shared and Primary
> HCDs. This can happen asynchronously and we have to be prepared
> for it.
>
Even after this series I do occasionally see a delay of 5 seconds
during adapter detach. (please see kernel log below).
Is it possible to further optimize so that when xhci_stop is called
we don't depend entirely on timeout timers to stop queued commands?
[ 106.301771] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[ 106.307480] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 3
[ 106.320818] xhci-hcd xhci-hcd.0.auto: hcc params 0x0238f06d hci version 0x100 quirks 0x00010010
[ 106.329809] xhci-hcd xhci-hcd.0.auto: irq 253, io mem 0x48390000
[ 106.337587] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002
[ 106.344455] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 106.352769] usb usb3: Product: xHCI Host Controller
[ 106.357813] usb usb3: Manufacturer: Linux 4.1.6-01054-g496f557-dirty xhci-hcd
[ 106.365012] usb usb3: SerialNumber: xhci-hcd.0.auto
[ 106.381914] hub 3-0:1.0: USB hub found
[ 106.390765] hub 3-0:1.0: 1 port detected
[ 106.400732] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[ 106.407492] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 4
[ 106.421396] usb usb4: We don't know the algorithms for LPM for this host, disabling LPM.
[ 106.436701] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003
[ 106.443577] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 106.454456] usb usb4: Product: xHCI Host Controller
[ 106.460990] usb usb4: Manufacturer: Linux 4.1.6-01054-g496f557-dirty xhci-hcd
[ 106.473275] usb usb4: SerialNumber: xhci-hcd.0.auto
[ 106.502263] hub 4-0:1.0: USB hub found
[ 106.511431] hub 4-0:1.0: 1 port detected
[ 106.715490] usb 3-1: new high-speed USB device number 2 using xhci-hcd
[ 106.822091] xhci-hcd xhci-hcd.0.auto: remove, state 4
[ 106.827261] usb usb4: USB disconnect, device number 1
[ 111.845544] xhci-hcd xhci-hcd.0.auto: Command completion event does not match command
[ 111.853518] xhci-hcd xhci-hcd.0.auto: Timeout while waiting for setup device command
[ 111.888145] xhci-hcd xhci-hcd.0.auto: Host not halted after 16000 microseconds.
[ 111.895528] xhci-hcd xhci-hcd.0.auto: Host controller not halted, aborting reset.
[ 111.905732] xhci-hcd xhci-hcd.0.auto: USB bus 4 deregistered
[ 111.912598] xhci-hcd xhci-hcd.0.auto: remove, state 1
[ 111.918695] usb usb3: USB disconnect, device number 1
[ 112.125544] usb 3-1: device descriptor read/all, error -22
[ 112.131106] usb usb3-port1: couldn't allocate usb_device
[ 112.140019] xhci-hcd xhci-hcd.0.auto: USB bus 3 deregistered
cheers,
-roger
On 20.08.2015 10:09, Roger Quadros wrote:
> Hi Mathias,
Hi
>
> On 18/08/15 13:39, Roger Quadros wrote:
>> Hi,
>>
>> Plugging and unplugging a USB-OTG adapter with a USB device into a
>> am437x-gp-evm dual-role port (USB1) causes XHCI to malfunction
>> and USB device to be no longer detected after a few iterations.
>>
>> The triggering case is so
>> 1) USB1 in peripheal mode
>> 2) plug OTG adapter with USB device
>> 3) USB1 switches to host mode
>> 4) Detects new USB device
>> 5) unplug OTG adapter
>> 6) OTG core tries to remove host controller while new device
>> is being processed.
>>
>> At 6 some races are observed in the XHCI driver causing it to
>> malfunction. See kernel log at the end of this mail.
>>
>> This series tries to address some of the issues.
>> Althouth it is not 100% fool proof yet and XHCI can still get
>> stuck up for a few seconds occasionally, it did recover always
>> in a max of 10 seconds and the USB device was enumerated after
>> that.
>>
>> During a dual-role switch, usb_remove_hcd() and usb_add_hcd()
>> will be called consecutively for both Shared and Primary
>> HCDs. This can happen asynchronously and we have to be prepared
>> for it.
>>
>
> Even after this series I do occasionally see a delay of 5 seconds
> during adapter detach. (please see kernel log below).
>
> Is it possible to further optimize so that when xhci_stop is called
> we don't depend entirely on timeout timers to stop queued commands?
Yes, sounds reasonable. Command timer and ring could probably be stopped,
remaining commands aborted and returned.
-Mathias