Hi Alan,
thanks for the patch.
One question, which kernel version should I use
for this patch?
It's the latest from git?
Thanks,
bye,
pg
On Tue, Dec 04, 2012 at 11:45:14AM -0500, Alan Stern wrote:
> On Mon, 3 Dec 2012, Piergiorgio Sartor wrote:
>
> > Hi Alan,
> >
> > I updated the bug report with dmesg dump.
> >
> > I hope this time it is correct...
>
> Yes, it is. It shows a couple of strange things; I need more
> information.
>
> Below is a new test patch; try running the test with this patch in
> place of the previous one. I don't need to see the usbmon trace, just
> the dmesg log. And not even all of that; just the part from "alan
> start" to "alan end" -- this will be near the end of the log.
>
> Also, what output do you get from "lspci -v -s b.1"?
>
> Alan Stern
>
>
>
> Index: usb-3.7/drivers/usb/host/ehci-hcd.c
> ===================================================================
> --- usb-3.7.orig/drivers/usb/host/ehci-hcd.c
> +++ usb-3.7/drivers/usb/host/ehci-hcd.c
> @@ -825,8 +825,10 @@ dead:
> bh = 0;
> }
>
> - if (bh)
> + if (bh) {
> + ehci->last_scan_time = jiffies;
> ehci_work (ehci);
> + }
> spin_unlock (&ehci->lock);
> if (pcd_status)
> usb_hcd_poll_rh_status(hcd);
> @@ -884,6 +886,53 @@ static int ehci_urb_enqueue (
> }
> }
>
> +static void alan_debug(struct ehci_hcd *ehci, struct urb *urb, struct ehci_qh *qh)
> +{
> + static int done;
> + struct ehci_qh *qh2;
> + struct ehci_qtd *td;
> + char label[24];
> +
> + if (done)
> + return;
> + if (urb->transfer_buffer_length != 31) {
> + ehci_dbg(ehci, "unlink urb len %d\n", urb->transfer_buffer_length);
> + return;
> + }
> +
> + ehci->alan_urb = urb;
> + done = 1;
> + ehci_dbg(ehci, "alan start cur time %lu last scan %lu\n",
> + jiffies, ehci->last_scan_time);
> + ehci_dbg(ehci, "command %x cmd reg %x io watchdog %d async count %d\n",
> + ehci->command, ehci_readl(ehci, &ehci->regs->command),
> + ehci->need_io_watchdog, ehci->async_count);
> +
> + ehci_dbg(ehci, "async list:\n");
> + qh2 = ehci->async;
> + while (qh2) {
> + ehci_dbg(ehci, " qh %p hw %p dma %x next %p hw_next %x\n",
> + qh2, qh2->hw, (u32) qh2->qh_dma, qh2->qh_next.qh,
> + hc32_to_cpu(ehci, qh2->hw->hw_next));
> + qh2 = qh2->qh_next.qh;
> + }
> +
> + ehci_dbg(ehci, "This qh link time %lu enqueue time %lu td token %x ov token %x\n",
> + qh->link_time, qh->enqueue_time,
> + hc32_to_cpu(ehci, qh->tdtoken),
> + hc32_to_cpu(ehci, qh->ovtoken));
> + dbg_qh(" ", ehci, qh);
> +
> + list_for_each_entry(td, &qh->qtd_list, qtd_list) {
> + sprintf(label, " dma %x", (u32) td->qtd_dma);
> + dbg_qtd(label, ehci, td);
> + }
> +
> + sprintf(label, " dummy %x", (u32) qh->dummy->qtd_dma);
> + dbg_qtd(label, ehci, qh->dummy);
> +}
> +
> +
> /* remove from hardware lists
> * completions normally happen asynchronously
> */
> @@ -907,6 +956,10 @@ static int ehci_urb_dequeue(struct usb_h
> qh = (struct ehci_qh *) urb->hcpriv;
> if (!qh)
> break;
> +
> + if (usb_pipetype(urb->pipe) == PIPE_BULK)
> + alan_debug(ehci, urb, qh);
> +
> switch (qh->qh_state) {
> case QH_STATE_LINKED:
> case QH_STATE_COMPLETING:
> Index: usb-3.7/drivers/usb/host/ehci.h
> ===================================================================
> --- usb-3.7.orig/drivers/usb/host/ehci.h
> +++ usb-3.7/drivers/usb/host/ehci.h
> @@ -221,6 +221,10 @@ struct ehci_hcd { /* one per controlle
> #ifdef DEBUG
> struct dentry *debug_dir;
> #endif
> +
> + struct urb *alan_urb;
> + unsigned long last_scan_time;
> +
> };
>
> /* convert between an HCD pointer and the corresponding EHCI_HCD */
> @@ -400,6 +404,9 @@ struct ehci_qh {
> struct usb_device *dev; /* access to TT */
> unsigned is_out:1; /* bulk or intr OUT */
> unsigned clearing_tt:1; /* Clear-TT-Buf in progress */
> +
> + unsigned long link_time, enqueue_time;
> + __hc32 tdtoken, ovtoken;
> };
>
> /*-------------------------------------------------------------------------*/
> Index: usb-3.7/drivers/usb/host/ehci-q.c
> ===================================================================
> --- usb-3.7.orig/drivers/usb/host/ehci-q.c
> +++ usb-3.7/drivers/usb/host/ehci-q.c
> @@ -291,6 +291,11 @@ __acquires(ehci->lock)
> /* complete() can reenter this HCD */
> usb_hcd_unlink_urb_from_ep(ehci_to_hcd(ehci), urb);
> spin_unlock (&ehci->lock);
> + if (urb == ehci->alan_urb) {
> + ehci->alan_urb = NULL;
> + ehci_dbg(ehci, "giveback urb %p actual %d\n", urb, urb->actual_length);
> + ehci_dbg(ehci, "alan end\n");
> + }
> usb_hcd_giveback_urb(ehci_to_hcd(ehci), urb, status);
> spin_lock (&ehci->lock);
> }
> @@ -1002,6 +1007,7 @@ static void qh_link_async (struct ehci_h
>
> /* clear halt and/or toggle; and maybe recover from silicon quirk */
> qh_refresh(ehci, qh);
> + qh->link_time = jiffies;
>
> /* splice right after start */
> head = ehci->async;
> @@ -1101,6 +1107,7 @@ static struct ehci_qh *qh_append_tds (
> dummy->hw_token = token;
>
> urb->hcpriv = qh;
> + qh->tdtoken = token;
> }
> }
> return qh;
> @@ -1154,8 +1161,11 @@ submit_async (
> /* Control/bulk operations through TTs don't need scheduling,
> * the HC and TT handle it when the TT has a buffer ready.
> */
> + qh->enqueue_time = jiffies;
> if (likely (qh->qh_state == QH_STATE_IDLE))
> qh_link_async(ehci, qh);
> + qh->ovtoken = qh->hw->hw_token;
> +
> done:
> spin_unlock_irqrestore (&ehci->lock, flags);
> if (unlikely (qh == NULL))
--
piergiorgio
--
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
