Hi Felipe and Mathias, On 5/19/2016 1:22 PM, Mathias Nyman wrote: > On 19.05.2016 14:23, Joao Pinto wrote: >> Hi Felipe, >> >> On 5/19/2016 11:32 AM, Felipe Balbi wrote: >>> >>> Hi, >>> >>> >>> Note that we really did get a command timeout. Can you add a little >>> extra debugging to try and figure out why that command failed? >>> >> >> After instrumenting and capturing FPGA signals, the driver could go a bit >> further... Could this be a FPGA timming issue? >> > .. > >> xhci-hcd xhci-hcd.0.auto: Timeout while waiting for setup device command >> usb 3-1: hub failed to enable device, error -62 >> xhci-hcd xhci-hcd.0.auto: Endpoint 0x0 ep reset callback called >> xhci-hcd xhci-hcd.0.auto: xHCI dying or halted, can't queue_command >> xhci-hcd xhci-hcd.0.auto: FIXME: allocate a command ring segment >> usb usb3-port1: couldn't allocate usb_device >> >> Joao > > Does the patch from Chris Bainbridge help? > It's currently only Gregs tree in the usb-next branch. > > It fixes a locking issue where hw can't handle several ports being in default > state at > the same time, and setup device command timeout issue when both usb2 and usb3 > devices > try to enumerate at the same time. > > commit feb26ac31a2a5cb88d86680d9a94916a6343e9e6 > usb: core: hub: hub_port_init lock controller instead of bus Applied Chris' patch and apparently solved the cyclic crash problem that happened every time the wait completion timeout and context had to change. But the log after insert pen drive remains the same: xhci-hcd xhci-hcd.0.auto: Port Status Change Event for port 1 xhci-hcd xhci-hcd.0.auto: resume root hub xhci-hcd xhci-hcd.0.auto: handle_port_status: starting port polling. xhci-hcd xhci-hcd.0.auto: get port status, actual port 0 status = 0x206e1 xhci-hcd xhci-hcd.0.auto: Get port status returned 0x10101 xhci-hcd xhci-hcd.0.auto: clear port connect change, actual port 0 status = 0x6e1 xhci-hcd xhci-hcd.0.auto: get port status, actual port 0 status = 0x6e1 xhci-hcd xhci-hcd.0.auto: Get port status returned 0x101 xhci-hcd xhci-hcd.0.auto: xhci_hub_status_data: stopping port polling. xhci-hcd xhci-hcd.0.auto: // Ding dong! xhci-hcd xhci-hcd.0.auto: Command timeout xhci-hcd xhci-hcd.0.auto: Abort command ring It worked a bit a few hours ago like I tiold you in a past e-mail: After instrumenting and capturing FPGA signals, the driver could go a bit further... Could this be a FPGA timming issue? xhci-hcd xhci-hcd.0.auto: Port Status Change Event for port 1 xhci-hcd xhci-hcd.0.auto: resume root hub xhci-hcd xhci-hcd.0.auto: handle_port_status: starting port polling. xhci-hcd xhci-hcd.0.auto: get port status, actual port 0 status = 0x206e1 xhci-hcd xhci-hcd.0.auto: Get port status returned 0x10101 xhci-hcd xhci-hcd.0.auto: clear port connect change, actual port 0 status = 0x6e1 xhci-hcd xhci-hcd.0.auto: xhci_hub_status_data: stopping port polling. xhci-hcd xhci-hcd.0.auto: get port status, actual port 0 status = 0x6e1 xhci-hcd xhci-hcd.0.auto: Get port status returned 0x101 xhci-hcd xhci-hcd.0.auto: xhci_hub_status_data: stopping port polling. xhci-hcd xhci-hcd.0.auto: // Ding dong! xhci-hcd xhci-hcd.0.auto: Slot 1 output ctx = 0x9f5d64000 (dma) xhci-hcd xhci-hcd.0.auto: Slot 1 input ctx = 0x9f5d68000 (dma) xhci-hcd xhci-hcd.0.auto: Set slot id 1 dcbaa entry ffffff800807c008 to 0x9f5d64000 xhci-hcd xhci-hcd.0.auto: set port reset, actual port 0 status = 0x6f1 xhci-hcd xhci-hcd.0.auto: get port status, actual port 0 status = 0x200e03 xhci-hcd xhci-hcd.0.auto: Get port status returned 0x100503 xhci-hcd xhci-hcd.0.auto: clear port reset change, actual port 0 status = 0xe03 usb 3-1: new high-speed USB device number 2 using xhci-hcd xhci-hcd xhci-hcd.0.auto: Set root hub portnum to 1 xhci-hcd xhci-hcd.0.auto: Set fake root hub portnum to 1 xhci-hcd xhci-hcd.0.auto: udev->tt = (null) xhci-hcd xhci-hcd.0.auto: udev->ttport = 0x0 xhci-hcd xhci-hcd.0.auto: Slot ID 1 Input Context: xhci-hcd xhci-hcd.0.auto: @ffffff8008acd000 (virt) @9f5d68000 (dma) 0x000000 - drop flags xhci-hcd xhci-hcd.0.auto: @ffffff8008acd004 (virt) @9f5d68004 (dma) 0x000003 - add flags xhci-hcd xhci-hcd.0.auto: @ffffff8008acd008 (virt) @9f5d68008 (dma) 0x000000 - rsvd2[0] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd00c (virt) @9f5d6800c (dma) 0x000000 - rsvd2[1] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd010 (virt) @9f5d68010 (dma) 0x000000 - rsvd2[2] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd014 (virt) @9f5d68014 (dma) 0x000000 - rsvd2[3] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd018 (virt) @9f5d68018 (dma) 0x000000 - rsvd2[4] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd01c (virt) @9f5d6801c (dma) 0x000000 - rsvd2[5] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd020 (virt) @9f5d68020 (dma) 0x000000 - rsvd64[0] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd028 (virt) @9f5d68028 (dma) 0x000000 - rsvd64[1] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd030 (virt) @9f5d68030 (dma) 0x000000 - rsvd64[2] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd038 (virt) @9f5d68038 (dma) 0x000000 - rsvd64[3] xhci-hcd xhci-hcd.0.auto: Slot Context: xhci-hcd xhci-hcd.0.auto: @ffffff8008acd040 (virt) @9f5d68040 (dma) 0x8300000 - dev_info xhci-hcd xhci-hcd.0.auto: @ffffff8008acd044 (virt) @9f5d68044 (dma) 0x010000 - dev_info2 xhci-hcd xhci-hcd.0.auto: @ffffff8008acd048 (virt) @9f5d68048 (dma) 0x000000 - tt_info xhci-hcd xhci-hcd.0.auto: @ffffff8008acd04c (virt) @9f5d6804c (dma) 0x000000 - dev_state xhci-hcd xhci-hcd.0.auto: @ffffff8008acd050 (virt) @9f5d68050 (dma) 0x000000 - rsvd[0] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd054 (virt) @9f5d68054 (dma) 0x000000 - rsvd[1] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd058 (virt) @9f5d68058 (dma) 0x000000 - rsvd[2] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd05c (virt) @9f5d6805c (dma) 0x000000 - rsvd[3] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd060 (virt) @9f5d68060 (dma) 0x000000 - rsvd64[0] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd068 (virt) @9f5d68068 (dma) 0x000000 - rsvd64[1] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd070 (virt) @9f5d68070 (dma) 0x000000 - rsvd64[2] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd078 (virt) @9f5d68078 (dma) 0x000000 - rsvd64[3] xhci-hcd xhci-hcd.0.auto: IN Endpoint 00 Context (ep_index 00): xhci-hcd xhci-hcd.0.auto: @ffffff8008acd080 (virt) @9f5d68080 (dma) 0x000000 - ep_info xhci-hcd xhci-hcd.0.auto: @ffffff8008acd084 (virt) @9f5d68084 (dma) 0x400026 - ep_info2 xhci-hcd xhci-hcd.0.auto: @ffffff8008acd088 (virt) @9f5d68088 (dma) 0x9f5d66001 - deq xhci-hcd xhci-hcd.0.auto: @ffffff8008acd090 (virt) @9f5d68090 (dma) 0x000000 - tx_info xhci-hcd xhci-hcd.0.auto: @ffffff8008acd094 (virt) @9f5d68094 (dma) 0x000000 - rsvd[0] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd098 (virt) @9f5d68098 (dma) 0x000000 - rsvd[1] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd09c (virt) @9f5d6809c (dma) 0x000000 - rsvd[2] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0a0 (virt) @9f5d680a0 (dma) 0x000000 - rsvd64[0] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0a8 (virt) @9f5d680a8 (dma) 0x000000 - rsvd64[1] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0b0 (virt) @9f5d680b0 (dma) 0x000000 - rsvd64[2] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0b8 (virt) @9f5d680b8 (dma) 0x000000 - rsvd64[3] xhci-hcd xhci-hcd.0.auto: OUT Endpoint 01 Context (ep_index 01): xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0c0 (virt) @9f5d680c0 (dma) 0x000000 - ep_info xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0c4 (virt) @9f5d680c4 (dma) 0x000000 - ep_info2 xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0c8 (virt) @9f5d680c8 (dma) 0x000000 - deq xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0d0 (virt) @9f5d680d0 (dma) 0x000000 - tx_info xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0d4 (virt) @9f5d680d4 (dma) 0x000000 - rsvd[0] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0d8 (virt) @9f5d680d8 (dma) 0x000000 - rsvd[1] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0dc (virt) @9f5d680dc (dma) 0x000000 - rsvd[2] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0e0 (virt) @9f5d680e0 (dma) 0x000000 - rsvd64[0] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0e8 (virt) @9f5d680e8 (dma) 0x000000 - rsvd64[1] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0f0 (virt) @9f5d680f0 (dma) 0x000000 - rsvd64[2] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd0f8 (virt) @9f5d680f8 (dma) 0x000000 - rsvd64[3] xhci-hcd xhci-hcd.0.auto: IN Endpoint 01 Context (ep_index 02): xhci-hcd xhci-hcd.0.auto: @ffffff8008acd100 (virt) @9f5d68100 (dma) 0x000000 - ep_info xhci-hcd xhci-hcd.0.auto: @ffffff8008acd104 (virt) @9f5d68104 (dma) 0x000000 - ep_info2 xhci-hcd xhci-hcd.0.auto: @ffffff8008acd108 (virt) @9f5d68108 (dma) 0x000000 - deq xhci-hcd xhci-hcd.0.auto: @ffffff8008acd110 (virt) @9f5d68110 (dma) 0x000000 - tx_info xhci-hcd xhci-hcd.0.auto: @ffffff8008acd114 (virt) @9f5d68114 (dma) 0x000000 - rsvd[0] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd118 (virt) @9f5d68118 (dma) 0x000000 - rsvd[1] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd11c (virt) @9f5d6811c (dma) 0x000000 - rsvd[2] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd120 (virt) @9f5d68120 (dma) 0x000000 - rsvd64[0] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd128 (virt) @9f5d68128 (dma) 0x000000 - rsvd64[1] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd130 (virt) @9f5d68130 (dma) 0x000000 - rsvd64[2] xhci-hcd xhci-hcd.0.auto: @ffffff8008acd138 (virt) @9f5d68138 (dma) 0x000000 - rsvd64[3] xhci-hcd xhci-hcd.0.auto: // Ding dong! xhci-hcd xhci-hcd.0.auto: Command timeout xhci-hcd xhci-hcd.0.auto: Abort command ring xhci-hcd xhci-hcd.0.auto: Stopped the command ring failed, maybe the host is dead xhci-hcd xhci-hcd.0.auto: // Halt the HC xhci-hcd xhci-hcd.0.auto: Host not halted after 16000 microseconds. xhci-hcd xhci-hcd.0.auto: Abort command ring failed xhci-hcd xhci-hcd.0.auto: HC died; cleaning up xhci-hcd xhci-hcd.0.auto: xHCI host controller is dead. xhci-hcd xhci-hcd.0.auto: Timeout while waiting for setup device command usb 3-1: hub failed to enable device, error -62 xhci-hcd xhci-hcd.0.auto: Endpoint 0x0 ep reset callback called xhci-hcd xhci-hcd.0.auto: xHCI dying or halted, can't queue_command xhci-hcd xhci-hcd.0.auto: FIXME: allocate a command ring segment usb usb3-port1: couldn't allocate usb_device Any thoughts? > > -Mathias > Thanks! -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
