I've done some more testing, and Andiry's seven PM patches (mostly)
work, when I apply the two extra patches that are attached. The first
patch fixes the control endpoint issue I described, and the second patch
fixes an issue with persistent USB 3.0 devices across suspend with a
power loss and hibernate.
Alan, could you look over the second patch? It fixes the issue I was
seeing, but I'm not sure if there are further-reaching implications for
khubd when a USB 3.0 port is not disabled after a hub reset-resume.
Andiry, I've been testing suspend and hibernate support on my laptop
with an NEC express card. The card isn't powered across the suspend,
and I'm testing with CONFIG_PM_RUNTIME=y and CONFIG_USB_SUSPEND=n.
Suspend and hibernate work fine with USB 2.0 devices under xHCI.
Inactive USB 3.0 devices also seem to work after both suspend and
hibernate.
However, I'm seeing an issue that is triggered by playing a movie on a
USB 3.0 hard drive when I attempt to hibernate. The first couple of
times, my xserver or i915 driver seemed to act up (screen blank but
mouse still there, or screen brightness turned completely down with no
response to contrast buttons).
The third time the hibernate worked successfully, but when I immediately
tried to hibernate it again, the computer rebooted on resume. The
fourth time the PM subsystem seemed to get stuck in the "syncing
filesystems" portion, and bulk endpoint transfers from the USB 3.0
device kept streaming by. The magic sysreq keys worked, and I was able
to umount the drive and reboot. I haven't been able to get any useful
dmesg output.
I'm not sure if my issues are caused by my graphics hardware/xserver,
so could you try to reproduce this issue on your own systems?
Sarah Sharp
On Thu, Oct 07, 2010 at 03:47:28PM -0700, Sarah Sharp wrote:
> Sorry, here's the actual log snippet.
>
> Sarah Sharp
>
> On Thu, Oct 07, 2010 at 03:19:27PM -0700, Sarah Sharp wrote:
> > Andiry,
> >
> > I think there is a bug in this patch, but I'm not sure exactly what
> > you're doing with virt_dev->configured, so I can't suggest how to fix
> > it.
> >
> > The problem happens when the USB core tries to reset and re-address a
> > device that had been active and had some control transfers complete. An
> > example would be when the usb-storage driver tries to reset the device
> > after it gets an answer to a SCSI command that it doesn't like.
> >
> > With this patch, after a Device Reset command finishes,
> > virt_dev->configured is set to false. When the USB core tries to
> > address the device, xhci_address_device() will call
> > xhci_setup_addressable_virt_dev(). This initializes the slot and
> > endpoint 0 contexts to their defaults, including setting the control
> > endpoint ring dequeue pointer to the top of the ring.
> >
> > However, the control endpoint ring was used before, so the internal xHCI
> > driver internal dequeue pointer still points somewhere in the middle of
> > the ring. Worse, the hardware may go re-execute the control transfers
> > between the top of the ring and the internal dequeue pointer, because
> > the cycle bit says it owns those TRBs. Then the driver will see a bunch
> > of spurious events from the control endpoint ring the next time the
> > doorbell is rung. See the attached log for an example.
> >
> > In the case of a device reset when control transfers have already
> > occurred, I think you really want to call
> > xhci_copy_ep0_dequeue_into_input_ctx() in xhci_address_device().
> > However, the code in xhci_address_device() won't do that, since
> > virt_dev->configured is always set to false after the Device Reset
> > command completes.
> >
> > Were you trying to use virt_dev->configured to set up the slot context
> > for an address device command after a resume where the xHCI host lost
> > power and the virt_dev had to be reallocated? Doesn't the place where
> > you set it to false in xhci_alloc_dev() cover that case?
> >
> > You could remove the statement where virt_dev->configured gets set to
> > false in after the Device Reset command completes, and that would fix
> > the problem with active devices being reset. But why make
> > xhci_address_device() just test some field in the slot context to see if
> > it's set properly, and call xhci_setup_addressable_virt_dev() if not?
> > Then you wouldn't need virt_dev->configured at all. You could check
> > that, say, slot_ctx->dev_info isn't zero (since the speed field in that
> > has to be set to some non-zero number).
> >
> > Sarah Sharp
> >
> > On Tue, Aug 31, 2010 at 04:44:53PM +0800, Andiry Xu wrote:
> > > >From bc53db5a7c84c2afad0f0dd938dec6c336e8ebe4 Mon Sep 17 00:00:00 2001
> > > From: Andiry Xu <andiry.xu@xxxxxxx>
> > > Date: Mon, 23 Aug 2010 13:29:35 +0800
> > > Subject: [PATCH 2/3] xHCI: change xhci_reset_device() to allocate new device
> > >
> > > Rename xhci_reset_device() to xhci_discover_or_reset_device().
> > > If xhci_discover_or_reset_device() is called to reset a device which does
> > > not exist or does not match the udev, it calls xhci_alloc_dev() to
> > > re-allocate the device.
> > >
> > > This would prevent the reset device failure, possibly due to the xHC restore
> > > error during S3/S4 resume. Note this change would affect xhci_address_device()
> > > behavior: udev->config exists, but the device is actually not configured yet.
> > > Add a flag in struct xhci_virt_device to indicate its actual state.
> > >
> > > Signed-off-by: Andiry Xu <andiry.xu@xxxxxxx>
> > > ---
> > > drivers/usb/host/xhci-mem.c | 1 +
> > > drivers/usb/host/xhci-pci.c | 2 +-
> > > drivers/usb/host/xhci.c | 37 ++++++++++++++++++++++++++++++++++---
> > > drivers/usb/host/xhci.h | 4 +++-
> > > 4 files changed, 39 insertions(+), 5 deletions(-)
> > >
> > > diff --git a/drivers/usb/host/xhci-mem.c b/drivers/usb/host/xhci-mem.c
> > > index be90180..e7947ea 100644
> > > --- a/drivers/usb/host/xhci-mem.c
> > > +++ b/drivers/usb/host/xhci-mem.c
> > > @@ -779,6 +779,7 @@ int xhci_alloc_virt_device(struct xhci_hcd *xhci, int slot_id,
> > > init_completion(&dev->cmd_completion);
> > > INIT_LIST_HEAD(&dev->cmd_list);
> > > dev->udev = udev;
> > > + dev->configured = false;
> > >
> > > /* Point to output device context in dcbaa. */
> > > xhci->dcbaa->dev_context_ptrs[slot_id] = dev->out_ctx->dma;
> > > diff --git a/drivers/usb/host/xhci-pci.c b/drivers/usb/host/xhci-pci.c
> > > index f7efe02..aefc349 100644
> > > --- a/drivers/usb/host/xhci-pci.c
> > > +++ b/drivers/usb/host/xhci-pci.c
> > > @@ -152,7 +152,7 @@ static const struct hc_driver xhci_pci_hc_driver = {
> > > .reset_bandwidth = xhci_reset_bandwidth,
> > > .address_device = xhci_address_device,
> > > .update_hub_device = xhci_update_hub_device,
> > > - .reset_device = xhci_reset_device,
> > > + .reset_device = xhci_discover_or_reset_device,
> > >
> > > /*
> > > * scheduling support
> > > diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
> > > index 4201119..a0dca7c 100644
> > > --- a/drivers/usb/host/xhci.c
> > > +++ b/drivers/usb/host/xhci.c
> > > @@ -1372,6 +1372,7 @@ int xhci_check_bandwidth(struct usb_hcd *hcd, struct usb_device *udev)
> > > return ret;
> > > }
> > >
> > > + virt_dev->configured = true;
> > > xhci_dbg(xhci, "Output context after successful config ep cmd:\n");
> > > xhci_dbg_ctx(xhci, virt_dev->out_ctx,
> > > LAST_CTX_TO_EP_NUM(slot_ctx->dev_info));
> > > @@ -1943,8 +1944,13 @@ int xhci_free_streams(struct usb_hcd *hcd, struct usb_device *udev,
> > > * Wait for the Reset Device command to finish. Remove all structures
> > > * associated with the endpoints that were disabled. Clear the input device
> > > * structure? Cache the rings? Reset the control endpoint 0 max packet size?
> > > + *
> > > + * If the virt_dev to be reset does not exist or does not match the udev,
> > > + * it means the device is lost, possibly due to the xHC restore error and
> > > + * re-initialization during S3/S4. In this case, call xhci_alloc_dev() to
> > > + * re-allocate the device.
> > > */
> > > -int xhci_reset_device(struct usb_hcd *hcd, struct usb_device *udev)
> > > +int xhci_discover_or_reset_device(struct usb_hcd *hcd, struct usb_device *udev)
> > > {
> > > int ret, i;
> > > unsigned long flags;
> > > @@ -1955,12 +1961,36 @@ int xhci_reset_device(struct usb_hcd *hcd, struct usb_device *udev)
> > > int timeleft;
> > > int last_freed_endpoint;
> > >
> > > - ret = xhci_check_args(hcd, udev, NULL, 0, true, __func__);
> > > + ret = xhci_check_args(hcd, udev, NULL, 0, false, __func__);
> > > if (ret <= 0)
> > > return ret;
> > > xhci = hcd_to_xhci(hcd);
> > > slot_id = udev->slot_id;
> > > virt_dev = xhci->devs[slot_id];
> > > + if (!virt_dev) {
> > > + xhci_dbg(xhci, "The device to be reset with slot ID %u does "
> > > + "not exist. Re-allocate the device\n", slot_id);
> > > + ret = xhci_alloc_dev(hcd, udev);
> > > + if (ret == 1)
> > > + return 0;
> > > + else
> > > + return -EINVAL;
> > > + }
> > > +
> > > + if (virt_dev->udev != udev) {
> > > + /* If the virt_dev and the udev does not match, this virt_dev
> > > + * may belong to another udev.
> > > + * Re-allocate the device.
> > > + */
> > > + xhci_dbg(xhci, "The device to be reset with slot ID %u does "
> > > + "not match the udev. Re-allocate the device\n",
> > > + slot_id);
> > > + ret = xhci_alloc_dev(hcd, udev);
> > > + if (ret == 1)
> > > + return 0;
> > > + else
> > > + return -EINVAL;
> > > + }
> > >
> > > xhci_dbg(xhci, "Resetting device with slot ID %u\n", slot_id);
> > > /* Allocate the command structure that holds the struct completion.
> > > @@ -2024,6 +2054,7 @@ int xhci_reset_device(struct usb_hcd *hcd, struct usb_device *udev)
> > > goto command_cleanup;
> > > case COMP_SUCCESS:
> > > xhci_dbg(xhci, "Successful reset device command.\n");
> > > + virt_dev->configured = false;
> > > break;
> > > default:
> > > if (xhci_is_vendor_info_code(xhci, ret))
> > > @@ -2177,7 +2208,7 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev)
> > > virt_dev = xhci->devs[udev->slot_id];
> > >
> > > /* If this is a Set Address to an unconfigured device, setup ep 0 */
> > > - if (!udev->config)
> > > + if (!udev->config || !virt_dev->configured)
> > > xhci_setup_addressable_virt_dev(xhci, udev);
> > > else
> > > xhci_copy_ep0_dequeue_into_input_ctx(xhci, udev);
> > > diff --git a/drivers/usb/host/xhci.h b/drivers/usb/host/xhci.h
> > > index f03f140..6ab0a52 100644
> > > --- a/drivers/usb/host/xhci.h
> > > +++ b/drivers/usb/host/xhci.h
> > > @@ -746,6 +746,8 @@ struct xhci_virt_device {
> > > /* Rings saved to ensure old alt settings can be re-instated */
> > > struct xhci_ring **ring_cache;
> > > int num_rings_cached;
> > > + /* Indicate whether the device is configured */
> > > + bool configured;
> > > #define XHCI_MAX_RINGS_CACHED 31
> > > struct xhci_virt_ep eps[31];
> > > struct completion cmd_completion;
> > > @@ -1389,7 +1391,7 @@ int xhci_urb_dequeue(struct usb_hcd *hcd, struct urb *urb, int status);
> > > int xhci_add_endpoint(struct usb_hcd *hcd, struct usb_device *udev, struct usb_host_endpoint *ep);
> > > int xhci_drop_endpoint(struct usb_hcd *hcd, struct usb_device *udev, struct usb_host_endpoint *ep);
> > > void xhci_endpoint_reset(struct usb_hcd *hcd, struct usb_host_endpoint *ep);
> > > -int xhci_reset_device(struct usb_hcd *hcd, struct usb_device *udev);
> > > +int xhci_discover_or_reset_device(struct usb_hcd *hcd, struct usb_device *udev);
> > > int xhci_check_bandwidth(struct usb_hcd *hcd, struct usb_device *udev);
> > > void xhci_reset_bandwidth(struct usb_hcd *hcd, struct usb_device *udev);
> > >
> > > --
> > > 1.7.0.4
> > >
> > >
> > >
> > --
> > 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
> Oct 6 15:17:36 xanatos kernel: [ 2165.826232] xhci_hcd 0000:05:00.0: set port reset, actual port 1 status = 0x1311
> Oct 6 15:17:36 xanatos kernel: [ 2165.826260] xhci_hcd 0000:05:00.0: op reg status = 00000018
> Oct 6 15:17:36 xanatos kernel: [ 2165.826262] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.826265] xhci_hcd 0000:05:00.0: @37c806c0 02000000 00000000 01000000 00008801
> Oct 6 15:17:36 xanatos kernel: [ 2165.826268] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h18, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.826271] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.826273] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.826276] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_port_status
> Oct 6 15:17:36 xanatos kernel: [ 2165.826279] xhci_hcd 0000:05:00.0: Port Status Change Event for port 2
> Oct 6 15:17:36 xanatos kernel: [ 2165.826285] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c806d0 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.826300] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_port_status
> Oct 6 15:17:36 xanatos kernel: [ 2165.826302] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.826312] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c806d8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.880068] xhci_hcd 0000:05:00.0: get port status, actual port 1 status = 0x201203
> Oct 6 15:17:36 xanatos kernel: [ 2165.880071] xhci_hcd 0000:05:00.0: Get port status returned 0x8103
> Oct 6 15:17:36 xanatos kernel: [ 2165.936095] xhci_hcd 0000:05:00.0: Resetting device with slot ID 1
> Oct 6 15:17:36 xanatos kernel: [ 2165.936098] xhci_hcd 0000:05:00.0: Endpoint state = 0x1
> Oct 6 15:17:36 xanatos kernel: [ 2165.936101] xhci_hcd 0000:05:00.0: Command ring enq = 0x37c80100 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.936103] xhci_hcd 0000:05:00.0: // Ding dong!
> Oct 6 15:17:36 xanatos kernel: [ 2165.936109] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360800, 32'h0, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.936557] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.936560] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.936563] xhci_hcd 0000:05:00.0: @37c806d0 37c800f0 00000000 01000000 01008401
> Oct 6 15:17:36 xanatos kernel: [ 2165.936566] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.936568] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.936571] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.936573] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_cmd_completion
> Oct 6 15:17:36 xanatos kernel: [ 2165.936576] xhci_hcd 0000:05:00.0: Completed reset device command.
> Oct 6 15:17:36 xanatos kernel: [ 2165.936579] xhci_hcd 0000:05:00.0: Command ring deq = 0x37c80100 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.936582] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_cmd_completion
> Oct 6 15:17:36 xanatos kernel: [ 2165.936585] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c806e0 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.936587] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.936596] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c806e8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.936602] xhci_hcd 0000:05:00.0: Successful reset device command.
> Oct 6 15:17:36 xanatos kernel: [ 2165.936605] xhci_hcd 0000:05:00.0: Cached old ring, 1 ring cached
> Oct 6 15:17:36 xanatos kernel: [ 2165.936608] xhci_hcd 0000:05:00.0: Cached old ring, 2 rings cached
> Oct 6 15:17:36 xanatos kernel: [ 2165.936610] xhci_hcd 0000:05:00.0: Output context after successful reset device cmd:
> Oct 6 15:17:36 xanatos kernel: [ 2165.936613] xhci_hcd 0000:05:00.0: Slot Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.936616] xhci_hcd 0000:05:00.0: @ffff8800ad408000 (virt) @ad408000 (dma) 0x20400000 - dev_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936620] xhci_hcd 0000:05:00.0: @ffff8800ad408004 (virt) @ad408004 (dma) 0x020000 - dev_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.936623] xhci_hcd 0000:05:00.0: @ffff8800ad408008 (virt) @ad408008 (dma) 0x000000 - tt_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936626] xhci_hcd 0000:05:00.0: @ffff8800ad40800c (virt) @ad40800c (dma) 0x8000000 - dev_state
> Oct 6 15:17:36 xanatos kernel: [ 2165.936629] xhci_hcd 0000:05:00.0: @ffff8800ad408010 (virt) @ad408010 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936633] xhci_hcd 0000:05:00.0: @ffff8800ad408014 (virt) @ad408014 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936636] xhci_hcd 0000:05:00.0: @ffff8800ad408018 (virt) @ad408018 (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936639] xhci_hcd 0000:05:00.0: @ffff8800ad40801c (virt) @ad40801c (dma) 0x000000 - rsvd[3]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936642] xhci_hcd 0000:05:00.0: Endpoint 00 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.936645] xhci_hcd 0000:05:00.0: @ffff8800ad408020 (virt) @ad408020 (dma) 0x000001 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936648] xhci_hcd 0000:05:00.0: @ffff8800ad408024 (virt) @ad408024 (dma) 0x2000026 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.936651] xhci_hcd 0000:05:00.0: @ffff8800ad408028 (virt) @ad408028 (dma) 0x37c80801 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.936654] xhci_hcd 0000:05:00.0: @ffff8800ad408030 (virt) @ad408030 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936657] xhci_hcd 0000:05:00.0: @ffff8800ad408034 (virt) @ad408034 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936660] xhci_hcd 0000:05:00.0: @ffff8800ad408038 (virt) @ad408038 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936663] xhci_hcd 0000:05:00.0: @ffff8800ad40803c (virt) @ad40803c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936666] xhci_hcd 0000:05:00.0: Endpoint 01 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.936669] xhci_hcd 0000:05:00.0: @ffff8800ad408040 (virt) @ad408040 (dma) 0x000000 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936672] xhci_hcd 0000:05:00.0: @ffff8800ad408044 (virt) @ad408044 (dma) 0x000000 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.936675] xhci_hcd 0000:05:00.0: @ffff8800ad408048 (virt) @ad408048 (dma) 0x000000 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.936678] xhci_hcd 0000:05:00.0: @ffff8800ad408050 (virt) @ad408050 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936681] xhci_hcd 0000:05:00.0: @ffff8800ad408054 (virt) @ad408054 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936684] xhci_hcd 0000:05:00.0: @ffff8800ad408058 (virt) @ad408058 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936688] xhci_hcd 0000:05:00.0: @ffff8800ad40805c (virt) @ad40805c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936690] xhci_hcd 0000:05:00.0: Endpoint 02 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.936693] xhci_hcd 0000:05:00.0: @ffff8800ad408060 (virt) @ad408060 (dma) 0x000000 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936696] xhci_hcd 0000:05:00.0: @ffff8800ad408064 (virt) @ad408064 (dma) 0x4000f36 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.936699] xhci_hcd 0000:05:00.0: @ffff8800ad408068 (virt) @ad408068 (dma) 0xad5470e1 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.936702] xhci_hcd 0000:05:00.0: @ffff8800ad408070 (virt) @ad408070 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936705] xhci_hcd 0000:05:00.0: @ffff8800ad408074 (virt) @ad408074 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936709] xhci_hcd 0000:05:00.0: @ffff8800ad408078 (virt) @ad408078 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936712] xhci_hcd 0000:05:00.0: @ffff8800ad40807c (virt) @ad40807c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936714] xhci_hcd 0000:05:00.0: Endpoint 03 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.936717] xhci_hcd 0000:05:00.0: @ffff8800ad408080 (virt) @ad408080 (dma) 0x000000 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936720] xhci_hcd 0000:05:00.0: @ffff8800ad408084 (virt) @ad408084 (dma) 0x4000f16 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.936723] xhci_hcd 0000:05:00.0: @ffff8800ad408088 (virt) @ad408088 (dma) 0xad547401 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.936726] xhci_hcd 0000:05:00.0: @ffff8800ad408090 (virt) @ad408090 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936730] xhci_hcd 0000:05:00.0: @ffff8800ad408094 (virt) @ad408094 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936733] xhci_hcd 0000:05:00.0: @ffff8800ad408098 (virt) @ad408098 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936736] xhci_hcd 0000:05:00.0: @ffff8800ad40809c (virt) @ad40809c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936744] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360430, 32'h201201, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.936752] xhci_hcd 0000:05:00.0: clear port reset change, actual port 1 status = 0x1203
> Oct 6 15:17:36 xanatos kernel: [ 2165.936756] xhci_hcd 0000:05:00.0: Set root hub portnum to 2
> Oct 6 15:17:36 xanatos kernel: [ 2165.936758] xhci_hcd 0000:05:00.0: udev->tt = (null)
> Oct 6 15:17:36 xanatos kernel: [ 2165.936761] xhci_hcd 0000:05:00.0: udev->ttport = 0x0
> Oct 6 15:17:36 xanatos kernel: [ 2165.936763] xhci_hcd 0000:05:00.0: Slot ID 1 Input Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.936766] xhci_hcd 0000:05:00.0: @ffff880037ed6000 (virt) @37ed6000 (dma) 0x000000 - drop flags
> Oct 6 15:17:36 xanatos kernel: [ 2165.936769] xhci_hcd 0000:05:00.0: @ffff880037ed6004 (virt) @37ed6004 (dma) 0x000003 - add flags
> Oct 6 15:17:36 xanatos kernel: [ 2165.936773] xhci_hcd 0000:05:00.0: @ffff880037ed6008 (virt) @37ed6008 (dma) 0x000000 - rsvd2[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936776] xhci_hcd 0000:05:00.0: @ffff880037ed600c (virt) @37ed600c (dma) 0x000000 - rsvd2[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936779] xhci_hcd 0000:05:00.0: @ffff880037ed6010 (virt) @37ed6010 (dma) 0x000000 - rsvd2[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936782] xhci_hcd 0000:05:00.0: @ffff880037ed6014 (virt) @37ed6014 (dma) 0x000000 - rsvd2[3]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936785] xhci_hcd 0000:05:00.0: @ffff880037ed6018 (virt) @37ed6018 (dma) 0x000000 - rsvd2[4]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936788] xhci_hcd 0000:05:00.0: @ffff880037ed601c (virt) @37ed601c (dma) 0x000000 - rsvd2[5]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936791] xhci_hcd 0000:05:00.0: Slot Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.936794] xhci_hcd 0000:05:00.0: @ffff880037ed6020 (virt) @37ed6020 (dma) 0x8400000 - dev_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936797] xhci_hcd 0000:05:00.0: @ffff880037ed6024 (virt) @37ed6024 (dma) 0x020000 - dev_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.936800] xhci_hcd 0000:05:00.0: @ffff880037ed6028 (virt) @37ed6028 (dma) 0x000000 - tt_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936803] xhci_hcd 0000:05:00.0: @ffff880037ed602c (virt) @37ed602c (dma) 0x000000 - dev_state
> Oct 6 15:17:36 xanatos kernel: [ 2165.936812] xhci_hcd 0000:05:00.0: @ffff880037ed6030 (virt) @37ed6030 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936815] xhci_hcd 0000:05:00.0: @ffff880037ed6034 (virt) @37ed6034 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936817] xhci_hcd 0000:05:00.0: @ffff880037ed6038 (virt) @37ed6038 (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936820] xhci_hcd 0000:05:00.0: @ffff880037ed603c (virt) @37ed603c (dma) 0x000000 - rsvd[3]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936823] xhci_hcd 0000:05:00.0: Endpoint 00 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.936825] xhci_hcd 0000:05:00.0: @ffff880037ed6040 (virt) @37ed6040 (dma) 0x000000 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936828] xhci_hcd 0000:05:00.0: @ffff880037ed6044 (virt) @37ed6044 (dma) 0x2000026 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.936831] xhci_hcd 0000:05:00.0: @ffff880037ed6048 (virt) @37ed6048 (dma) 0x37c80801 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.936833] xhci_hcd 0000:05:00.0: @ffff880037ed6050 (virt) @37ed6050 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936836] xhci_hcd 0000:05:00.0: @ffff880037ed6054 (virt) @37ed6054 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936839] xhci_hcd 0000:05:00.0: @ffff880037ed6058 (virt) @37ed6058 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936841] xhci_hcd 0000:05:00.0: @ffff880037ed605c (virt) @37ed605c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936844] xhci_hcd 0000:05:00.0: Endpoint 01 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.936846] xhci_hcd 0000:05:00.0: @ffff880037ed6060 (virt) @37ed6060 (dma) 0x000000 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936849] xhci_hcd 0000:05:00.0: @ffff880037ed6064 (virt) @37ed6064 (dma) 0x000000 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.936851] xhci_hcd 0000:05:00.0: @ffff880037ed6068 (virt) @37ed6068 (dma) 0x000000 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.936854] xhci_hcd 0000:05:00.0: @ffff880037ed6070 (virt) @37ed6070 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936857] xhci_hcd 0000:05:00.0: @ffff880037ed6074 (virt) @37ed6074 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936860] xhci_hcd 0000:05:00.0: @ffff880037ed6078 (virt) @37ed6078 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936862] xhci_hcd 0000:05:00.0: @ffff880037ed607c (virt) @37ed607c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936865] xhci_hcd 0000:05:00.0: Endpoint 02 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.936867] xhci_hcd 0000:05:00.0: @ffff880037ed6080 (virt) @37ed6080 (dma) 0x000000 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936870] xhci_hcd 0000:05:00.0: @ffff880037ed6084 (virt) @37ed6084 (dma) 0x000000 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.936873] xhci_hcd 0000:05:00.0: @ffff880037ed6088 (virt) @37ed6088 (dma) 0x000000 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.936875] xhci_hcd 0000:05:00.0: @ffff880037ed6090 (virt) @37ed6090 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.936878] xhci_hcd 0000:05:00.0: @ffff880037ed6094 (virt) @37ed6094 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936881] xhci_hcd 0000:05:00.0: @ffff880037ed6098 (virt) @37ed6098 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936883] xhci_hcd 0000:05:00.0: @ffff880037ed609c (virt) @37ed609c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.936886] xhci_hcd 0000:05:00.0: Endpoint state = 0x1
> Oct 6 15:17:36 xanatos kernel: [ 2165.936888] xhci_hcd 0000:05:00.0: Command ring enq = 0x37c80110 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.936890] xhci_hcd 0000:05:00.0: // Ding dong!
> Oct 6 15:17:36 xanatos kernel: [ 2165.936896] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360800, 32'h0, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.937280] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.937283] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.937286] xhci_hcd 0000:05:00.0: @37c806e0 37c80100 00000000 01000000 01008401
> Oct 6 15:17:36 xanatos kernel: [ 2165.937289] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.937292] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.937294] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.937297] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_cmd_completion
> Oct 6 15:17:36 xanatos kernel: [ 2165.937301] xhci_hcd 0000:05:00.0: Command ring deq = 0x37c80110 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.937303] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_cmd_completion
> Oct 6 15:17:36 xanatos kernel: [ 2165.937306] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c806f0 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.937308] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.937317] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c806f8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.937325] xhci_hcd 0000:05:00.0: Successful Address Device command
> Oct 6 15:17:36 xanatos kernel: [ 2165.937334] xhci_hcd 0000:05:00.0: Op regs DCBAA ptr = 0x00000037eaa000
> Oct 6 15:17:36 xanatos kernel: [ 2165.937337] xhci_hcd 0000:05:00.0: Slot ID 1 dcbaa entry @ffff880037eaa008 = 0x000000ad408000
> Oct 6 15:17:36 xanatos kernel: [ 2165.937340] xhci_hcd 0000:05:00.0: Output Context DMA address = 0xad408000
> Oct 6 15:17:36 xanatos kernel: [ 2165.937343] xhci_hcd 0000:05:00.0: Slot ID 1 Input Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.937346] xhci_hcd 0000:05:00.0: @ffff880037ed6000 (virt) @37ed6000 (dma) 0x000000 - drop flags
> Oct 6 15:17:36 xanatos kernel: [ 2165.937349] xhci_hcd 0000:05:00.0: @ffff880037ed6004 (virt) @37ed6004 (dma) 0x000003 - add flags
> Oct 6 15:17:36 xanatos kernel: [ 2165.937353] xhci_hcd 0000:05:00.0: @ffff880037ed6008 (virt) @37ed6008 (dma) 0x000000 - rsvd2[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937356] xhci_hcd 0000:05:00.0: @ffff880037ed600c (virt) @37ed600c (dma) 0x000000 - rsvd2[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937359] xhci_hcd 0000:05:00.0: @ffff880037ed6010 (virt) @37ed6010 (dma) 0x000000 - rsvd2[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937362] xhci_hcd 0000:05:00.0: @ffff880037ed6014 (virt) @37ed6014 (dma) 0x000000 - rsvd2[3]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937365] xhci_hcd 0000:05:00.0: @ffff880037ed6018 (virt) @37ed6018 (dma) 0x000000 - rsvd2[4]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937368] xhci_hcd 0000:05:00.0: @ffff880037ed601c (virt) @37ed601c (dma) 0x000000 - rsvd2[5]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937371] xhci_hcd 0000:05:00.0: Slot Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.937374] xhci_hcd 0000:05:00.0: @ffff880037ed6020 (virt) @37ed6020 (dma) 0x8400000 - dev_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937377] xhci_hcd 0000:05:00.0: @ffff880037ed6024 (virt) @37ed6024 (dma) 0x020000 - dev_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.937380] xhci_hcd 0000:05:00.0: @ffff880037ed6028 (virt) @37ed6028 (dma) 0x000000 - tt_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937383] xhci_hcd 0000:05:00.0: @ffff880037ed602c (virt) @37ed602c (dma) 0x000000 - dev_state
> Oct 6 15:17:36 xanatos kernel: [ 2165.937386] xhci_hcd 0000:05:00.0: @ffff880037ed6030 (virt) @37ed6030 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937390] xhci_hcd 0000:05:00.0: @ffff880037ed6034 (virt) @37ed6034 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937393] xhci_hcd 0000:05:00.0: @ffff880037ed6038 (virt) @37ed6038 (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937396] xhci_hcd 0000:05:00.0: @ffff880037ed603c (virt) @37ed603c (dma) 0x000000 - rsvd[3]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937399] xhci_hcd 0000:05:00.0: Endpoint 00 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.937401] xhci_hcd 0000:05:00.0: @ffff880037ed6040 (virt) @37ed6040 (dma) 0x000000 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937405] xhci_hcd 0000:05:00.0: @ffff880037ed6044 (virt) @37ed6044 (dma) 0x2000026 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.937408] xhci_hcd 0000:05:00.0: @ffff880037ed6048 (virt) @37ed6048 (dma) 0x37c80801 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.937411] xhci_hcd 0000:05:00.0: @ffff880037ed6050 (virt) @37ed6050 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937414] xhci_hcd 0000:05:00.0: @ffff880037ed6054 (virt) @37ed6054 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937417] xhci_hcd 0000:05:00.0: @ffff880037ed6058 (virt) @37ed6058 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937420] xhci_hcd 0000:05:00.0: @ffff880037ed605c (virt) @37ed605c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937423] xhci_hcd 0000:05:00.0: Endpoint 01 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.937426] xhci_hcd 0000:05:00.0: @ffff880037ed6060 (virt) @37ed6060 (dma) 0x000000 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937429] xhci_hcd 0000:05:00.0: @ffff880037ed6064 (virt) @37ed6064 (dma) 0x000000 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.937432] xhci_hcd 0000:05:00.0: @ffff880037ed6068 (virt) @37ed6068 (dma) 0x000000 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.937435] xhci_hcd 0000:05:00.0: @ffff880037ed6070 (virt) @37ed6070 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937438] xhci_hcd 0000:05:00.0: @ffff880037ed6074 (virt) @37ed6074 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937441] xhci_hcd 0000:05:00.0: @ffff880037ed6078 (virt) @37ed6078 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937444] xhci_hcd 0000:05:00.0: @ffff880037ed607c (virt) @37ed607c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937447] xhci_hcd 0000:05:00.0: Endpoint 02 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.937449] xhci_hcd 0000:05:00.0: @ffff880037ed6080 (virt) @37ed6080 (dma) 0x000000 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937452] xhci_hcd 0000:05:00.0: @ffff880037ed6084 (virt) @37ed6084 (dma) 0x000000 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.937456] xhci_hcd 0000:05:00.0: @ffff880037ed6088 (virt) @37ed6088 (dma) 0x000000 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.937459] xhci_hcd 0000:05:00.0: @ffff880037ed6090 (virt) @37ed6090 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937462] xhci_hcd 0000:05:00.0: @ffff880037ed6094 (virt) @37ed6094 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937465] xhci_hcd 0000:05:00.0: @ffff880037ed6098 (virt) @37ed6098 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937468] xhci_hcd 0000:05:00.0: @ffff880037ed609c (virt) @37ed609c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937471] xhci_hcd 0000:05:00.0: Slot ID 1 Output Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.937473] xhci_hcd 0000:05:00.0: Slot Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.937476] xhci_hcd 0000:05:00.0: @ffff8800ad408000 (virt) @ad408000 (dma) 0x8400000 - dev_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937479] xhci_hcd 0000:05:00.0: @ffff8800ad408004 (virt) @ad408004 (dma) 0x020000 - dev_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.937482] xhci_hcd 0000:05:00.0: @ffff8800ad408008 (virt) @ad408008 (dma) 0x000000 - tt_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937485] xhci_hcd 0000:05:00.0: @ffff8800ad40800c (virt) @ad40800c (dma) 0x10000001 - dev_state
> Oct 6 15:17:36 xanatos kernel: [ 2165.937488] xhci_hcd 0000:05:00.0: @ffff8800ad408010 (virt) @ad408010 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937492] xhci_hcd 0000:05:00.0: @ffff8800ad408014 (virt) @ad408014 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937495] xhci_hcd 0000:05:00.0: @ffff8800ad408018 (virt) @ad408018 (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937498] xhci_hcd 0000:05:00.0: @ffff8800ad40801c (virt) @ad40801c (dma) 0x000000 - rsvd[3]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937501] xhci_hcd 0000:05:00.0: Endpoint 00 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.937503] xhci_hcd 0000:05:00.0: @ffff8800ad408020 (virt) @ad408020 (dma) 0x000001 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937506] xhci_hcd 0000:05:00.0: @ffff8800ad408024 (virt) @ad408024 (dma) 0x2000026 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.937510] xhci_hcd 0000:05:00.0: @ffff8800ad408028 (virt) @ad408028 (dma) 0x37c80801 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.937513] xhci_hcd 0000:05:00.0: @ffff8800ad408030 (virt) @ad408030 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937516] xhci_hcd 0000:05:00.0: @ffff8800ad408034 (virt) @ad408034 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937519] xhci_hcd 0000:05:00.0: @ffff8800ad408038 (virt) @ad408038 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937522] xhci_hcd 0000:05:00.0: @ffff8800ad40803c (virt) @ad40803c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937525] xhci_hcd 0000:05:00.0: Endpoint 01 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.937527] xhci_hcd 0000:05:00.0: @ffff8800ad408040 (virt) @ad408040 (dma) 0x000000 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937536] xhci_hcd 0000:05:00.0: @ffff8800ad408044 (virt) @ad408044 (dma) 0x000000 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.937539] xhci_hcd 0000:05:00.0: @ffff8800ad408048 (virt) @ad408048 (dma) 0x000000 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.937541] xhci_hcd 0000:05:00.0: @ffff8800ad408050 (virt) @ad408050 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937544] xhci_hcd 0000:05:00.0: @ffff8800ad408054 (virt) @ad408054 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937547] xhci_hcd 0000:05:00.0: @ffff8800ad408058 (virt) @ad408058 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937549] xhci_hcd 0000:05:00.0: @ffff8800ad40805c (virt) @ad40805c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937552] xhci_hcd 0000:05:00.0: Endpoint 02 Context:
> Oct 6 15:17:36 xanatos kernel: [ 2165.937554] xhci_hcd 0000:05:00.0: @ffff8800ad408060 (virt) @ad408060 (dma) 0x000000 - ep_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937557] xhci_hcd 0000:05:00.0: @ffff8800ad408064 (virt) @ad408064 (dma) 0x4000f36 - ep_info2
> Oct 6 15:17:36 xanatos kernel: [ 2165.937560] xhci_hcd 0000:05:00.0: @ffff8800ad408068 (virt) @ad408068 (dma) 0xad5470e1 - deq
> Oct 6 15:17:36 xanatos kernel: [ 2165.937562] xhci_hcd 0000:05:00.0: @ffff8800ad408070 (virt) @ad408070 (dma) 0x000000 - tx_info
> Oct 6 15:17:36 xanatos kernel: [ 2165.937565] xhci_hcd 0000:05:00.0: @ffff8800ad408074 (virt) @ad408074 (dma) 0x000000 - rsvd[0]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937568] xhci_hcd 0000:05:00.0: @ffff8800ad408078 (virt) @ad408078 (dma) 0x000000 - rsvd[1]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937570] xhci_hcd 0000:05:00.0: @ffff8800ad40807c (virt) @ad40807c (dma) 0x000000 - rsvd[2]
> Oct 6 15:17:36 xanatos kernel: [ 2165.937573] xhci_hcd 0000:05:00.0: Internal device address = 2
> Oct 6 15:17:36 xanatos kernel: [ 2165.937576] usb 9-2: reset SuperSpeed USB device using xhci_hcd and address 2
> Oct 6 15:17:36 xanatos kernel: [ 2165.952014] xhci_hcd 0000:05:00.0: Queueing ctrl tx for slot id 1, ep 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.952017] xhci_hcd 0000:05:00.0: Endpoint state = 0x1
> Oct 6 15:17:36 xanatos kernel: [ 2165.952020] xhci_hcd 0000:05:00.0: Ring enq = 0x37c80990 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.952023] xhci_hcd 0000:05:00.0: Ring enq = 0x37c809a0 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.952025] xhci_hcd 0000:05:00.0: Ring enq = 0x37c809b0 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.952032] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360804, 32'h1, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.952592] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.952596] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.952600] xhci_hcd 0000:05:00.0: @37c806f0 37c80820 00000000 01000000 01018001
> Oct 6 15:17:36 xanatos kernel: [ 2165.952604] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.952607] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.952610] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.952614] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.952617] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.952621] xhci_hcd 0000:05:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
> Oct 6 15:17:36 xanatos kernel: [ 2165.952625] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.952628] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c80700 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.952632] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.952641] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c80708, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.953217] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.953219] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.953222] xhci_hcd 0000:05:00.0: @37c80700 37c80850 00000000 01000000 01018001
> Oct 6 15:17:36 xanatos kernel: [ 2165.953225] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.953227] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.953230] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.953232] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.953235] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.953237] xhci_hcd 0000:05:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
> Oct 6 15:17:36 xanatos kernel: [ 2165.953240] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.953243] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c80710 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.953245] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.953255] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c80718, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.953842] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.953845] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.953849] xhci_hcd 0000:05:00.0: @37c80710 37c80880 00000000 01000000 01018001
> Oct 6 15:17:36 xanatos kernel: [ 2165.953853] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.953856] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.953859] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.953862] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.953866] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.953869] xhci_hcd 0000:05:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
> Oct 6 15:17:36 xanatos kernel: [ 2165.953873] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.953876] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c80720 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.953879] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.953889] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c80728, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.954219] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.954221] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.954224] xhci_hcd 0000:05:00.0: @37c80720 37c808a0 00000000 0d0000dd 01018001
> Oct 6 15:17:36 xanatos kernel: [ 2165.954227] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.954230] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.954232] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.954234] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.954237] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.954239] xhci_hcd 0000:05:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
> Oct 6 15:17:36 xanatos kernel: [ 2165.954242] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.954245] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c80730 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.954247] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.954256] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c80738, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.954470] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.954473] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.954477] xhci_hcd 0000:05:00.0: @37c80730 37c808b0 00000000 01000000 01018001
> Oct 6 15:17:36 xanatos kernel: [ 2165.954481] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.954485] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.954488] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.954491] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.954494] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.954497] xhci_hcd 0000:05:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
> Oct 6 15:17:36 xanatos kernel: [ 2165.954500] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.954504] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c80740 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.954507] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.954517] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c80748, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.954844] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.954846] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.954849] xhci_hcd 0000:05:00.0: @37c80740 37c808d0 00000000 01000000 01018001
> Oct 6 15:17:36 xanatos kernel: [ 2165.954852] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.954854] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.954857] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.954859] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.954862] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.954864] xhci_hcd 0000:05:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
> Oct 6 15:17:36 xanatos kernel: [ 2165.954867] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.954869] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c80750 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.954872] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.954881] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c80758, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.955219] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.955222] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.955225] xhci_hcd 0000:05:00.0: @37c80750 37c808f0 00000000 01000000 01018001
> Oct 6 15:17:36 xanatos kernel: [ 2165.955228] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.955230] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.955233] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.955235] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.955238] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.955240] xhci_hcd 0000:05:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
> Oct 6 15:17:36 xanatos kernel: [ 2165.955243] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.955245] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c80760 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.955248] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.955255] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c80768, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.955591] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.955593] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.955596] xhci_hcd 0000:05:00.0: @37c80760 37c80910 00000000 01000000 01018001
> Oct 6 15:17:36 xanatos kernel: [ 2165.955599] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.955602] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.955604] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.955606] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.955609] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.955611] xhci_hcd 0000:05:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
> Oct 6 15:17:36 xanatos kernel: [ 2165.955614] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.955616] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c80770 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.955619] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.955628] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c80778, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.955967] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.955970] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.955974] xhci_hcd 0000:05:00.0: @37c80770 37c80930 00000000 01000000 01018001
> Oct 6 15:17:36 xanatos kernel: [ 2165.955978] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.955982] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.955985] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.955988] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.955991] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.955994] xhci_hcd 0000:05:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
> Oct 6 15:17:36 xanatos kernel: [ 2165.955997] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.956001] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c80780 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.956003] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.956013] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c80788, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.956341] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.956343] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.956347] xhci_hcd 0000:05:00.0: @37c80780 37c80950 00000000 01000000 01018001
> Oct 6 15:17:36 xanatos kernel: [ 2165.956349] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.956352] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.956354] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.956357] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.956359] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.956362] xhci_hcd 0000:05:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
> Oct 6 15:17:36 xanatos kernel: [ 2165.956364] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.956367] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c80790 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.956369] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.956378] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c80798, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.956717] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.956719] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.956722] xhci_hcd 0000:05:00.0: @37c80790 37c80970 00000000 01000000 01018001
> Oct 6 15:17:36 xanatos kernel: [ 2165.956725] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.956728] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.956730] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.956733] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.956735] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.956738] xhci_hcd 0000:05:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
> Oct 6 15:17:36 xanatos kernel: [ 2165.956740] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.956743] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c807a0 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.956745] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.956754] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c807a8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.957344] xhci_hcd 0000:05:00.0: op reg status = 00000008
> Oct 6 15:17:36 xanatos kernel: [ 2165.957346] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
> Oct 6 15:17:36 xanatos kernel: [ 2165.957349] xhci_hcd 0000:05:00.0: @37c807a0 37c809a0 00000000 01000000 01018001
> Oct 6 15:17:36 xanatos kernel: [ 2165.957352] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
> Oct 6 15:17:36 xanatos kernel: [ 2165.957354] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.957356] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
> Oct 6 15:17:36 xanatos kernel: [ 2165.957359] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.957361] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.957364] xhci_hcd 0000:05:00.0: DMA address or buffer contents= 935856544
> Oct 6 15:17:36 xanatos kernel: [ 2165.957367] xhci_hcd 0000:05:00.0: Successful control transfer!
> Oct 6 15:17:36 xanatos kernel: [ 2165.957369] xhci_hcd 0000:05:00.0: Ring deq = 0x37c80990 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.957372] xhci_hcd 0000:05:00.0: Ring deq = 0x37c809a0 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.957374] xhci_hcd 0000:05:00.0: Ring deq = 0x37c809b0 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.957377] xhci_hcd 0000:05:00.0: Event ring deq = 0x37c807b0 (DMA)
> Oct 6 15:17:36 xanatos kernel: [ 2165.957380] xhci_hcd 0000:05:00.0: Giveback URB ffff880037cf7cc0, len = 8, status = 0
> Oct 6 15:17:36 xanatos kernel: [ 2165.957384] xhci_hcd 0000:05:00.0: xhci_handle_event - returned from handle_tx_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.957387] xhci_hcd 0000:05:00.0: In xhci_handle_event
> Oct 6 15:17:36 xanatos kernel: [ 2165.957396] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 64'hffffc90017360638, 64'h37c807b8, 4'hf);
>From 710709ba2b487bbfbd5f2c92dfe4a36604fcbf11 Mon Sep 17 00:00:00 2001
From: Sarah Sharp <sarah.a.sharp@xxxxxxxxxxxxxxx>
Date: Thu, 7 Oct 2010 15:30:04 -0700
Subject: [PATCH 1/2] xhci: Fix spurious control transfers after device reset.
Cc: linux-usb@xxxxxxxxxxxxxxx
Fix a bug introduced in the patch "xHCI: change xhci_reset_device() to
allocate new device". This patch caused control transfers to be replayed
after a device was reset by the usb-storage driver. Remove the field
"configured" in xhci_virt_device, and check fields in the slot context in
xhci_address_device() to determine whether the xHCI driver needs to set up
the slot and control endpoint 0 contexts.
This fixes messages about spurious events after a device reset:
Oct 6 15:17:36 xanatos kernel: [ 2165.937325] xhci_hcd 0000:05:00.0: Successful Address Device command
...
Oct 6 15:17:36 xanatos kernel: [ 2165.937471] xhci_hcd 0000:05:00.0: Slot ID 1 Output Context:
...
Oct 6 15:17:36 xanatos kernel: [ 2165.937501] xhci_hcd 0000:05:00.0: Endpoint 00 Context:
Oct 6 15:17:36 xanatos kernel: [ 2165.937503] xhci_hcd 0000:05:00.0: @ffff8800ad408020 (virt) @ad408020 (dma) 0x000001 - ep_info
Oct 6 15:17:36 xanatos kernel: [ 2165.937506] xhci_hcd 0000:05:00.0: @ffff8800ad408024 (virt) @ad408024 (dma) 0x2000026 - ep_info2
Oct 6 15:17:36 xanatos kernel: [ 2165.937510] xhci_hcd 0000:05:00.0: @ffff8800ad408028 (virt) @ad408028 (dma) 0x37c80801 - deq
Oct 6 15:17:36 xanatos kernel: [ 2165.937513] xhci_hcd 0000:05:00.0: @ffff8800ad408030 (virt) @ad408030 (dma) 0x000000 - tx_info
Oct 6 15:17:36 xanatos kernel: [ 2165.937516] xhci_hcd 0000:05:00.0: @ffff8800ad408034 (virt) @ad408034 (dma) 0x000000 - rsvd[0]
Oct 6 15:17:36 xanatos kernel: [ 2165.937519] xhci_hcd 0000:05:00.0: @ffff8800ad408038 (virt) @ad408038 (dma) 0x000000 - rsvd[1]
Oct 6 15:17:36 xanatos kernel: [ 2165.937522] xhci_hcd 0000:05:00.0: @ffff8800ad40803c (virt) @ad40803c (dma) 0x000000 - rsvd[2]
...
Oct 6 15:17:36 xanatos kernel: [ 2165.937576] usb 9-2: reset SuperSpeed USB device using xhci_hcd and address 2
Oct 6 15:17:36 xanatos kernel: [ 2165.952014] xhci_hcd 0000:05:00.0: Queueing ctrl tx for slot id 1, ep 0
Oct 6 15:17:36 xanatos kernel: [ 2165.952017] xhci_hcd 0000:05:00.0: Endpoint state = 0x1
Oct 6 15:17:36 xanatos kernel: [ 2165.952020] xhci_hcd 0000:05:00.0: Ring enq = 0x37c80990 (DMA)
Oct 6 15:17:36 xanatos kernel: [ 2165.952023] xhci_hcd 0000:05:00.0: Ring enq = 0x37c809a0 (DMA)
Oct 6 15:17:36 xanatos kernel: [ 2165.952025] xhci_hcd 0000:05:00.0: Ring enq = 0x37c809b0 (DMA)
Oct 6 15:17:36 xanatos kernel: [ 2165.952032] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360804, 32'h1, 4'hf);
Oct 6 15:17:36 xanatos kernel: [ 2165.952592] xhci_hcd 0000:05:00.0: op reg status = 00000008
Oct 6 15:17:36 xanatos kernel: [ 2165.952596] xhci_hcd 0000:05:00.0: Event ring dequeue ptr:
Oct 6 15:17:36 xanatos kernel: [ 2165.952600] xhci_hcd 0000:05:00.0: @37c806f0 37c80820 00000000 01000000 01018001
Oct 6 15:17:36 xanatos kernel: [ 2165.952604] xhci_hcd 0000:05:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90017360024, 32'h8, 4'hf);
Oct 6 15:17:36 xanatos kernel: [ 2165.952607] xhci_hcd 0000:05:00.0: In xhci_handle_event
Oct 6 15:17:36 xanatos kernel: [ 2165.952610] xhci_hcd 0000:05:00.0: xhci_handle_event - OS owns TRB
Oct 6 15:17:36 xanatos kernel: [ 2165.952614] xhci_hcd 0000:05:00.0: xhci_handle_event - calling handle_tx_event
Oct 6 15:17:36 xanatos kernel: [ 2165.952617] xhci_hcd 0000:05:00.0: handle_tx_event - ep index = 0
Oct 6 15:17:36 xanatos kernel: [ 2165.952621] xhci_hcd 0000:05:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
Signed-off-by: Sarah Sharp <sarah.a.sharp@xxxxxxxxxxxxxxx>
---
drivers/usb/host/xhci-mem.c | 1 -
drivers/usb/host/xhci.c | 13 ++++++++-----
drivers/usb/host/xhci.h | 2 --
3 files changed, 8 insertions(+), 8 deletions(-)
diff --git a/drivers/usb/host/xhci-mem.c b/drivers/usb/host/xhci-mem.c
index 0a8605a..2027706 100644
--- a/drivers/usb/host/xhci-mem.c
+++ b/drivers/usb/host/xhci-mem.c
@@ -779,7 +779,6 @@ int xhci_alloc_virt_device(struct xhci_hcd *xhci, int slot_id,
init_completion(&dev->cmd_completion);
INIT_LIST_HEAD(&dev->cmd_list);
dev->udev = udev;
- dev->configured = false;
/* Point to output device context in dcbaa. */
xhci->dcbaa->dev_context_ptrs[slot_id] = dev->out_ctx->dma;
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index cc54158..33d0034 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -1582,7 +1582,6 @@ int xhci_check_bandwidth(struct usb_hcd *hcd, struct usb_device *udev)
return ret;
}
- virt_dev->configured = true;
xhci_dbg(xhci, "Output context after successful config ep cmd:\n");
xhci_dbg_ctx(xhci, virt_dev->out_ctx,
LAST_CTX_TO_EP_NUM(slot_ctx->dev_info));
@@ -2264,7 +2263,6 @@ int xhci_discover_or_reset_device(struct usb_hcd *hcd, struct usb_device *udev)
goto command_cleanup;
case COMP_SUCCESS:
xhci_dbg(xhci, "Successful reset device command.\n");
- virt_dev->configured = false;
break;
default:
if (xhci_is_vendor_info_code(xhci, ret))
@@ -2417,12 +2415,17 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev)
virt_dev = xhci->devs[udev->slot_id];
- /* If this is a Set Address to an unconfigured device, setup ep 0 */
- if (!udev->config || !virt_dev->configured)
+ slot_ctx = xhci_get_slot_ctx(xhci, virt_dev->in_ctx);
+ /*
+ * If this is the first Set Address since device plug-in or
+ * virt_device realloaction after a resume with an xHCI power loss,
+ * then set up the slot context.
+ */
+ if (!slot_ctx->dev_info)
xhci_setup_addressable_virt_dev(xhci, udev);
+ /* Otherwise, update the control endpoint ring enqueue pointer. */
else
xhci_copy_ep0_dequeue_into_input_ctx(xhci, udev);
- /* Otherwise, assume the core has the device configured how it wants */
xhci_dbg(xhci, "Slot ID %d Input Context:\n", udev->slot_id);
xhci_dbg_ctx(xhci, virt_dev->in_ctx, 2);
diff --git a/drivers/usb/host/xhci.h b/drivers/usb/host/xhci.h
index d1c5266..c08928a 100644
--- a/drivers/usb/host/xhci.h
+++ b/drivers/usb/host/xhci.h
@@ -753,8 +753,6 @@ struct xhci_virt_device {
/* Rings saved to ensure old alt settings can be re-instated */
struct xhci_ring **ring_cache;
int num_rings_cached;
- /* Indicate whether the device is configured */
- bool configured;
/* Store xHC assigned device address */
int address;
#define XHCI_MAX_RINGS_CACHED 31
--
1.6.3.3
>From bec45e4eb35cec0fb98f1466e2563810ce5e6c86 Mon Sep 17 00:00:00 2001
From: Sarah Sharp <sarah.a.sharp@xxxxxxxxxxxxxxx>
Date: Fri, 8 Oct 2010 09:39:43 -0700
Subject: [PATCH 2/2] usb: Fix issue with USB 3.0 devices after system resume.
Cc: linux-usb@xxxxxxxxxxxxxxx
When the system suspends and a host controller's power is lost, the USB
core attempts to revive any USB devices that had the persist_enabled flag
set. For non-SuperSpeed devices, it will disable the port, and then set
the udev->reset_resume flag. This will cause the USB core to reset the
device, verify the device descriptors to make sure it's the same device,
and re-install any non-default configurations or alternate interface
settings.
However, we can't disable SuperSpeed root hub ports because that turns off
SuperSpeed terminations, which will inhibit any devices connecting at USB
3.0 speeds. (Plus external hubs don't allow SuperSpeed ports to be
disabled.)
Because of this logic in hub_activate():
/* We can forget about a "removed" device when there's a
* physical disconnect or the connect status changes.
*/
if (!(portstatus & USB_PORT_STAT_CONNECTION) ||
(portchange & USB_PORT_STAT_C_CONNECTION))
clear_bit(port1, hub->removed_bits);
if (!udev || udev->state == USB_STATE_NOTATTACHED) {
/* Tell khubd to disconnect the device or
* check for a new connection
*/
if (udev || (portstatus & USB_PORT_STAT_CONNECTION))
set_bit(port1, hub->change_bits);
} else if (portstatus & USB_PORT_STAT_ENABLE) {
/* The power session apparently survived the resume.
* If there was an overcurrent or suspend change
* (i.e., remote wakeup request), have khubd
* take care of it.
*/
if (portchange)
set_bit(port1, hub->change_bits);
} else if (udev->persist_enabled) {
udev->reset_resume = 1;
set_bit(port1, hub->change_bits);
} else {
/* The power session is gone; tell khubd */
usb_set_device_state(udev, USB_STATE_NOTATTACHED);
set_bit(port1, hub->change_bits);
}
a SuperSpeed device after a resume with a loss of power will never get the
reset_resume flag set. Instead the core will assume the power session
survived and that the device still has the same address, configuration,
and alternate interface settings. The xHCI host controller will have no
knowledge of the device (since all xhci_virt_devices were destroyed when
power loss was discovered, and xhci_discover_or_reset_device() has not
been called), and all URBs to the device will fail.
If the device driver responds by resetting the device, everything will
continue smoothly. However, if lsusb is used before the device driver
resets the device (or there is no driver), then all lsusb descriptor
fetches will fail.
The quick fix is to pretend the port is disabled in hub_activate(), by
clearing the local variable. But I'm not sure what other parts of the hub
driver need to be changed because they have assumptions about when ports
will be disabled.
Signed-off-by: Sarah Sharp <sarah.a.sharp@xxxxxxxxxxxxxxx>
---
drivers/usb/core/hub.c | 3 +++
1 files changed, 3 insertions(+), 0 deletions(-)
diff --git a/drivers/usb/core/hub.c b/drivers/usb/core/hub.c
index 6035fe3..b5f46fb 100644
--- a/drivers/usb/core/hub.c
+++ b/drivers/usb/core/hub.c
@@ -758,6 +758,9 @@ static void hub_activate(struct usb_hub *hub, enum hub_activation_type type)
clear_port_feature(hdev, port1,
USB_PORT_FEAT_ENABLE);
portstatus &= ~USB_PORT_STAT_ENABLE;
+ } else {
+ /* Pretend that power was lost for USB3 devs */
+ portstatus &= ~USB_PORT_STAT_ENABLE;
}
}
--
1.6.3.3
