On Thu, Oct 24, 2013 at 02:24:14PM -0700, Praveen Murali wrote:
Hi,
I have a USB3.0 hard drive enclosure which works perfectly on my
desktop (w/ a TI TUSB73x0 SuperSpeed USB 3.0 xHCI Host Controller)
running Debian 3.10-3-amd64 kernel. But when I plug it on my other
setup (with a VIA VL80x xHCI USB 3.0 Controller) running Ubuntu
12.04 3.2.48-amd64 kernel, a simple read using dd on the device
errors out (at random points) and crashes the kernel. I did some
tests with USB debugs and xHCI driver debugs on and also did some
packet captures using usbmon & tcpdump. What I see in these tests is
that the device stops responding, I am not able to tell if its the
hub or the device, mainly because this device works perfectly on my
desktop. I have attached the two log files here; kern.log.1 is with
USB debugs on and kerne.log.2 is with both USB and xHCI debugs on.
Can you please help me identify if this is a protocol or hardware
problem?
It's probably a problem with the 3.2-based kernel. Can you update the
kernel for the Ubuntu machine to the latest 3.10 stable kernel and
retest?
If you need directions for building a kernel, you can follow these (and
follow the "Downloading the latest stable tree" section):
http://kernelnewbies.org/KernelBuild
Oct 24 12:17:33 falcon-p01 kernel: [ 206.384034] xhci_hcd 0000:0e:00.0: Timeout while waiting for a slot
Oct 24 12:17:33 falcon-p01 kernel: [ 206.384048] hub 2-0:1.0: couldn't allocate port 4 usb_device
Oct 24 12:17:33 falcon-p01 kernel: [ 206.384100] hub 2-0:1.0: state 7 ports 4 chg 0000 evt 0010
Oct 24 12:17:33 falcon-p01 kernel: [ 206.384118] hub 2-0:1.0: port 4, status 02a0, change 0001, 5.0 Gb/s
Oct 24 12:17:33 falcon-p01 kernel: [ 206.512033] hub 2-0:1.0: debounce: port 4: total 100ms stable 100ms status 0x2e0
Oct 24 12:17:34 falcon-p01 kernel: [ 207.020051] hub 2-0:1.0: state 7 ports 4 chg 0000 evt 0010
Oct 24 12:17:34 falcon-p01 kernel: [ 207.020076] hub 2-0:1.0: port 4, status 0203, change 0001, 5.0 Gb/s
Oct 24 12:17:34 falcon-p01 kernel: [ 207.148056] hub 2-0:1.0: debounce: port 4: total 100ms stable 100ms status 0x203
Oct 24 12:17:34 falcon-p01 kernel: [ 207.824026] xhci_hcd 0000:0e:00.0: xHCI host not responding to stop endpoint command.
Oct 24 12:17:34 falcon-p01 kernel: [ 207.824036] xhci_hcd 0000:0e:00.0: Assuming host is dying, halting host.
Oct 24 12:17:34 falcon-p01 kernel: [ 207.824065] xhci_hcd 0000:0e:00.0: HC died; cleaning up
Oct 24 12:17:39 falcon-p01 kernel: [ 212.148026] xhci_hcd 0000:0e:00.0: Timeout while waiting for a slot
Oct 24 12:17:39 falcon-p01 kernel: [ 212.148037] xhci_hcd 0000:0e:00.0: Abort the command ring, but the xHCI is dead.
Oct 24 12:17:39 falcon-p01 kernel: [ 212.148060] hub 2-0:1.0: hub_port_status failed (err = -19)
Oct 24 12:17:39 falcon-p01 kernel: [ 212.148072] hub 2-0:1.0: cannot disable port 4 (err = -19)
Oct 24 12:17:39 falcon-p01 kernel: [ 212.148079] hub 2-0:1.0: cannot disable port 4 (err = -19)
Oct 24 12:17:39 falcon-p01 kernel: [ 212.148114] BUG: unable to handle kernel NULL pointer dereference at 0000000000000040
Oct 24 12:17:39 falcon-p01 kernel: [ 212.148239] IP: [<ffffffffa0130b8c>] xhci_free_dev+0x53/0x106 [xhci_hcd]
Oct 24 12:17:39 falcon-p01 kernel: [ 212.148350] PGD 1146c1067 PUD 1146ca067 PMD 0
Oct 24 12:17:39 falcon-p01 kernel: [ 212.148426] Oops: 0002 [#1] SMP
Oct 24 12:17:39 falcon-p01 kernel: [ 212.148481] CPU 1
Oct 24 12:17:39 falcon-p01 kernel: [ 212.148511] Modules linked in: usb_storage firewire_sbp2 firewire_ohci iptable_filter ip_tables x_tables joydev dm_dmirror exfat_fs exfat_core dm_zcache dm_mod padlock_aes aes_generic padlock_sha iscsi_target_mod target_core_mod configfs sswipe usbhid hid picdev uhci_hcd via_cputemp hwmon_vid ib_iser rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi psmouse serio_raw usb3380 shpchp udc_core evdev processor thermal_sys lp parport loop ext4 jbd2 mbcache crc16 sd_mod crc_t10dif ata_generic pata_via mvsas libsas libata firewire_core crc_itu_t ehci_hcd scsi_transport_sas scsi_mod xhci_hcd usbcore via_chrome9 usb_common ttm drm_kms_helper drm button i2c_core vgastate [last unloaded: firewire_ohci]
Oct 24 12:17:39 falcon-p01 kernel: [ 212.149708]
Oct 24 12:17:39 falcon-p01 kernel: [ 212.149734] Pid: 130, comm: khubd Not tainted 3.2.48-logicube-ng.13.d2 #3 VIA technology Inc. VX900/EPIA-M860
Oct 24 12:17:39 falcon-p01 kernel: [ 212.149879] RIP: 0010:[<ffffffffa0130b8c>] [<ffffffffa0130b8c>] xhci_free_dev+0x53/0x106 [xhci_hcd]
Oct 24 12:17:39 falcon-p01 kernel: [ 212.150016] RSP: 0018:ffff880114f57da0 EFLAGS: 00010246
Oct 24 12:17:39 falcon-p01 kernel: [ 212.150089] RAX: 0000000000000000 RBX: ffff8801151aa000 RCX: 0000000000000000
Oct 24 12:17:39 falcon-p01 kernel: [ 212.150185] RDX: 0000000000000003 RSI: ffffffffa0139170 RDI: ffff880114ed8000
Oct 24 12:17:39 falcon-p01 kernel: [ 212.150281] RBP: ffff880115b63800 R08: 0000000000000001 R09: ffffffffa0139170
Oct 24 12:17:39 falcon-p01 kernel: [ 212.150377] R10: ffff880115b63800 R11: 0000000000000003 R12: ffff880114ed8000
Oct 24 12:17:39 falcon-p01 kernel: [ 212.150474] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
Oct 24 12:17:39 falcon-p01 kernel: [ 212.150571] FS: 0000000000000000(0000) GS:ffff88011fc80000(0000) knlGS:0000000000000000
Oct 24 12:17:39 falcon-p01 kernel: [ 212.150680] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Oct 24 12:17:39 falcon-p01 kernel: [ 212.150758] CR2: 0000000000000040 CR3: 00000001146d0000 CR4: 00000000000006e0
Oct 24 12:17:39 falcon-p01 kernel: [ 212.150855] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Oct 24 12:17:39 falcon-p01 kernel: [ 212.150951] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Oct 24 12:17:39 falcon-p01 kernel: [ 212.151048] Process khubd (pid: 130, threadinfo ffff880114f56000, task ffff8801151c5140)
Oct 24 12:17:39 falcon-p01 kernel: [ 212.151155] Stack:
Oct 24 12:17:39 falcon-p01 kernel: [ 212.151185] ffffffffa0130b39 ffff880114f43000 ffff880115b63800 0000000000000004
Oct 24 12:17:39 falcon-p01 kernel: [ 212.151302] 00000000ffffffed ffff880114f43058 ffff880114ee0000 ffffffffa00c0fc8
Oct 24 12:17:39 falcon-p01 kernel: [ 212.151418] ffffffff00000203 ffffffff81038033 ffff8801151a8108 ffff880114ed8028
Oct 24 12:17:39 falcon-p01 kernel: [ 212.151534] Call Trace:
Oct 24 12:17:39 falcon-p01 kernel: [ 212.151582] [<ffffffffa0130b39>] ? xhci_set_usb2_hardware_lpm+0x116/0x116 [xhci_hcd]
Oct 24 12:17:39 falcon-p01 kernel: [ 212.151701] [<ffffffffa00c0fc8>] ? hub_thread+0xd1a/0x10f6 [usbcore]
Oct 24 12:17:39 falcon-p01 kernel: [ 212.151794] [<ffffffff81038033>] ? set_next_entity+0x32/0x55
Oct 24 12:17:39 falcon-p01 kernel: [ 212.151880] [<ffffffff8105fca3>] ? add_wait_queue+0x3c/0x3c
Oct 24 12:17:39 falcon-p01 kernel: [ 212.151970] [<ffffffffa00c02ae>] ? usb_remote_wakeup+0x53/0x53 [usbcore]
Oct 24 12:17:39 falcon-p01 kernel: [ 212.152007] [<ffffffff8105f651>] ? kthread+0x76/0x7e
Oct 24 12:17:39 falcon-p01 kernel: [ 212.152007] [<ffffffff8135c1f4>] ? kernel_thread_helper+0x4/0x10
Oct 24 12:17:39 falcon-p01 kernel: [ 212.152007] [<ffffffff8105f5db>] ? kthread_worker_fn+0x139/0x139
Oct 24 12:17:39 falcon-p01 kernel: [ 212.152007] [<ffffffff8135c1f0>] ? gs_change+0x13/0x13
Oct 24 12:17:39 falcon-p01 kernel: [ 212.152007] Code: 00 e8 00 c5 ff ff 83 f8 ed 74 08 85 c0 0f 8e bf 00 00 00 48 63 85 a0 05 00 00 45 31 ed 4c 8b bc c3 08 01 00 00 4d 89 fe 49 63 c5 <41> 83 66 40 fb 41 ff c5 48 69 c0 e8 00 00 00 49 81 c6 e8 00 00
Oct 24 12:17:39 falcon-p01 kernel: [ 212.152007] RIP [<ffffffffa0130b8c>] xhci_free_dev+0x53/0x106 [xhci_hcd]
Oct 24 12:17:39 falcon-p01 kernel: [ 212.152007] RSP <ffff880114f57da0>
Oct 24 12:17:39 falcon-p01 kernel: [ 212.152007] CR2: 0000000000000040
Oct 24 12:17:39 falcon-p01 kernel: [ 212.186151] ---[ end trace 1ffc8c47914f334e ]---
I have a couple theories about what the root cause of this issue could
be, and those issues were fixed in 3.10.15, with commit
57ad776884c52610af5e00d53e9755f2a8d50bbd "xhci: Ensure a command
structure points to the correct trb on the command ring". Ubuntu may
not have picked up the patch yet for their 3.2 kernel.
But please try the latest 3.10 stable kernel and see if it fixes the
issue on your VIA xHCI host.
More comments on the log below.
Oct 24 12:21:26 falcon-p01 kernel: [ 161.146869] xhci_hcd 0000:0e:00.0:
Oct 24 12:21:26 falcon-p01 kernel: [ 161.146875] xhci_hcd 0000:0e:00.0: ep 0x81 - urb len = 8192, sglist used, num_trbs = 2
Oct 24 12:21:26 falcon-p01 kernel: [ 161.146884] xhci_hcd 0000:0e:00.0: First length to xfer from 1st sglist entry = 4096
Oct 24 12:21:26 falcon-p01 kernel: [ 161.146893] xhci_hcd 0000:0e:00.0: sg entry: dma = 0x5f5f000, len = 0x1000 (4096), 64KB boundary at 0x5f60000, end dma = 0x5f60000
Oct 24 12:21:26 falcon-p01 kernel: [ 161.146904] xhci_hcd 0000:0e:00.0: sg entry: dma = 0x5f60000, len = 0x1000 (4096), 64KB boundary at 0x5f70000, end dma = 0x5f61000
Oct 24 12:21:26 falcon-p01 kernel: [ 161.146967] xhci_hcd 0000:0e:00.0: ep 0x81 - urb len = 0xd (13), addr = 0xbb0b0000, num_trbs = 1
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147218] xhci_hcd 0000:0e:00.0: ep 0x2 - urb len = 0x1f (31), addr = 0xbb0b0000, num_trbs = 1
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147253] xhci_hcd 0000:0e:00.0: count sg list trbs:
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147262] xhci_hcd 0000:0e:00.0: sg #0: dma = 0x5f61000, len = 0x10000 (65536), num_trbs = 2
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147272] xhci_hcd 0000:0e:00.0: sg #1: dma = 0x5f71000, len = 0xe000 (57344), num_trbs = 1
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147279] xhci_hcd 0000:0e:00.0:
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147286] xhci_hcd 0000:0e:00.0: ep 0x81 - urb len = 122880, sglist used, num_trbs = 3
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147294] xhci_hcd 0000:0e:00.0: First length to xfer from 1st sglist entry = 61440
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147303] xhci_hcd 0000:0e:00.0: sg entry: dma = 0x5f61000, len = 0xf000 (61440), 64KB boundary at 0x5f70000, end dma = 0x5f70000
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147315] xhci_hcd 0000:0e:00.0: sg entry: dma = 0x5f70000, len = 0x1000 (4096), 64KB boundary at 0x5f80000, end dma = 0x5f71000
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147326] xhci_hcd 0000:0e:00.0: sg entry: dma = 0x5f71000, len = 0xe000 (57344), 64KB boundary at 0x5f80000, end dma = 0x5f7f000
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147768] xhci_hcd 0000:0e:00.0: ep 0x81 - urb len = 0xd (13), addr = 0xbb0b0000, num_trbs = 1
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147778] xhci_hcd 0000:0e:00.0: queue_trb: Toggle cycle state for ring ffff880114d87dc0 = 0
Oct 24 12:21:26 falcon-p01 kernel: [ 161.147975] xhci_hcd 0000:0e:00.0: ep 0x2 - urb len = 0x1f (31), addr = 0xbb0b0000, num_trbs = 1
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148033] xhci_hcd 0000:0e:00.0: count sg list trbs:
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148041] xhci_hcd 0000:0e:00.0: sg #0: dma = 0x5f7f000, len = 0x2000 (8192), num_trbs = 2
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148049] xhci_hcd 0000:0e:00.0:
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148055] xhci_hcd 0000:0e:00.0: ep 0x81 - urb len = 8192, sglist used, num_trbs = 2
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148063] xhci_hcd 0000:0e:00.0: First length to xfer from 1st sglist entry = 4096
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148072] xhci_hcd 0000:0e:00.0: sg entry: dma = 0x5f7f000, len = 0x1000 (4096), 64KB boundary at 0x5f80000, end dma = 0x5f80000
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148083] xhci_hcd 0000:0e:00.0: sg entry: dma = 0x5f80000, len = 0x1000 (4096), 64KB boundary at 0x5f90000, end dma = 0x5f81000
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148138] xhci_hcd 0000:0e:00.0: ep 0x81 - urb len = 0xd (13), addr = 0xbb0b0000, num_trbs = 1
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148400] xhci_hcd 0000:0e:00.0: ep 0x2 - urb len = 0x1f (31), addr = 0xbb0b0000, num_trbs = 1
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148410] xhci_hcd 0000:0e:00.0: queue_trb: Toggle cycle state for ring ffff880115fc3140 = 1
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148454] xhci_hcd 0000:0e:00.0: count sg list trbs:
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148462] xhci_hcd 0000:0e:00.0: sg #0: dma = 0x5f81000, len = 0x10000 (65536), num_trbs = 2
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148472] xhci_hcd 0000:0e:00.0: sg #1: dma = 0x5f91000, len = 0xe000 (57344), num_trbs = 1
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148479] xhci_hcd 0000:0e:00.0:
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148486] xhci_hcd 0000:0e:00.0: ep 0x81 - urb len = 122880, sglist used, num_trbs = 3
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148494] xhci_hcd 0000:0e:00.0: First length to xfer from 1st sglist entry = 61440
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148503] xhci_hcd 0000:0e:00.0: sg entry: dma = 0x5f81000, len = 0xf000 (61440), 64KB boundary at 0x5f90000, end dma = 0x5f90000
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148515] xhci_hcd 0000:0e:00.0: sg entry: dma = 0x5f90000, len = 0x1000 (4096), 64KB boundary at 0x5fa0000, end dma = 0x5f91000
Oct 24 12:21:26 falcon-p01 kernel: [ 161.148526] xhci_hcd 0000:0e:00.0: sg entry: dma = 0x5f91000, len = 0xe000 (57344), 64KB boundary at 0x5fa0000, end dma = 0x5f9f000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840043] xhci_hcd 0000:0e:00.0: Cancel URB ffff8800b2b75600
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840053] xhci_hcd 0000:0e:00.0: Event ring:
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840063] xhci_hcd 0000:0e:00.0: @00000000bb0e1400 c4b2db00 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840073] xhci_hcd 0000:0e:00.0: @00000000bb0e1410 c4b2d500 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840082] xhci_hcd 0000:0e:00.0: @00000000bb0e1420 c4b2d510 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840092] xhci_hcd 0000:0e:00.0: @00000000bb0e1430 c4b2db10 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840101] xhci_hcd 0000:0e:00.0: @00000000bb0e1440 c4b2d540 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840110] xhci_hcd 0000:0e:00.0: @00000000bb0e1450 c4b2d550 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840119] xhci_hcd 0000:0e:00.0: @00000000bb0e1460 c4b2db20 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840128] xhci_hcd 0000:0e:00.0: @00000000bb0e1470 c4b2d570 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840137] xhci_hcd 0000:0e:00.0: @00000000bb0e1480 c4b2d580 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840146] xhci_hcd 0000:0e:00.0: @00000000bb0e1490 c4b2db30 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840155] xhci_hcd 0000:0e:00.0: @00000000bb0e14a0 c4b2d5b0 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840164] xhci_hcd 0000:0e:00.0: @00000000bb0e14b0 c4b2d5c0 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840173] xhci_hcd 0000:0e:00.0: @00000000bb0e14c0 c4b2db40 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840182] xhci_hcd 0000:0e:00.0: @00000000bb0e14d0 c4b2d5e0 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840191] xhci_hcd 0000:0e:00.0: @00000000bb0e14e0 c4b2d5f0 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840200] xhci_hcd 0000:0e:00.0: @00000000bb0e14f0 c4b2db50 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840209] xhci_hcd 0000:0e:00.0: @00000000bb0e1500 c4b2d620 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840218] xhci_hcd 0000:0e:00.0: @00000000bb0e1510 c4b2d630 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840227] xhci_hcd 0000:0e:00.0: @00000000bb0e1520 c4b2db60 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840236] xhci_hcd 0000:0e:00.0: @00000000bb0e1530 c4b2d650 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840245] xhci_hcd 0000:0e:00.0: @00000000bb0e1540 c4b2d660 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840254] xhci_hcd 0000:0e:00.0: @00000000bb0e1550 c4b2db70 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840263] xhci_hcd 0000:0e:00.0: @00000000bb0e1560 c4b2d690 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840272] xhci_hcd 0000:0e:00.0: @00000000bb0e1570 c4b2d6a0 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840281] xhci_hcd 0000:0e:00.0: @00000000bb0e1580 c4b2db80 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840290] xhci_hcd 0000:0e:00.0: @00000000bb0e1590 c4b2d6c0 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840299] xhci_hcd 0000:0e:00.0: @00000000bb0e15a0 c4b2d6d0 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840308] xhci_hcd 0000:0e:00.0: @00000000bb0e15b0 c4b2db90 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840317] xhci_hcd 0000:0e:00.0: @00000000bb0e15c0 c4b2d700 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840326] xhci_hcd 0000:0e:00.0: @00000000bb0e15d0 c4b2d710 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840335] xhci_hcd 0000:0e:00.0: @00000000bb0e15e0 c4b2dba0 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840344] xhci_hcd 0000:0e:00.0: @00000000bb0e15f0 c4b2d730 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840353] xhci_hcd 0000:0e:00.0: @00000000bb0e1600 c4b2d740 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840363] xhci_hcd 0000:0e:00.0: @00000000bb0e1610 c4b2dbb0 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840372] xhci_hcd 0000:0e:00.0: @00000000bb0e1620 c4b2d770 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840381] xhci_hcd 0000:0e:00.0: @00000000bb0e1630 c4b2d780 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840390] xhci_hcd 0000:0e:00.0: @00000000bb0e1640 c4b2dbc0 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840399] xhci_hcd 0000:0e:00.0: @00000000bb0e1650 c4b2d7a0 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840408] xhci_hcd 0000:0e:00.0: @00000000bb0e1660 c4b2d7b0 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840417] xhci_hcd 0000:0e:00.0: @00000000bb0e1670 c4b2dbd0 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840426] xhci_hcd 0000:0e:00.0: @00000000bb0e1680 c4b2d7e0 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840435] xhci_hcd 0000:0e:00.0: @00000000bb0e1690 c4b2d400 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840444] xhci_hcd 0000:0e:00.0: @00000000bb0e16a0 c4b2dbe0 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840453] xhci_hcd 0000:0e:00.0: @00000000bb0e16b0 c4b2d420 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840462] xhci_hcd 0000:0e:00.0: @00000000bb0e16c0 c4b2d430 00000000 01000000 02038000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840471] xhci_hcd 0000:0e:00.0: @00000000bb0e16d0 c4b2d800 00000000 01000000 02048000
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840480] xhci_hcd 0000:0e:00.0: @00000000bb0e16e0 c4b2daa0 00000000 01000000 02048001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840489] xhci_hcd 0000:0e:00.0: @00000000bb0e16f0 c4b2d7a0 00000000 01000000 02038001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840498] xhci_hcd 0000:0e:00.0: @00000000bb0e1700 c4b2d7b0 00000000 01000000 02038001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840507] xhci_hcd 0000:0e:00.0: @00000000bb0e1710 c4b2dab0 00000000 01000000 02048001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840516] xhci_hcd 0000:0e:00.0: @00000000bb0e1720 c4b2d7e0 00000000 01000000 02038001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840525] xhci_hcd 0000:0e:00.0: @00000000bb0e1730 c4b2d400 00000000 01000000 02038001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840534] xhci_hcd 0000:0e:00.0: @00000000bb0e1740 c4b2dac0 00000000 01000000 02048001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840543] xhci_hcd 0000:0e:00.0: @00000000bb0e1750 c4b2d420 00000000 01000000 02038001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840552] xhci_hcd 0000:0e:00.0: @00000000bb0e1760 c4b2d430 00000000 01000000 02038001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840561] xhci_hcd 0000:0e:00.0: @00000000bb0e1770 c4b2dad0 00000000 01000000 02048001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840570] xhci_hcd 0000:0e:00.0: @00000000bb0e1780 c4b2d460 00000000 01000000 02038001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840579] xhci_hcd 0000:0e:00.0: @00000000bb0e1790 c4b2d470 00000000 01000000 02038001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840588] xhci_hcd 0000:0e:00.0: @00000000bb0e17a0 c4b2dae0 00000000 01000000 02048001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840597] xhci_hcd 0000:0e:00.0: @00000000bb0e17b0 c4b2d490 00000000 01000000 02038001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840606] xhci_hcd 0000:0e:00.0: @00000000bb0e17c0 c4b2d4a0 00000000 01000000 02038001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840615] xhci_hcd 0000:0e:00.0: @00000000bb0e17d0 c4b2daf0 00000000 01000000 02048001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840625] xhci_hcd 0000:0e:00.0: @00000000bb0e17e0 c4b2d4d0 00000000 01000000 02038001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840634] xhci_hcd 0000:0e:00.0: @00000000bb0e17f0 c4b2d4e0 00000000 01000000 02038001
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840642] xhci_hcd 0000:0e:00.0: Endpoint ring:
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840650] xhci_hcd 0000:0e:00.0: @00000000c4b2d400 bb0b0000 00000000 0000000d 00000424
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840660] xhci_hcd 0000:0e:00.0: @00000000c4b2d410 05f7f000 00000000 00101000 00000414
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840669] xhci_hcd 0000:0e:00.0: @00000000c4b2d420 05f80000 00000000 00081000 00000424
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840678] xhci_hcd 0000:0e:00.0: @00000000c4b2d430 bb0b0000 00000000 0000000d 00000424
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840687] xhci_hcd 0000:0e:00.0: @00000000c4b2d440 05f81000 00000000 003ef000 00000414
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840696] xhci_hcd 0000:0e:00.0: @00000000c4b2d450 05f90000 00000000 003e1000 00000414
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840705] xhci_hcd 0000:0e:00.0: @00000000c4b2d460 05f91000 00000000 003ee000 00000424
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840714] xhci_hcd 0000:0e:00.0: @00000000c4b2d470 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840723] xhci_hcd 0000:0e:00.0: @00000000c4b2d480 05e7f000 00000000 00101000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840732] xhci_hcd 0000:0e:00.0: @00000000c4b2d490 05e80000 00000000 00081000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840741] xhci_hcd 0000:0e:00.0: @00000000c4b2d4a0 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840750] xhci_hcd 0000:0e:00.0: @00000000c4b2d4b0 05e81000 00000000 003ef000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840759] xhci_hcd 0000:0e:00.0: @00000000c4b2d4c0 05e90000 00000000 003e1000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840768] xhci_hcd 0000:0e:00.0: @00000000c4b2d4d0 05e91000 00000000 003ee000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840777] xhci_hcd 0000:0e:00.0: @00000000c4b2d4e0 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840786] xhci_hcd 0000:0e:00.0: @00000000c4b2d4f0 05e9f000 00000000 00101000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840795] xhci_hcd 0000:0e:00.0: @00000000c4b2d500 05ea0000 00000000 00081000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840804] xhci_hcd 0000:0e:00.0: @00000000c4b2d510 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840813] xhci_hcd 0000:0e:00.0: @00000000c4b2d520 05ea1000 00000000 003ef000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840822] xhci_hcd 0000:0e:00.0: @00000000c4b2d530 05eb0000 00000000 003e1000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840832] xhci_hcd 0000:0e:00.0: @00000000c4b2d540 05eb1000 00000000 003ee000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840841] xhci_hcd 0000:0e:00.0: @00000000c4b2d550 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840850] xhci_hcd 0000:0e:00.0: @00000000c4b2d560 05ebf000 00000000 00101000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840859] xhci_hcd 0000:0e:00.0: @00000000c4b2d570 05ec0000 00000000 00081000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840868] xhci_hcd 0000:0e:00.0: @00000000c4b2d580 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840877] xhci_hcd 0000:0e:00.0: @00000000c4b2d590 05ec1000 00000000 003ef000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840886] xhci_hcd 0000:0e:00.0: @00000000c4b2d5a0 05ed0000 00000000 003e1000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840895] xhci_hcd 0000:0e:00.0: @00000000c4b2d5b0 05ed1000 00000000 003ee000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840904] xhci_hcd 0000:0e:00.0: @00000000c4b2d5c0 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840913] xhci_hcd 0000:0e:00.0: @00000000c4b2d5d0 05edf000 00000000 00101000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840922] xhci_hcd 0000:0e:00.0: @00000000c4b2d5e0 05ee0000 00000000 00081000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840931] xhci_hcd 0000:0e:00.0: @00000000c4b2d5f0 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840940] xhci_hcd 0000:0e:00.0: @00000000c4b2d600 05ee1000 00000000 003ef000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840949] xhci_hcd 0000:0e:00.0: @00000000c4b2d610 05ef0000 00000000 003e1000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840958] xhci_hcd 0000:0e:00.0: @00000000c4b2d620 05ef1000 00000000 003ee000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840967] xhci_hcd 0000:0e:00.0: @00000000c4b2d630 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840976] xhci_hcd 0000:0e:00.0: @00000000c4b2d640 05eff000 00000000 00101000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840985] xhci_hcd 0000:0e:00.0: @00000000c4b2d650 05f00000 00000000 00081000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.840994] xhci_hcd 0000:0e:00.0: @00000000c4b2d660 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841003] xhci_hcd 0000:0e:00.0: @00000000c4b2d670 05f01000 00000000 003ef000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841012] xhci_hcd 0000:0e:00.0: @00000000c4b2d680 05f10000 00000000 003e1000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841021] xhci_hcd 0000:0e:00.0: @00000000c4b2d690 05f11000 00000000 003ee000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841030] xhci_hcd 0000:0e:00.0: @00000000c4b2d6a0 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841039] xhci_hcd 0000:0e:00.0: @00000000c4b2d6b0 05f1f000 00000000 00101000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841048] xhci_hcd 0000:0e:00.0: @00000000c4b2d6c0 05f20000 00000000 00081000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841057] xhci_hcd 0000:0e:00.0: @00000000c4b2d6d0 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841066] xhci_hcd 0000:0e:00.0: @00000000c4b2d6e0 05f21000 00000000 003ef000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841075] xhci_hcd 0000:0e:00.0: @00000000c4b2d6f0 05f30000 00000000 003e1000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841084] xhci_hcd 0000:0e:00.0: @00000000c4b2d700 05f31000 00000000 003ee000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841093] xhci_hcd 0000:0e:00.0: @00000000c4b2d710 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841102] xhci_hcd 0000:0e:00.0: @00000000c4b2d720 05f3f000 00000000 00101000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841111] xhci_hcd 0000:0e:00.0: @00000000c4b2d730 05f40000 00000000 00081000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841120] xhci_hcd 0000:0e:00.0: @00000000c4b2d740 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841129] xhci_hcd 0000:0e:00.0: @00000000c4b2d750 05f41000 00000000 003ef000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841138] xhci_hcd 0000:0e:00.0: @00000000c4b2d760 05f50000 00000000 003e1000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841147] xhci_hcd 0000:0e:00.0: @00000000c4b2d770 05f51000 00000000 003ee000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841156] xhci_hcd 0000:0e:00.0: @00000000c4b2d780 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841165] xhci_hcd 0000:0e:00.0: @00000000c4b2d790 05f5f000 00000000 00101000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841174] xhci_hcd 0000:0e:00.0: @00000000c4b2d7a0 05f60000 00000000 00081000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841183] xhci_hcd 0000:0e:00.0: @00000000c4b2d7b0 bb0b0000 00000000 0000000d 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841192] xhci_hcd 0000:0e:00.0: @00000000c4b2d7c0 05f61000 00000000 003ef000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841201] xhci_hcd 0000:0e:00.0: @00000000c4b2d7d0 05f70000 00000000 003e1000 00000415
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841210] xhci_hcd 0000:0e:00.0: @00000000c4b2d7e0 05f71000 00000000 003ee000 00000425
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841219] xhci_hcd 0000:0e:00.0: @00000000c4b2d7f0 c4b2d400 00000000 00000000 00001803
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841230] xhci_hcd 0000:0e:00.0: // Ding dong!
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841355] xhci_hcd 0000:0e:00.0: Cancelling TD starting at ffff8800c4b2d440, 0xc4b2d440 (dma).
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841369] xhci_hcd 0000:0e:00.0: Cancel TRB ffff8800c4b2d440 (0xc4b2d440 dma) in seg ffff8800c4b325c0 (0xc4b2d400 dma)
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841381] xhci_hcd 0000:0e:00.0: Cancel TRB ffff8800c4b2d450 (0xc4b2d450 dma) in seg ffff8800c4b325c0 (0xc4b2d400 dma)
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841392] xhci_hcd 0000:0e:00.0: Cancel TRB ffff8800c4b2d460 (0xc4b2d460 dma) in seg ffff8800c4b325c0 (0xc4b2d400 dma)
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841443] xhci_hcd 0000:0e:00.0: get port status, actual port 3 status = 0x1203
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841452] xhci_hcd 0000:0e:00.0: Get port status returned 0x203
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841466] xhci_hcd 0000:0e:00.0: set port reset, actual port 3 status = 0x311
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841482] xhci_hcd 0000:0e:00.0: Port Status Change Event for port 5
Oct 24 12:21:56 falcon-p01 kernel: [ 191.841492] xhci_hcd 0000:0e:00.0: handle_port_status: starting port polling.
Oct 24 12:21:56 falcon-p01 kernel: [ 191.896044] xhci_hcd 0000:0e:00.0: get port status, actual port 3 status = 0x201203
Oct 24 12:21:56 falcon-p01 kernel: [ 191.896055] xhci_hcd 0000:0e:00.0: Get port status returned 0x100203
Oct 24 12:21:56 falcon-p01 kernel: [ 191.952033] xhci_hcd 0000:0e:00.0: Resetting device with slot ID 2
I'm a bit confused about what's happening here. Earlier in the log, the
stop endpoint command stalled (possibly because it was waiting on a
bogus command pointer), and the xHCI host was marked as dying. That
should cause the USB core to halt and reset the host controller, which
means we should never get a port status change event. So something odd
is happening here.
This log doesn't match my mental model of how the driver currently
works, so please test on the 3.10 kernel and let me know if that either
resolves your issue, or send a new log if you still run into the issue.
