Commit f444ff27 authored by Sarah Sharp's avatar Sarah Sharp

xhci: STFU: Be quieter during URB submission and completion.

Unsurprisingly, URBs get submitted and completed a lot in the xHCI
driver.  If we have to print 10 lines of debug for every URB submitted
or completed, then that can cause the whole system to stay in the
interrupt handler too long, and can cause Missed Service completion
codes for isochronous transfers.

Cut down the debugging in the URB submission and completion paths:
 - Don't squawk about successful transfers, only unsuccessful ones.
 - Only print the number of bytes transferred if this was a short
   transfer.
 - Don't print the endpoint index for successful transfers (will add
   more debug to failed transfers to show endpoint index there later).
 - Stop printing MMIO writes.  This debugging shows up when the endpoint
   doorbell is rung a to start a transfer (basically for every URB).
 - Don't print out the ring enqueue and dequeue pointers
 - Stop printing when we're pointing to a link TRB.
Signed-off-by: default avatarSarah Sharp <sarah.a.sharp@linux.intel.com>
parent 5153b7b3
...@@ -167,10 +167,6 @@ static void inc_deq(struct xhci_hcd *xhci, struct xhci_ring *ring, bool consumer ...@@ -167,10 +167,6 @@ static void inc_deq(struct xhci_hcd *xhci, struct xhci_ring *ring, bool consumer
next = ring->dequeue; next = ring->dequeue;
} }
addr = (unsigned long long) xhci_trb_virt_to_dma(ring->deq_seg, ring->dequeue); addr = (unsigned long long) xhci_trb_virt_to_dma(ring->deq_seg, ring->dequeue);
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);
} }
/* /*
...@@ -246,12 +242,6 @@ static void inc_enq(struct xhci_hcd *xhci, struct xhci_ring *ring, ...@@ -246,12 +242,6 @@ static void inc_enq(struct xhci_hcd *xhci, struct xhci_ring *ring,
next = ring->enqueue; next = ring->enqueue;
} }
addr = (unsigned long long) xhci_trb_virt_to_dma(ring->enq_seg, 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);
} }
/* /*
...@@ -634,13 +624,11 @@ static void xhci_giveback_urb_in_irq(struct xhci_hcd *xhci, ...@@ -634,13 +624,11 @@ static void xhci_giveback_urb_in_irq(struct xhci_hcd *xhci,
} }
} }
usb_hcd_unlink_urb_from_ep(hcd, urb); usb_hcd_unlink_urb_from_ep(hcd, urb);
xhci_dbg(xhci, "Giveback %s URB %p\n", adjective, urb);
spin_unlock(&xhci->lock); spin_unlock(&xhci->lock);
usb_hcd_giveback_urb(hcd, urb, status); usb_hcd_giveback_urb(hcd, urb, status);
xhci_urb_free_priv(xhci, urb_priv); xhci_urb_free_priv(xhci, urb_priv);
spin_lock(&xhci->lock); spin_lock(&xhci->lock);
xhci_dbg(xhci, "%s URB given back\n", adjective);
} }
} }
...@@ -1630,7 +1618,6 @@ static int process_ctrl_td(struct xhci_hcd *xhci, struct xhci_td *td, ...@@ -1630,7 +1618,6 @@ static int process_ctrl_td(struct xhci_hcd *xhci, struct xhci_td *td,
"without IOC set??\n"); "without IOC set??\n");
*status = -ESHUTDOWN; *status = -ESHUTDOWN;
} else { } else {
xhci_dbg(xhci, "Successful control transfer!\n");
*status = 0; *status = 0;
} }
break; break;
...@@ -1727,7 +1714,6 @@ static int process_isoc_td(struct xhci_hcd *xhci, struct xhci_td *td, ...@@ -1727,7 +1714,6 @@ static int process_isoc_td(struct xhci_hcd *xhci, struct xhci_td *td,
switch (trb_comp_code) { switch (trb_comp_code) {
case COMP_SUCCESS: case COMP_SUCCESS:
frame->status = 0; frame->status = 0;
xhci_dbg(xhci, "Successful isoc transfer!\n");
break; break;
case COMP_SHORT_TX: case COMP_SHORT_TX:
frame->status = td->urb->transfer_flags & URB_SHORT_NOT_OK ? frame->status = td->urb->transfer_flags & URB_SHORT_NOT_OK ?
...@@ -1837,12 +1823,6 @@ static int process_bulk_intr_td(struct xhci_hcd *xhci, struct xhci_td *td, ...@@ -1837,12 +1823,6 @@ static int process_bulk_intr_td(struct xhci_hcd *xhci, struct xhci_td *td,
else else
*status = 0; *status = 0;
} else { } else {
if (usb_endpoint_xfer_bulk(&td->urb->ep->desc))
xhci_dbg(xhci, "Successful bulk "
"transfer!\n");
else
xhci_dbg(xhci, "Successful interrupt "
"transfer!\n");
*status = 0; *status = 0;
} }
break; break;
...@@ -1856,11 +1836,12 @@ static int process_bulk_intr_td(struct xhci_hcd *xhci, struct xhci_td *td, ...@@ -1856,11 +1836,12 @@ static int process_bulk_intr_td(struct xhci_hcd *xhci, struct xhci_td *td,
/* Others already handled above */ /* Others already handled above */
break; break;
} }
xhci_dbg(xhci, "ep %#x - asked for %d bytes, " if (trb_comp_code == COMP_SHORT_TX)
"%d bytes untransferred\n", xhci_dbg(xhci, "ep %#x - asked for %d bytes, "
td->urb->ep->desc.bEndpointAddress, "%d bytes untransferred\n",
td->urb->transfer_buffer_length, td->urb->ep->desc.bEndpointAddress,
TRB_LEN(le32_to_cpu(event->transfer_len))); td->urb->transfer_buffer_length,
TRB_LEN(le32_to_cpu(event->transfer_len)));
/* Fast path - was this the last TRB in the TD for this URB? */ /* Fast path - was this the last TRB in the TD for this URB? */
if (event_trb == td->last_trb) { if (event_trb == td->last_trb) {
if (TRB_LEN(le32_to_cpu(event->transfer_len)) != 0) { if (TRB_LEN(le32_to_cpu(event->transfer_len)) != 0) {
...@@ -1954,7 +1935,6 @@ static int handle_tx_event(struct xhci_hcd *xhci, ...@@ -1954,7 +1935,6 @@ 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(le32_to_cpu(event->flags)) - 1; ep_index = TRB_TO_EP_ID(le32_to_cpu(event->flags)) - 1;
xhci_dbg(xhci, "%s - ep index = %d\n", __func__, ep_index);
ep = &xdev->eps[ep_index]; ep = &xdev->eps[ep_index];
ep_ring = xhci_dma_to_transfer_ring(ep, le64_to_cpu(event->buffer)); ep_ring = xhci_dma_to_transfer_ring(ep, le64_to_cpu(event->buffer));
ep_ctx = xhci_get_ep_ctx(xhci, xdev->out_ctx, ep_index); ep_ctx = xhci_get_ep_ctx(xhci, xdev->out_ctx, ep_index);
...@@ -2149,9 +2129,15 @@ static int handle_tx_event(struct xhci_hcd *xhci, ...@@ -2149,9 +2129,15 @@ static int handle_tx_event(struct xhci_hcd *xhci,
xhci_urb_free_priv(xhci, urb_priv); xhci_urb_free_priv(xhci, urb_priv);
usb_hcd_unlink_urb_from_ep(bus_to_hcd(urb->dev->bus), urb); usb_hcd_unlink_urb_from_ep(bus_to_hcd(urb->dev->bus), urb);
xhci_dbg(xhci, "Giveback URB %p, len = %d, " if ((urb->actual_length != urb->transfer_buffer_length &&
"status = %d\n", (urb->transfer_flags &
urb, urb->actual_length, status); URB_SHORT_NOT_OK)) ||
status != 0)
xhci_dbg(xhci, "Giveback URB %p, len = %d, "
"expected = %x, status = %d\n",
urb, urb->actual_length,
urb->transfer_buffer_length,
status);
spin_unlock(&xhci->lock); spin_unlock(&xhci->lock);
usb_hcd_giveback_urb(bus_to_hcd(urb->dev->bus), urb, status); usb_hcd_giveback_urb(bus_to_hcd(urb->dev->bus), urb, status);
spin_lock(&xhci->lock); spin_lock(&xhci->lock);
...@@ -2379,7 +2365,6 @@ static int prepare_ring(struct xhci_hcd *xhci, struct xhci_ring *ep_ring, ...@@ -2379,7 +2365,6 @@ static int prepare_ring(struct xhci_hcd *xhci, struct xhci_ring *ep_ring,
u32 ep_state, unsigned int num_trbs, gfp_t mem_flags) u32 ep_state, unsigned int num_trbs, gfp_t mem_flags)
{ {
/* Make sure the endpoint has been added to xHC schedule */ /* Make sure the endpoint has been added to xHC schedule */
xhci_dbg(xhci, "Endpoint state = 0x%x\n", ep_state);
switch (ep_state) { switch (ep_state) {
case EP_STATE_DISABLED: case EP_STATE_DISABLED:
/* /*
...@@ -2416,7 +2401,6 @@ static int prepare_ring(struct xhci_hcd *xhci, struct xhci_ring *ep_ring, ...@@ -2416,7 +2401,6 @@ static int prepare_ring(struct xhci_hcd *xhci, struct xhci_ring *ep_ring,
struct xhci_ring *ring = ep_ring; struct xhci_ring *ring = ep_ring;
union xhci_trb *next; union xhci_trb *next;
xhci_dbg(xhci, "prepare_ring: pointing to link trb\n");
next = ring->enqueue; next = ring->enqueue;
while (last_trb(xhci, ring, ring->enq_seg, next)) { while (last_trb(xhci, ring, ring->enq_seg, next)) {
......
...@@ -1338,9 +1338,6 @@ static inline unsigned int xhci_readl(const struct xhci_hcd *xhci, ...@@ -1338,9 +1338,6 @@ 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, __le32 __iomem *regs) const unsigned int val, __le32 __iomem *regs)
{ {
xhci_dbg(xhci,
"`MEM_WRITE_DWORD(3'b000, 32'h%p, 32'h%0x, 4'hf);\n",
regs, val);
writel(val, regs); writel(val, regs);
} }
...@@ -1368,9 +1365,6 @@ static inline void xhci_write_64(struct xhci_hcd *xhci, ...@@ -1368,9 +1365,6 @@ 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);
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_lo, ptr);
writel(val_hi, ptr + 1); writel(val_hi, ptr + 1);
} }
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment