On Thu, Oct 05, 2006 at 10:46:53AM -0400, Alan Stern wrote:
> On Wed, 4 Oct 2006, Greg KH wrote:
> 
> > Ok, they still cause problems :)
> > 
> > I've applied them, and plugged a usb stick into a USB 2.0 hub and got
> > the following:
> > 
> > [  375.562120] ehci_hcd 0000:00:1d.7: port 4 remote wakeup
> > [  375.562134] hub 5-0:1.0: state 8 ports 8 chg 0000 evt 0000
> > [  375.562141] usb usb5: usb auto-resume
> > [  375.562147] usb usb5: finish resume
> > [  375.562165] hub 5-0:1.0: hub_resume
> > [  375.562172] ehci_hcd 0000:00:1d.7: resume root hub
> > [  375.593289] hub 5-0:1.0: state 7 ports 8 chg 0000 evt 0000
> > [  377.588840] hub 5-0:1.0: hub_suspend
> > [  377.588898] usb usb5: usb auto-suspend
> > 
> > And the hub is now dead.  Unplug the device and plug it back in and
> > nothing.
> > 
> > If I plug something into any other port on the hub, it too does not show
> > anything.
> > 
> > Any hints on what I can do to debug this?
> 
> (I need to buy a high-speed hub so I can run these sorts of tests here...)

They're real cheap now, I can send you one if you can't find one
nearby...

> I don't know exactly where the trouble is, but here's what _should_ be 
> happening:
> 
> In ehci-hcd.c:ehci_irq(), look at the block that starts with
> 
>       /* remote wakeup [4.3.1] */
>       if (status & STS_PCD) {
> 
> Since you got the "port 4 remote wakeup" message in your log, this block 
> is running and we know that (pstatus & PORT_RESUME) is non-zero and that 
> ehci->reset_done[i] is set to 20 ms in the future.
> 
> Now look at ehci_hub.c:ehci_hub_status_data().  This routine should get 
> called every 250 ms, starting from the "hub_resume" message in the 
> log.  Buried inside the main loop is this ungainly test:
> 
>               if ((temp & (PORT_CSC | PORT_PEC | PORT_OCC)) != 0
>                               // PORT_STAT_C_SUSPEND?
>                               || ((temp & PORT_RESUME) != 0
>                                       && time_after (jiffies,
>                                               ehci->reset_done [i]))) {
> 
> As mentioned above, we know that (temp & PORT_RESUME) is non-zero.  The 
> time_after() condition might not be true the very first time the 
> subroutine gets called, but it certainly ought to be true the second time 
> since 250 ms > 20 ms.  But apparently it isn't, since bit i+1 in buf 
> remains 0 (that's the "evt 0000" value in the log).
> 
> So this is where you should concentrate your debugging.  The questions 
> to be answered are:
> 
>       Is (temp & PORT_RESUME) really set?
> 
>       How does jiffies compare with ehci->reset_done[i]?
> 
>       Does the subroutine really get called every 250 ms?

Ok, here's the log to answer the first and last of those questions.
Same thing happens, I plug the device into the usb hub:


[  304.401339] ehci_hcd 0000:00:1d.7: port 4 remote wakeup
[  304.401352] hub 1-0:1.0: state 8 ports 8 chg 0000 evt 0000
[  304.401359] usb usb1: usb auto-resume
[  304.401365] usb usb1: finish resume
[  304.401383] hub 1-0:1.0: hub_resume
[  304.401391] ehci_hcd 0000:00:1d.7: resume root hub
[  304.431673] hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0000
[  304.680955] GREGKH: ehci_hub_status_data: hcd->state=0x1
[  304.680961] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  304.680964] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  304.680969] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  304.680972] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  304.680976] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  304.680979] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  304.930282] GREGKH: ehci_hub_status_data: hcd->state=0x1
[  304.930288] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  304.930291] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  304.930296] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  304.930299] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  304.930302] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  304.930306] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.179610] GREGKH: ehci_hub_status_data: hcd->state=0x1
[  305.179615] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.179619] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.179624] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.179627] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.179630] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.179634] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.428938] GREGKH: ehci_hub_status_data: hcd->state=0x1
[  305.428944] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.428947] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.428952] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.428955] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.428959] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.428962] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.678274] GREGKH: ehci_hub_status_data: hcd->state=0x1
[  305.678280] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.678284] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.678288] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.678291] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.678295] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.678298] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.927616] GREGKH: ehci_hub_status_data: hcd->state=0x1
[  305.927621] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.927624] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.927629] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.927632] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.927635] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  305.927639] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.176963] GREGKH: ehci_hub_status_data: hcd->state=0x1
[  306.176969] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.176973] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.176977] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.176981] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.176984] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.176988] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.426290] GREGKH: ehci_hub_status_data: hcd->state=0x1
[  306.426295] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.426299] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.426304] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.426307] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.426310] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.426314] GREGKH: ehci_hub_status_data: temp & PORT_RESUME=0
[  306.426323] hub 1-0:1.0: hub_suspend
[  306.426376] usb usb1: usb auto-suspend

I should have numbered the ports that the temp variable got checked for,
sorry.

The initial "hcd->state" line is printed out every time that function
gets called.  The check is printed out every time it is about to be
tested.  The patch that adds these lines is below.

Does this help out any?  Should I still check the jiffies value?

thanks,

greg k-h


---
 drivers/usb/host/ehci-hub.c |    3 +++
 1 file changed, 3 insertions(+)

--- gregkh-2.6.orig/drivers/usb/host/ehci-hub.c
+++ gregkh-2.6/drivers/usb/host/ehci-hub.c
@@ -225,6 +225,8 @@ ehci_hub_status_data (struct usb_hcd *hc
        int             ports, i, retval = 1;
        unsigned long   flags;
 
+       printk("GREGKH: %s: hcd->state=0x%x\n", __FUNCTION__, hcd->state);
+
        /* if !USB_SUSPEND, root hub timers won't get shut down ... */
        if (!HC_IS_RUNNING(hcd->state))
                return 0;
@@ -254,6 +256,7 @@ ehci_hub_status_data (struct usb_hcd *hc
                }
                if (!(temp & PORT_CONNECT))
                        ehci->reset_done [i] = 0;
+               printk("GREGKH: %s: temp & PORT_RESUME=%d\n", __FUNCTION__, 
temp&PORT_RESUME);
                if ((temp & (PORT_CSC | PORT_PEC | PORT_OCC)) != 0
                                // PORT_STAT_C_SUSPEND?
                                || ((temp & PORT_RESUME) != 0

-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your
opinions on IT & business topics through brief surveys -- and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
_______________________________________________
linux-usb-devel@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel

Reply via email to