On Thu, Nov 03, 2011 at 06:18:24PM +1100, Matt wrote: > Hi Sarah, > > On 3/11/2011 6:02 AM, Sarah Sharp wrote: > >Ok, the xHCI driver code already has a warning message about disabled > >endpoints that's split out when a driver attempts to submit an URB to a > >disabled endpoint: > > > > > > xhci_warn(xhci, "WARN urb submitted to disabled ep\n"); > > > > > I've re-run dmesg and, to stop it scrolling away, I took a capture > of dmesg every 100ms (1 second lost data) then recombined the files > together. I'm sure there's a more elegant way to do it but I lack > the coding skills :-) tail -f /var/log/kern.log | tee dmesg.log This works if you're on a debian based system, otherwise you might need to pull from /var/log/messages. Just ctrl+c to kill it when you're done. Or you can just copy lines from those log files directly into a new temporary file. :) > I can confirm, however, that the log is complete from beginning to > end as the files provide overlap and therefore confidence that I > have captured every line. I've uploaded the output here: > http://pastebin.com/raw.php?i=0ZcNKG5E > > The error you mention above is never issued. > > Does the output offer any clues or is there any other debugging I can do? I think I see where the error is (or at least the first error, anyway): [ 223.701839] xhci_hcd 0000:03:00.0: Slot ID 1 Input Context: [ 223.701841] xhci_hcd 0000:03:00.0: @ffff880137b25000 (virt) @ffffc000 (dma) 0x000000 - drop flags [ 223.701843] xhci_hcd 0000:03:00.0: @ffff880137b25004 (virt) @ffffc004 (dma) 0x000000 - add flags ... [ 223.701927] xhci_hcd 0000:03:00.0: // Ding dong! [ 223.701992] xhci_hcd 0000:03:00.0: Setup ERROR: address device command for slot 1. Those add flags are supposed to be 0x3, to indicate that the slot and endpoint zero contexts are valid. The AsMedia host is responding with a Context Error, probably because it doesn't like the flags being cleared. Can you try applying the attached patch and post the full dmesg? Sarah Sharp
>From 79bd6b22aa5a1709b0a3e7bc6383b670dce0f3ca Mon Sep 17 00:00:00 2001 From: Sarah Sharp <sarah.a.sharp@xxxxxxxxxxxxxxx> Date: Thu, 3 Nov 2011 13:06:08 -0700 Subject: [PATCH] xhci: Set slot and ep0 flags for address command. Matt's AsMedia xHCI host controller was responding with a Context Error to an address device command after a configured device reset. Some sequence of events leads both the slot and endpoint zero add flags cleared to zero, which the AsMedia host doesn't like: [ 223.701839] xhci_hcd 0000:03:00.0: Slot ID 1 Input Context: [ 223.701841] xhci_hcd 0000:03:00.0: @ffff880137b25000 (virt) @ffffc000 (dma) 0x000000 - drop flags [ 223.701843] xhci_hcd 0000:03:00.0: @ffff880137b25004 (virt) @ffffc004 (dma) 0x000000 - add flags [ 223.701846] xhci_hcd 0000:03:00.0: @ffff880137b25008 (virt) @ffffc008 (dma) 0x000000 - rsvd2[0] [ 223.701848] xhci_hcd 0000:03:00.0: @ffff880137b2500c (virt) @ffffc00c (dma) 0x000000 - rsvd2[1] [ 223.701850] xhci_hcd 0000:03:00.0: @ffff880137b25010 (virt) @ffffc010 (dma) 0x000000 - rsvd2[2] [ 223.701852] xhci_hcd 0000:03:00.0: @ffff880137b25014 (virt) @ffffc014 (dma) 0x000000 - rsvd2[3] [ 223.701854] xhci_hcd 0000:03:00.0: @ffff880137b25018 (virt) @ffffc018 (dma) 0x000000 - rsvd2[4] [ 223.701857] xhci_hcd 0000:03:00.0: @ffff880137b2501c (virt) @ffffc01c (dma) 0x000000 - rsvd2[5] [ 223.701858] xhci_hcd 0000:03:00.0: Slot Context: [ 223.701860] xhci_hcd 0000:03:00.0: @ffff880137b25020 (virt) @ffffc020 (dma) 0x8400000 - dev_info [ 223.701862] xhci_hcd 0000:03:00.0: @ffff880137b25024 (virt) @ffffc024 (dma) 0x010000 - dev_info2 [ 223.701864] xhci_hcd 0000:03:00.0: @ffff880137b25028 (virt) @ffffc028 (dma) 0x000000 - tt_info [ 223.701866] xhci_hcd 0000:03:00.0: @ffff880137b2502c (virt) @ffffc02c (dma) 0x000000 - dev_state [ 223.701869] xhci_hcd 0000:03:00.0: @ffff880137b25030 (virt) @ffffc030 (dma) 0x000000 - rsvd[0] [ 223.701871] xhci_hcd 0000:03:00.0: @ffff880137b25034 (virt) @ffffc034 (dma) 0x000000 - rsvd[1] [ 223.701873] xhci_hcd 0000:03:00.0: @ffff880137b25038 (virt) @ffffc038 (dma) 0x000000 - rsvd[2] [ 223.701875] xhci_hcd 0000:03:00.0: @ffff880137b2503c (virt) @ffffc03c (dma) 0x000000 - rsvd[3] [ 223.701877] xhci_hcd 0000:03:00.0: Endpoint 00 Context: [ 223.701879] xhci_hcd 0000:03:00.0: @ffff880137b25040 (virt) @ffffc040 (dma) 0x000000 - ep_info [ 223.701881] xhci_hcd 0000:03:00.0: @ffff880137b25044 (virt) @ffffc044 (dma) 0x2000026 - ep_info2 [ 223.701883] xhci_hcd 0000:03:00.0: @ffff880137b25048 (virt) @ffffc048 (dma) 0xffffe8e0 - deq [ 223.701885] xhci_hcd 0000:03:00.0: @ffff880137b25050 (virt) @ffffc050 (dma) 0x000000 - tx_info [ 223.701887] xhci_hcd 0000:03:00.0: @ffff880137b25054 (virt) @ffffc054 (dma) 0x000000 - rsvd[0] [ 223.701889] xhci_hcd 0000:03:00.0: @ffff880137b25058 (virt) @ffffc058 (dma) 0x000000 - rsvd[1] [ 223.701892] xhci_hcd 0000:03:00.0: @ffff880137b2505c (virt) @ffffc05c (dma) 0x000000 - rsvd[2] [ 223.701893] xhci_hcd 0000:03:00.0: Endpoint 01 Context: [ 223.701895] xhci_hcd 0000:03:00.0: @ffff880137b25060 (virt) @ffffc060 (dma) 0x000000 - ep_info [ 223.701897] xhci_hcd 0000:03:00.0: @ffff880137b25064 (virt) @ffffc064 (dma) 0x000000 - ep_info2 [ 223.701899] xhci_hcd 0000:03:00.0: @ffff880137b25068 (virt) @ffffc068 (dma) 0x000000 - deq [ 223.701901] xhci_hcd 0000:03:00.0: @ffff880137b25070 (virt) @ffffc070 (dma) 0x000000 - tx_info [ 223.701904] xhci_hcd 0000:03:00.0: @ffff880137b25074 (virt) @ffffc074 (dma) 0x000000 - rsvd[0] [ 223.701906] xhci_hcd 0000:03:00.0: @ffff880137b25078 (virt) @ffffc078 (dma) 0x000000 - rsvd[1] [ 223.701908] xhci_hcd 0000:03:00.0: @ffff880137b2507c (virt) @ffffc07c (dma) 0x000000 - rsvd[2] [ 223.701910] xhci_hcd 0000:03:00.0: Endpoint 02 Context: [ 223.701912] xhci_hcd 0000:03:00.0: @ffff880137b25080 (virt) @ffffc080 (dma) 0x000000 - ep_info [ 223.701914] xhci_hcd 0000:03:00.0: @ffff880137b25084 (virt) @ffffc084 (dma) 0x000000 - ep_info2 [ 223.701916] xhci_hcd 0000:03:00.0: @ffff880137b25088 (virt) @ffffc088 (dma) 0x000000 - deq [ 223.701918] xhci_hcd 0000:03:00.0: @ffff880137b25090 (virt) @ffffc090 (dma) 0x000000 - tx_info [ 223.701920] xhci_hcd 0000:03:00.0: @ffff880137b25094 (virt) @ffffc094 (dma) 0x000000 - rsvd[0] [ 223.701922] xhci_hcd 0000:03:00.0: @ffff880137b25098 (virt) @ffffc098 (dma) 0x000000 - rsvd[1] [ 223.701925] xhci_hcd 0000:03:00.0: @ffff880137b2509c (virt) @ffffc09c (dma) 0x000000 - rsvd[2] [ 223.701927] xhci_hcd 0000:03:00.0: // Ding dong! [ 223.701992] xhci_hcd 0000:03:00.0: Setup ERROR: address device command for slot 1. The xHCI spec says that both flags must be set to one for the Address Device command. When the device is first enumerated, xhci_setup_addressable_virt_dev() does set those flags. However, when the device is addressed after it has been reset in the configured state, xhci_setup_addressable_virt_dev() is not called, and xhci_copy_ep0_dequeue_into_input_ctx() is called instead. That function relies on the flags being set up by previous commands, which apparently isn't a good assumption. Move the setting of the flags into the common parent function. Signed-off-by: Sarah Sharp <sarah.a.sharp@xxxxxxxxxxxxxxx> Cc: Matt <mdm@xxxxxxxxxxxx> --- drivers/usb/host/xhci-mem.c | 5 ----- drivers/usb/host/xhci.c | 5 ++++- 2 files changed, 4 insertions(+), 6 deletions(-) diff --git a/drivers/usb/host/xhci-mem.c b/drivers/usb/host/xhci-mem.c index 42a22b8..0e4b25f 100644 --- a/drivers/usb/host/xhci-mem.c +++ b/drivers/usb/host/xhci-mem.c @@ -982,7 +982,6 @@ int xhci_setup_addressable_virt_dev(struct xhci_hcd *xhci, struct usb_device *ud struct xhci_virt_device *dev; struct xhci_ep_ctx *ep0_ctx; struct xhci_slot_ctx *slot_ctx; - struct xhci_input_control_ctx *ctrl_ctx; u32 port_num; struct usb_device *top_dev; @@ -994,12 +993,8 @@ int xhci_setup_addressable_virt_dev(struct xhci_hcd *xhci, struct usb_device *ud return -EINVAL; } ep0_ctx = xhci_get_ep_ctx(xhci, dev->in_ctx, 0); - ctrl_ctx = xhci_get_input_control_ctx(xhci, dev->in_ctx); slot_ctx = xhci_get_slot_ctx(xhci, dev->in_ctx); - /* 2) New slot context and endpoint 0 context are valid*/ - ctrl_ctx->add_flags = cpu_to_le32(SLOT_FLAG | EP0_FLAG); - /* 3) Only the control endpoint is valid - one endpoint context */ slot_ctx->dev_info |= cpu_to_le32(LAST_CTX(1) | udev->route); switch (udev->speed) { diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c index 1ff95a0..747c5ea 100644 --- a/drivers/usb/host/xhci.c +++ b/drivers/usb/host/xhci.c @@ -3504,6 +3504,10 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev) /* Otherwise, update the control endpoint ring enqueue pointer. */ else xhci_copy_ep0_dequeue_into_input_ctx(xhci, udev); + ctrl_ctx = xhci_get_input_control_ctx(xhci, virt_dev->in_ctx); + ctrl_ctx->add_flags = cpu_to_le32(SLOT_FLAG | EP0_FLAG); + ctrl_ctx->drop_flags = 0; + xhci_dbg(xhci, "Slot ID %d Input Context:\n", udev->slot_id); xhci_dbg_ctx(xhci, virt_dev->in_ctx, 2); @@ -3585,7 +3589,6 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev) virt_dev->address = (le32_to_cpu(slot_ctx->dev_state) & DEV_ADDR_MASK) + 1; /* Zero the input context control for later use */ - ctrl_ctx = xhci_get_input_control_ctx(xhci, virt_dev->in_ctx); ctrl_ctx->add_flags = 0; ctrl_ctx->drop_flags = 0; -- 1.7.5.4