From 66e49d8774fa03539713e8f91169c37c05df1e94 Mon Sep 17 00:00:00 2001 From: Sarah Sharp Date: Mon, 27 Jul 2009 12:03:46 -0700 Subject: [PATCH] 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 Signed-off-by: Greg Kroah-Hartman --- drivers/usb/host/xhci-hcd.c | 47 +++++++++++++++++++++++++----------- drivers/usb/host/xhci-ring.c | 35 +++++++++++++++++++++++++-- drivers/usb/host/xhci.h | 14 +++++------ 3 files changed, 72 insertions(+), 24 deletions(-) diff --git a/drivers/usb/host/xhci-hcd.c b/drivers/usb/host/xhci-hcd.c index 2e8e5bf6b6c..764995fd59e 100644 --- a/drivers/usb/host/xhci-hcd.c +++ b/drivers/usb/host/xhci-hcd.c @@ -267,8 +267,10 @@ irqreturn_t xhci_irq(struct usb_hcd *hcd) { struct xhci_hcd *xhci = hcd_to_xhci(hcd); u32 temp, temp2; + union xhci_trb *trb; spin_lock(&xhci->lock); + trb = xhci->event_ring->dequeue; /* Check if the xHC generated the interrupt, or the irq is shared */ temp = xhci_readl(xhci, &xhci->op_regs->status); 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); 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) { 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); #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"); temp = xhci_readl(xhci, &xhci->ir_set->irq_control); temp &= ~ER_IRQ_INTERVAL_MASK; @@ -409,20 +434,6 @@ int xhci_run(struct usb_hcd *hcd) if (NUM_TEST_NOOPS > 0) 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 |= (CMD_RUN); 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; 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_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; ep_ring->cancels_pending++; @@ -1178,6 +1193,8 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev) if (!udev->config) xhci_setup_addressable_virt_dev(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, virt_dev->in_ctx_dma, 2); spin_lock_irqsave(&xhci->lock, flags); 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: xhci_err(xhci, "ERROR: unexpected command completion " "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; break; } diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c index fe9541a89a3..1fc0decfa0a 100644 --- a/drivers/usb/host/xhci-ring.c +++ b/drivers/usb/host/xhci-ring.c @@ -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) { union xhci_trb *next = ++(ring->dequeue); + unsigned long long addr; ring->deq_updates++; /* 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; 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; union xhci_trb *next; + unsigned long long addr; chain = ring->enqueue->generic.field[3] & TRB_CHAIN; 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; 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. */ 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->ir_set->erst_dequeue); } @@ -781,6 +796,7 @@ static int handle_tx_event(struct xhci_hcd *xhci, struct urb *urb = 0; int status = -EINPROGRESS; + xhci_dbg(xhci, "In %s\n", __func__); xdev = xhci->devs[TRB_TO_SLOT_ID(event->flags)]; if (!xdev) { 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 */ 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]; 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"); @@ -797,6 +814,7 @@ static int handle_tx_event(struct xhci_hcd *xhci, event_dma = event->buffer; /* 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)) { xhci_warn(xhci, "WARN Event TRB for slot %d ep %d with no TDs queued?\n", TRB_TO_SLOT_ID(event->flags), ep_index); @@ -806,11 +824,14 @@ static int handle_tx_event(struct xhci_hcd *xhci, urb = NULL; goto cleanup; } + xhci_dbg(xhci, "%s - getting list entry\n", __func__); td = list_entry(ep_ring->td_list.next, struct xhci_td, td_list); /* 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, td->last_trb, event_dma); + xhci_dbg(xhci, "%s - found event_seg = %p\n", __func__, event_seg); if (!event_seg) { /* HC is busted, give up! */ xhci_err(xhci, "ERROR Transfer event TRB DMA ptr not part of current TD\n"); @@ -1027,6 +1048,8 @@ cleanup: /* FIXME for multi-TD URBs (who have buffers bigger than 64MB) */ if (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); usb_hcd_giveback_urb(xhci_to_hcd(xhci), urb, status); spin_lock(&xhci->lock); @@ -1044,6 +1067,7 @@ void xhci_handle_event(struct xhci_hcd *xhci) int update_ptrs = 1; int ret; + xhci_dbg(xhci, "In %s\n", __func__); if (!xhci->event_ring || !xhci->event_ring->dequeue) { xhci->error_bitmask |= 1 << 1; return; @@ -1056,18 +1080,25 @@ void xhci_handle_event(struct xhci_hcd *xhci) xhci->error_bitmask |= 1 << 2; return; } + xhci_dbg(xhci, "%s - OS owns TRB\n", __func__); /* FIXME: Handle more event types. */ switch ((event->event_cmd.flags & TRB_TYPE_BITMASK)) { case TRB_TYPE(TRB_COMPLETION): + xhci_dbg(xhci, "%s - calling handle_cmd_completion\n", __func__); handle_cmd_completion(xhci, &event->event_cmd); + xhci_dbg(xhci, "%s - returned from handle_cmd_completion\n", __func__); break; case TRB_TYPE(TRB_PORT_STATUS): + xhci_dbg(xhci, "%s - calling handle_port_status\n", __func__); handle_port_status(xhci, event); + xhci_dbg(xhci, "%s - returned from handle_port_status\n", __func__); update_ptrs = 0; break; case TRB_TYPE(TRB_TRANSFER): + xhci_dbg(xhci, "%s - calling handle_tx_event\n", __func__); ret = handle_tx_event(xhci, &event->trans_event); + xhci_dbg(xhci, "%s - returned from handle_tx_event\n", __func__); if (ret < 0) xhci->error_bitmask |= 1 << 9; else diff --git a/drivers/usb/host/xhci.h b/drivers/usb/host/xhci.h index 60770c89132..074728e1022 100644 --- a/drivers/usb/host/xhci.h +++ b/drivers/usb/host/xhci.h @@ -1065,10 +1065,9 @@ static inline unsigned int xhci_readl(const struct xhci_hcd *xhci, static inline void xhci_writel(struct xhci_hcd *xhci, const unsigned int val, __u32 __iomem *regs) { - if (!in_interrupt()) - xhci_dbg(xhci, - "`MEM_WRITE_DWORD(3'b000, 32'h%p, 32'h%0x, 4'hf);\n", - regs, val); + xhci_dbg(xhci, + "`MEM_WRITE_DWORD(3'b000, 32'h%p, 32'h%0x, 4'hf);\n", + regs, val); 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_hi = upper_32_bits(val); - if (!in_interrupt()) - xhci_dbg(xhci, - "`MEM_WRITE_DWORD(3'b000, 64'h%p, 64'h%0lx, 4'hf);\n", - regs, (long unsigned int) val); + xhci_dbg(xhci, + "`MEM_WRITE_DWORD(3'b000, 64'h%p, 64'h%0lx, 4'hf);\n", + regs, (long unsigned int) val); writel(val_lo, ptr); writel(val_hi, ptr + 1); } -- 2.41.0