USB: xhci: Make debugging more verbose.

Add more debugging to the irq handler, slot context initialization, ring
operations, URB cancellation, and MMIO writes.

Signed-off-by: Sarah Sharp <sarah.a.sharp@linux.intel.com>
Signed-off-by: Greg Kroah-Hartman <gregkh@suse.de>
This commit is contained in:
Sarah Sharp 2009-07-27 12:03:46 -07:00 committed by Greg Kroah-Hartman
parent 2d83109be6
commit 66e49d8774
3 changed files with 72 additions and 24 deletions

View File

@ -267,8 +267,10 @@ irqreturn_t xhci_irq(struct usb_hcd *hcd)
{ {
struct xhci_hcd *xhci = hcd_to_xhci(hcd); struct xhci_hcd *xhci = hcd_to_xhci(hcd);
u32 temp, temp2; u32 temp, temp2;
union xhci_trb *trb;
spin_lock(&xhci->lock); spin_lock(&xhci->lock);
trb = xhci->event_ring->dequeue;
/* Check if the xHC generated the interrupt, or the irq is shared */ /* Check if the xHC generated the interrupt, or the irq is shared */
temp = xhci_readl(xhci, &xhci->op_regs->status); temp = xhci_readl(xhci, &xhci->op_regs->status);
temp2 = xhci_readl(xhci, &xhci->ir_set->irq_pending); temp2 = xhci_readl(xhci, &xhci->ir_set->irq_pending);
@ -276,6 +278,15 @@ irqreturn_t xhci_irq(struct usb_hcd *hcd)
spin_unlock(&xhci->lock); spin_unlock(&xhci->lock);
return IRQ_NONE; return IRQ_NONE;
} }
xhci_dbg(xhci, "op reg status = %08x\n", temp);
xhci_dbg(xhci, "ir set irq_pending = %08x\n", temp2);
xhci_dbg(xhci, "Event ring dequeue ptr:\n");
xhci_dbg(xhci, "@%llx %08x %08x %08x %08x\n",
(unsigned long long)xhci_trb_virt_to_dma(xhci->event_ring->deq_seg, trb),
lower_32_bits(trb->link.segment_ptr),
upper_32_bits(trb->link.segment_ptr),
(unsigned int) trb->link.intr_target,
(unsigned int) trb->link.control);
if (temp & STS_FATAL) { if (temp & STS_FATAL) {
xhci_warn(xhci, "WARNING: Host System Error\n"); xhci_warn(xhci, "WARNING: Host System Error\n");
@ -385,6 +396,20 @@ int xhci_run(struct usb_hcd *hcd)
add_timer(&xhci->event_ring_timer); add_timer(&xhci->event_ring_timer);
#endif #endif
xhci_dbg(xhci, "Command ring memory map follows:\n");
xhci_debug_ring(xhci, xhci->cmd_ring);
xhci_dbg_ring_ptrs(xhci, xhci->cmd_ring);
xhci_dbg_cmd_ptrs(xhci);
xhci_dbg(xhci, "ERST memory map follows:\n");
xhci_dbg_erst(xhci, &xhci->erst);
xhci_dbg(xhci, "Event ring:\n");
xhci_debug_ring(xhci, xhci->event_ring);
xhci_dbg_ring_ptrs(xhci, xhci->event_ring);
temp_64 = xhci_read_64(xhci, &xhci->ir_set->erst_dequeue);
temp_64 &= ~ERST_PTR_MASK;
xhci_dbg(xhci, "ERST deq = 64'h%0lx\n", (long unsigned int) temp_64);
xhci_dbg(xhci, "// Set the interrupt modulation register\n"); xhci_dbg(xhci, "// Set the interrupt modulation register\n");
temp = xhci_readl(xhci, &xhci->ir_set->irq_control); temp = xhci_readl(xhci, &xhci->ir_set->irq_control);
temp &= ~ER_IRQ_INTERVAL_MASK; temp &= ~ER_IRQ_INTERVAL_MASK;
@ -409,20 +434,6 @@ int xhci_run(struct usb_hcd *hcd)
if (NUM_TEST_NOOPS > 0) if (NUM_TEST_NOOPS > 0)
doorbell = xhci_setup_one_noop(xhci); doorbell = xhci_setup_one_noop(xhci);
xhci_dbg(xhci, "Command ring memory map follows:\n");
xhci_debug_ring(xhci, xhci->cmd_ring);
xhci_dbg_ring_ptrs(xhci, xhci->cmd_ring);
xhci_dbg_cmd_ptrs(xhci);
xhci_dbg(xhci, "ERST memory map follows:\n");
xhci_dbg_erst(xhci, &xhci->erst);
xhci_dbg(xhci, "Event ring:\n");
xhci_debug_ring(xhci, xhci->event_ring);
xhci_dbg_ring_ptrs(xhci, xhci->event_ring);
temp_64 = xhci_read_64(xhci, &xhci->ir_set->erst_dequeue);
temp_64 &= ~ERST_PTR_MASK;
xhci_dbg(xhci, "ERST deq = 64'h%0lx\n", (long unsigned int) temp_64);
temp = xhci_readl(xhci, &xhci->op_regs->command); temp = xhci_readl(xhci, &xhci->op_regs->command);
temp |= (CMD_RUN); temp |= (CMD_RUN);
xhci_dbg(xhci, "// Turn on HC, cmd = 0x%x.\n", xhci_dbg(xhci, "// Turn on HC, cmd = 0x%x.\n",
@ -665,8 +676,12 @@ int xhci_urb_dequeue(struct usb_hcd *hcd, struct urb *urb, int status)
goto done; goto done;
xhci_dbg(xhci, "Cancel URB %p\n", urb); xhci_dbg(xhci, "Cancel URB %p\n", urb);
xhci_dbg(xhci, "Event ring:\n");
xhci_debug_ring(xhci, xhci->event_ring);
ep_index = xhci_get_endpoint_index(&urb->ep->desc); ep_index = xhci_get_endpoint_index(&urb->ep->desc);
ep_ring = xhci->devs[urb->dev->slot_id]->ep_rings[ep_index]; ep_ring = xhci->devs[urb->dev->slot_id]->ep_rings[ep_index];
xhci_dbg(xhci, "Endpoint ring:\n");
xhci_debug_ring(xhci, ep_ring);
td = (struct xhci_td *) urb->hcpriv; td = (struct xhci_td *) urb->hcpriv;
ep_ring->cancels_pending++; ep_ring->cancels_pending++;
@ -1178,6 +1193,8 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev)
if (!udev->config) if (!udev->config)
xhci_setup_addressable_virt_dev(xhci, udev); xhci_setup_addressable_virt_dev(xhci, udev);
/* Otherwise, assume the core has the device configured how it wants */ /* 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, virt_dev->in_ctx_dma, 2);
spin_lock_irqsave(&xhci->lock, flags); spin_lock_irqsave(&xhci->lock, flags);
ret = xhci_queue_address_device(xhci, virt_dev->in_ctx_dma, ret = xhci_queue_address_device(xhci, virt_dev->in_ctx_dma,
@ -1221,6 +1238,8 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev)
default: default:
xhci_err(xhci, "ERROR: unexpected command completion " xhci_err(xhci, "ERROR: unexpected command completion "
"code 0x%x.\n", virt_dev->cmd_status); "code 0x%x.\n", virt_dev->cmd_status);
xhci_dbg(xhci, "Slot ID %d Output Context:\n", udev->slot_id);
xhci_dbg_ctx(xhci, virt_dev->out_ctx, virt_dev->out_ctx_dma, 2);
ret = -EINVAL; ret = -EINVAL;
break; break;
} }

View File

@ -135,6 +135,7 @@ static void next_trb(struct xhci_hcd *xhci,
static void inc_deq(struct xhci_hcd *xhci, struct xhci_ring *ring, bool consumer) static void inc_deq(struct xhci_hcd *xhci, struct xhci_ring *ring, bool consumer)
{ {
union xhci_trb *next = ++(ring->dequeue); union xhci_trb *next = ++(ring->dequeue);
unsigned long long addr;
ring->deq_updates++; ring->deq_updates++;
/* Update the dequeue pointer further if that was a link TRB or we're at /* Update the dequeue pointer further if that was a link TRB or we're at
@ -152,6 +153,13 @@ static void inc_deq(struct xhci_hcd *xhci, struct xhci_ring *ring, bool consumer
ring->dequeue = ring->deq_seg->trbs; ring->dequeue = ring->deq_seg->trbs;
next = ring->dequeue; next = ring->dequeue;
} }
addr = (unsigned long long) xhci_trb_virt_to_dma(ring->deq_seg, ring->dequeue);
if (ring == xhci->event_ring)
xhci_dbg(xhci, "Event ring deq = 0x%llx (DMA)\n", addr);
else if (ring == xhci->cmd_ring)
xhci_dbg(xhci, "Command ring deq = 0x%llx (DMA)\n", addr);
else
xhci_dbg(xhci, "Ring deq = 0x%llx (DMA)\n", addr);
} }
/* /*
@ -171,6 +179,7 @@ static void inc_enq(struct xhci_hcd *xhci, struct xhci_ring *ring, bool consumer
{ {
u32 chain; u32 chain;
union xhci_trb *next; union xhci_trb *next;
unsigned long long addr;
chain = ring->enqueue->generic.field[3] & TRB_CHAIN; chain = ring->enqueue->generic.field[3] & TRB_CHAIN;
next = ++(ring->enqueue); next = ++(ring->enqueue);
@ -204,6 +213,13 @@ static void inc_enq(struct xhci_hcd *xhci, struct xhci_ring *ring, bool consumer
ring->enqueue = ring->enq_seg->trbs; ring->enqueue = ring->enq_seg->trbs;
next = ring->enqueue; next = ring->enqueue;
} }
addr = (unsigned long long) xhci_trb_virt_to_dma(ring->enq_seg, ring->enqueue);
if (ring == xhci->event_ring)
xhci_dbg(xhci, "Event ring enq = 0x%llx (DMA)\n", addr);
else if (ring == xhci->cmd_ring)
xhci_dbg(xhci, "Command ring enq = 0x%llx (DMA)\n", addr);
else
xhci_dbg(xhci, "Ring enq = 0x%llx (DMA)\n", addr);
} }
/* /*
@ -252,8 +268,7 @@ void xhci_set_hc_event_deq(struct xhci_hcd *xhci)
* there might be more events to service. * there might be more events to service.
*/ */
temp &= ~ERST_EHB; temp &= ~ERST_EHB;
if (!in_interrupt()) xhci_dbg(xhci, "// Write event ring dequeue pointer, preserving EHB bit\n");
xhci_dbg(xhci, "// Write event ring dequeue pointer, preserving EHB bit\n");
xhci_write_64(xhci, ((u64) deq & (u64) ~ERST_PTR_MASK) | temp, xhci_write_64(xhci, ((u64) deq & (u64) ~ERST_PTR_MASK) | temp,
&xhci->ir_set->erst_dequeue); &xhci->ir_set->erst_dequeue);
} }
@ -781,6 +796,7 @@ static int handle_tx_event(struct xhci_hcd *xhci,
struct urb *urb = 0; struct urb *urb = 0;
int status = -EINPROGRESS; int status = -EINPROGRESS;
xhci_dbg(xhci, "In %s\n", __func__);
xdev = xhci->devs[TRB_TO_SLOT_ID(event->flags)]; xdev = xhci->devs[TRB_TO_SLOT_ID(event->flags)];
if (!xdev) { if (!xdev) {
xhci_err(xhci, "ERROR Transfer event pointed to bad slot\n"); xhci_err(xhci, "ERROR Transfer event pointed to bad slot\n");
@ -789,6 +805,7 @@ static int handle_tx_event(struct xhci_hcd *xhci,
/* Endpoint ID is 1 based, our index is zero based */ /* Endpoint ID is 1 based, our index is zero based */
ep_index = TRB_TO_EP_ID(event->flags) - 1; ep_index = TRB_TO_EP_ID(event->flags) - 1;
xhci_dbg(xhci, "%s - ep index = %d\n", __func__, ep_index);
ep_ring = xdev->ep_rings[ep_index]; ep_ring = xdev->ep_rings[ep_index];
if (!ep_ring || (xdev->out_ctx->ep[ep_index].ep_info & EP_STATE_MASK) == EP_STATE_DISABLED) { if (!ep_ring || (xdev->out_ctx->ep[ep_index].ep_info & EP_STATE_MASK) == EP_STATE_DISABLED) {
xhci_err(xhci, "ERROR Transfer event pointed to disabled endpoint\n"); xhci_err(xhci, "ERROR Transfer event pointed to disabled endpoint\n");
@ -797,6 +814,7 @@ static int handle_tx_event(struct xhci_hcd *xhci,
event_dma = event->buffer; event_dma = event->buffer;
/* This TRB should be in the TD at the head of this ring's TD list */ /* This TRB should be in the TD at the head of this ring's TD list */
xhci_dbg(xhci, "%s - checking for list empty\n", __func__);
if (list_empty(&ep_ring->td_list)) { if (list_empty(&ep_ring->td_list)) {
xhci_warn(xhci, "WARN Event TRB for slot %d ep %d with no TDs queued?\n", xhci_warn(xhci, "WARN Event TRB for slot %d ep %d with no TDs queued?\n",
TRB_TO_SLOT_ID(event->flags), ep_index); TRB_TO_SLOT_ID(event->flags), ep_index);
@ -806,11 +824,14 @@ static int handle_tx_event(struct xhci_hcd *xhci,
urb = NULL; urb = NULL;
goto cleanup; goto cleanup;
} }
xhci_dbg(xhci, "%s - getting list entry\n", __func__);
td = list_entry(ep_ring->td_list.next, struct xhci_td, td_list); td = list_entry(ep_ring->td_list.next, struct xhci_td, td_list);
/* Is this a TRB in the currently executing TD? */ /* Is this a TRB in the currently executing TD? */
xhci_dbg(xhci, "%s - looking for TD\n", __func__);
event_seg = trb_in_td(ep_ring->deq_seg, ep_ring->dequeue, event_seg = trb_in_td(ep_ring->deq_seg, ep_ring->dequeue,
td->last_trb, event_dma); td->last_trb, event_dma);
xhci_dbg(xhci, "%s - found event_seg = %p\n", __func__, event_seg);
if (!event_seg) { if (!event_seg) {
/* HC is busted, give up! */ /* HC is busted, give up! */
xhci_err(xhci, "ERROR Transfer event TRB DMA ptr not part of current TD\n"); xhci_err(xhci, "ERROR Transfer event TRB DMA ptr not part of current TD\n");
@ -1027,6 +1048,8 @@ static int handle_tx_event(struct xhci_hcd *xhci,
/* FIXME for multi-TD URBs (who have buffers bigger than 64MB) */ /* FIXME for multi-TD URBs (who have buffers bigger than 64MB) */
if (urb) { if (urb) {
usb_hcd_unlink_urb_from_ep(xhci_to_hcd(xhci), urb); usb_hcd_unlink_urb_from_ep(xhci_to_hcd(xhci), urb);
xhci_dbg(xhci, "Giveback URB %p, len = %d, status = %d\n",
urb, td->urb->actual_length, status);
spin_unlock(&xhci->lock); spin_unlock(&xhci->lock);
usb_hcd_giveback_urb(xhci_to_hcd(xhci), urb, status); usb_hcd_giveback_urb(xhci_to_hcd(xhci), urb, status);
spin_lock(&xhci->lock); spin_lock(&xhci->lock);
@ -1044,6 +1067,7 @@ void xhci_handle_event(struct xhci_hcd *xhci)
int update_ptrs = 1; int update_ptrs = 1;
int ret; int ret;
xhci_dbg(xhci, "In %s\n", __func__);
if (!xhci->event_ring || !xhci->event_ring->dequeue) { if (!xhci->event_ring || !xhci->event_ring->dequeue) {
xhci->error_bitmask |= 1 << 1; xhci->error_bitmask |= 1 << 1;
return; return;
@ -1056,18 +1080,25 @@ void xhci_handle_event(struct xhci_hcd *xhci)
xhci->error_bitmask |= 1 << 2; xhci->error_bitmask |= 1 << 2;
return; return;
} }
xhci_dbg(xhci, "%s - OS owns TRB\n", __func__);
/* FIXME: Handle more event types. */ /* FIXME: Handle more event types. */
switch ((event->event_cmd.flags & TRB_TYPE_BITMASK)) { switch ((event->event_cmd.flags & TRB_TYPE_BITMASK)) {
case TRB_TYPE(TRB_COMPLETION): case TRB_TYPE(TRB_COMPLETION):
xhci_dbg(xhci, "%s - calling handle_cmd_completion\n", __func__);
handle_cmd_completion(xhci, &event->event_cmd); handle_cmd_completion(xhci, &event->event_cmd);
xhci_dbg(xhci, "%s - returned from handle_cmd_completion\n", __func__);
break; break;
case TRB_TYPE(TRB_PORT_STATUS): case TRB_TYPE(TRB_PORT_STATUS):
xhci_dbg(xhci, "%s - calling handle_port_status\n", __func__);
handle_port_status(xhci, event); handle_port_status(xhci, event);
xhci_dbg(xhci, "%s - returned from handle_port_status\n", __func__);
update_ptrs = 0; update_ptrs = 0;
break; break;
case TRB_TYPE(TRB_TRANSFER): case TRB_TYPE(TRB_TRANSFER):
xhci_dbg(xhci, "%s - calling handle_tx_event\n", __func__);
ret = handle_tx_event(xhci, &event->trans_event); ret = handle_tx_event(xhci, &event->trans_event);
xhci_dbg(xhci, "%s - returned from handle_tx_event\n", __func__);
if (ret < 0) if (ret < 0)
xhci->error_bitmask |= 1 << 9; xhci->error_bitmask |= 1 << 9;
else else

View File

@ -1065,10 +1065,9 @@ static inline unsigned int xhci_readl(const struct xhci_hcd *xhci,
static inline void xhci_writel(struct xhci_hcd *xhci, static inline void xhci_writel(struct xhci_hcd *xhci,
const unsigned int val, __u32 __iomem *regs) const unsigned int val, __u32 __iomem *regs)
{ {
if (!in_interrupt()) xhci_dbg(xhci,
xhci_dbg(xhci, "`MEM_WRITE_DWORD(3'b000, 32'h%p, 32'h%0x, 4'hf);\n",
"`MEM_WRITE_DWORD(3'b000, 32'h%p, 32'h%0x, 4'hf);\n", regs, val);
regs, val);
writel(val, regs); writel(val, regs);
} }
@ -1096,10 +1095,9 @@ static inline void xhci_write_64(struct xhci_hcd *xhci,
u32 val_lo = lower_32_bits(val); u32 val_lo = lower_32_bits(val);
u32 val_hi = upper_32_bits(val); u32 val_hi = upper_32_bits(val);
if (!in_interrupt()) xhci_dbg(xhci,
xhci_dbg(xhci, "`MEM_WRITE_DWORD(3'b000, 64'h%p, 64'h%0lx, 4'hf);\n",
"`MEM_WRITE_DWORD(3'b000, 64'h%p, 64'h%0lx, 4'hf);\n", regs, (long unsigned int) val);
regs, (long unsigned int) val);
writel(val_lo, ptr); writel(val_lo, ptr);
writel(val_hi, ptr + 1); writel(val_hi, ptr + 1);
} }