S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Brandon Philips]

Hello-

When an UVC device is open and a S4 is attempted the thaw hangs (see the
stack below). I don't see what the UVC driver is doing wrong to cause
this to happen though.

To make it quick to reproduce you can use init=/bin/bash and a little
program to open up and setup the device:
 http://ifup.org/~philips/467317/v4l-open-sleep.c

Here is a full log with some verbose debugging on:
 http://ifup.org/~philips/467317/pearl.log

The driver acts fine when using s2ram suspend and pm debugging levels.
On my Poweredge SC440 the S4 suspend restores the device properly but on
my Lenovo x200s and this Intel test box it hangs.

Cheers,

	Brandon

Linux version 2.6.29-rc7-1-default (root@pearl) (gcc version 4.3.2 [gcc-4_3-branch revision 141291] (SUSE Linux) ) #4 SMP Fri Mar 6 01:29:35 PST 2009

SysRq : Show Blocked State
  task                        PC stack   pid father
bash          D ffff880078524c94     0     1      0
 ffff88007bb9fae8 0000000000000082 0000000000000292 ffff88003747d140
 ffffffff80816f00 ffffffff80816f00 ffff88007bb9c040 ffff88007bb9c3b8
 0000000000000292 ffffffff80630350 ffff88003754d000 ffff880078524c80
Call Trace:
 [<ffffffff8036d8a8>] ? kobject_put+0x47/0x4b
 [<ffffffff802253a5>] ? default_spin_lock_flags+0x17/0x1a
 [<ffffffffa011ae2b>] usb_kill_urb+0x9d/0xbd [usbcore]
 [<ffffffff80258ca4>] ? autoremove_wake_function+0x0/0x38
 [<ffffffffa011c3a3>] usb_start_wait_urb+0xd9/0x1c2 [usbcore]
 [<ffffffffa011b52c>] ? usb_init_urb+0x22/0x33 [usbcore]
 [<ffffffffa011c6c8>] usb_control_msg+0x114/0x15b [usbcore]
 [<ffffffffa03433e7>] uvc_set_video_ctrl+0x134/0x184 [uvcvideo]
 [<ffffffffa0343442>] uvc_commit_video+0xb/0xd [uvcvideo]
 [<ffffffffa0343504>] uvc_video_resume+0x1e/0x58 [uvcvideo]
 [<ffffffffa033e112>] __uvc_resume+0x99/0xa1 [uvcvideo]
 [<ffffffffa033e135>] uvc_resume+0xb/0xd [uvcvideo]
 [<ffffffffa011dce6>] usb_resume_interface+0xdf/0x165 [usbcore]
 [<ffffffffa011e1ee>] usb_resume_both+0x102/0x128 [usbcore]
 [<ffffffffa011ed37>] usb_external_resume_device+0x33/0x6e [usbcore]
 [<ffffffffa011ed8d>] usb_resume+0x1b/0x1d [usbcore]
 [<ffffffffa0113178>] usb_dev_thaw+0xe/0x10 [usbcore]
 [<ffffffff803fb100>] pm_op+0xa4/0xe5
 [<ffffffff803fbd02>] device_resume+0x137/0x47b
 [<ffffffff8026e4e9>] hibernation_snapshot+0x1ba/0x1fa
 [<ffffffff8026e5ec>] hibernate+0xc3/0x1a1
 [<ffffffff8026d15a>] state_store+0x59/0xd8
 [<ffffffff8036d69f>] kobj_attr_store+0x17/0x19
 [<ffffffff8031d04b>] sysfs_write_file+0xdf/0x114
 [<ffffffff802cc8bd>] vfs_write+0xae/0x157
 [<ffffffff802cca2a>] sys_write+0x47/0x70
 [<ffffffff8020c42a>] system_call_fastpath+0x16/0x1b

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Greg KH]

On Fri, Mar 06, 2009 at 11:11:22AM -0800, Brandon Philips wrote:
> Hello-
> 
> When an UVC device is open and a S4 is attempted the thaw hangs (see the
> stack below). I don't see what the UVC driver is doing wrong to cause
> this to happen though.

I don't think this is a uvc driver issue, it looks like all you are
trying to do is a usb control message when things hang.

> To make it quick to reproduce you can use init=/bin/bash and a little
> program to open up and setup the device:
>  http://ifup.org/~philips/467317/v4l-open-sleep.c
> 
> Here is a full log with some verbose debugging on:
>  http://ifup.org/~philips/467317/pearl.log
> 
> The driver acts fine when using s2ram suspend and pm debugging levels.
> On my Poweredge SC440 the S4 suspend restores the device properly but on
> my Lenovo x200s and this Intel test box it hangs.
> 
> Cheers,
> 
> 	Brandon
> 
> Linux version 2.6.29-rc7-1-default (root@pearl) (gcc version 4.3.2 [gcc-4_3-branch revision 141291] (SUSE Linux) ) #4 SMP Fri Mar 6 01:29:35 PST 2009
> 
> SysRq : Show Blocked State
>   task                        PC stack   pid father
> bash          D ffff880078524c94     0     1      0
>  ffff88007bb9fae8 0000000000000082 0000000000000292 ffff88003747d140
>  ffffffff80816f00 ffffffff80816f00 ffff88007bb9c040 ffff88007bb9c3b8
>  0000000000000292 ffffffff80630350 ffff88003754d000 ffff880078524c80
> Call Trace:
>  [<ffffffff8036d8a8>] ? kobject_put+0x47/0x4b
>  [<ffffffff802253a5>] ? default_spin_lock_flags+0x17/0x1a
>  [<ffffffffa011ae2b>] usb_kill_urb+0x9d/0xbd [usbcore]
>  [<ffffffff80258ca4>] ? autoremove_wake_function+0x0/0x38
>  [<ffffffffa011c3a3>] usb_start_wait_urb+0xd9/0x1c2 [usbcore]
>  [<ffffffffa011b52c>] ? usb_init_urb+0x22/0x33 [usbcore]
>  [<ffffffffa011c6c8>] usb_control_msg+0x114/0x15b [usbcore]
>  [<ffffffffa03433e7>] uvc_set_video_ctrl+0x134/0x184 [uvcvideo]
>  [<ffffffffa0343442>] uvc_commit_video+0xb/0xd [uvcvideo]
>  [<ffffffffa0343504>] uvc_video_resume+0x1e/0x58 [uvcvideo]
>  [<ffffffffa033e112>] __uvc_resume+0x99/0xa1 [uvcvideo]
>  [<ffffffffa033e135>] uvc_resume+0xb/0xd [uvcvideo]
>  [<ffffffffa011dce6>] usb_resume_interface+0xdf/0x165 [usbcore]
>  [<ffffffffa011e1ee>] usb_resume_both+0x102/0x128 [usbcore]
>  [<ffffffffa011ed37>] usb_external_resume_device+0x33/0x6e [usbcore]
>  [<ffffffffa011ed8d>] usb_resume+0x1b/0x1d [usbcore]
>  [<ffffffffa0113178>] usb_dev_thaw+0xe/0x10 [usbcore]
>  [<ffffffff803fb100>] pm_op+0xa4/0xe5
>  [<ffffffff803fbd02>] device_resume+0x137/0x47b
>  [<ffffffff8026e4e9>] hibernation_snapshot+0x1ba/0x1fa
>  [<ffffffff8026e5ec>] hibernate+0xc3/0x1a1
>  [<ffffffff8026d15a>] state_store+0x59/0xd8
>  [<ffffffff8036d69f>] kobj_attr_store+0x17/0x19
>  [<ffffffff8031d04b>] sysfs_write_file+0xdf/0x114
>  [<ffffffff802cc8bd>] vfs_write+0xae/0x157
>  [<ffffffff802cca2a>] sys_write+0x47/0x70
>  [<ffffffff8020c42a>] system_call_fastpath+0x16/0x1b

That's the control message timing out and trying to reap the urb.

But the problem is the khubd is asleep, from your log file:

khubd         D 0000000000000000     0   255      2
 ffff880037509d80 0000000000000046 ffff88007864ba80 ffffffff8088fcf8
 ffffffff80816f00 ffffffff80816f00 ffff8800375b0380 ffff8800375b06f8
 0000000080816f00 ffff88007bb9c040 ffff8800375b0380 ffff8800375b06f8
Call Trace:
 [<ffffffff802253a5>] ? default_spin_lock_flags+0x17/0x1a
 [<ffffffff8025e7a9>] refrigerator+0x170/0x1cf
 [<ffffffffa01187ab>] hub_thread+0x1370/0x13bd [usbcore]
 [<ffffffff8020a7c2>] ? __switch_to+0xd4/0x4b3
 [<ffffffff80258ca4>] ? autoremove_wake_function+0x0/0x38
 [<ffffffffa011743b>] ? hub_thread+0x0/0x13bd [usbcore]
 [<ffffffff8025890b>] kthread+0x49/0x76
 [<ffffffff8020d69a>] child_rip+0xa/0x20
 [<ffffffff802588c2>] ? kthread+0x0/0x76
 [<ffffffff8020d690>] ? child_rip+0x0/0x20

udevd is also stuck in the refrigerator, which seems wierd as well.
a.out is also stuck, is that your test program?

It looks like things die right after this message:
	ehci_hcd 0000:00:1d.7: Unlink after no-IRQ?  Controller is probably using the wrong IRQ.

Alan, what causes this at resume time?

thanks,

greg k-h

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Brandon Philips]

On 21:26 Fri 06 Mar 2009, Greg KH wrote:
> On Fri, Mar 06, 2009 at 11:11:22AM -0800, Brandon Philips wrote:
> > Hello-
> > 
> > When an UVC device is open and a S4 is attempted the thaw hangs (see the
> > stack below). I don't see what the UVC driver is doing wrong to cause
> > this to happen though.
> 
> I don't think this is a uvc driver issue, it looks like all you are
> trying to do is a usb control message when things hang.

Indeed. When I was poking at this I tried to supress the control message coming
out of the uvcvideo driver after the suspend was issued to see what would
happen and the control messages after the resume locked up instead. Eh.

> > SysRq : Show Blocked State
> >   task                        PC stack   pid father
> > bash          D ffff880078524c94     0     1      0
> >  ffff88007bb9fae8 0000000000000082 0000000000000292 ffff88003747d140
> >  ffffffff80816f00 ffffffff80816f00 ffff88007bb9c040 ffff88007bb9c3b8
> >  0000000000000292 ffffffff80630350 ffff88003754d000 ffff880078524c80
> > Call Trace:
> >  [<ffffffff8036d8a8>] ? kobject_put+0x47/0x4b
> >  [<ffffffff802253a5>] ? default_spin_lock_flags+0x17/0x1a
> >  [<ffffffffa011ae2b>] usb_kill_urb+0x9d/0xbd [usbcore]
> >  [<ffffffff80258ca4>] ? autoremove_wake_function+0x0/0x38
> >  [<ffffffffa011c3a3>] usb_start_wait_urb+0xd9/0x1c2 [usbcore]
> >  [<ffffffffa011b52c>] ? usb_init_urb+0x22/0x33 [usbcore]
> >  [<ffffffffa011c6c8>] usb_control_msg+0x114/0x15b [usbcore]
> >  [<ffffffffa03433e7>] uvc_set_video_ctrl+0x134/0x184 [uvcvideo]
> >  [<ffffffffa0343442>] uvc_commit_video+0xb/0xd [uvcvideo]
> >  [<ffffffffa0343504>] uvc_video_resume+0x1e/0x58 [uvcvideo]
> >  [<ffffffffa033e112>] __uvc_resume+0x99/0xa1 [uvcvideo]
> >  [<ffffffffa033e135>] uvc_resume+0xb/0xd [uvcvideo]
> >  [<ffffffffa011dce6>] usb_resume_interface+0xdf/0x165 [usbcore]
> >  [<ffffffffa011e1ee>] usb_resume_both+0x102/0x128 [usbcore]
> >  [<ffffffffa011ed37>] usb_external_resume_device+0x33/0x6e [usbcore]
> >  [<ffffffffa011ed8d>] usb_resume+0x1b/0x1d [usbcore]
> >  [<ffffffffa0113178>] usb_dev_thaw+0xe/0x10 [usbcore]
> >  [<ffffffff803fb100>] pm_op+0xa4/0xe5
> >  [<ffffffff803fbd02>] device_resume+0x137/0x47b
> >  [<ffffffff8026e4e9>] hibernation_snapshot+0x1ba/0x1fa
> >  [<ffffffff8026e5ec>] hibernate+0xc3/0x1a1
> >  [<ffffffff8026d15a>] state_store+0x59/0xd8
> >  [<ffffffff8036d69f>] kobj_attr_store+0x17/0x19
> >  [<ffffffff8031d04b>] sysfs_write_file+0xdf/0x114
> >  [<ffffffff802cc8bd>] vfs_write+0xae/0x157
> >  [<ffffffff802cca2a>] sys_write+0x47/0x70
> >  [<ffffffff8020c42a>] system_call_fastpath+0x16/0x1b
> 
> That's the control message timing out and trying to reap the urb.

Yes. And like I said above it seems that after the suspend any usb_control_msg
coming from the driver hangs no matter if it is during the suspend, thaw or
resume.

> But the problem is the khubd is asleep, from your log file:
> 
> khubd         D 0000000000000000     0   255      2
>  ffff880037509d80 0000000000000046 ffff88007864ba80 ffffffff8088fcf8
>  ffffffff80816f00 ffffffff80816f00 ffff8800375b0380 ffff8800375b06f8
>  0000000080816f00 ffff88007bb9c040 ffff8800375b0380 ffff8800375b06f8
> Call Trace:
>  [<ffffffff802253a5>] ? default_spin_lock_flags+0x17/0x1a
>  [<ffffffff8025e7a9>] refrigerator+0x170/0x1cf
>  [<ffffffffa01187ab>] hub_thread+0x1370/0x13bd [usbcore]
>  [<ffffffff8020a7c2>] ? __switch_to+0xd4/0x4b3
>  [<ffffffff80258ca4>] ? autoremove_wake_function+0x0/0x38
>  [<ffffffffa011743b>] ? hub_thread+0x0/0x13bd [usbcore]
>  [<ffffffff8025890b>] kthread+0x49/0x76
>  [<ffffffff8020d69a>] child_rip+0xa/0x20
>  [<ffffffff802588c2>] ? kthread+0x0/0x76
>  [<ffffffff8020d690>] ? child_rip+0x0/0x20
> 
> udevd is also stuck in the refrigerator, which seems wierd as well.
> a.out is also stuck, is that your test program?

Yes, a.out is the test program. 8-)

> It looks like things die right after this message:
> 	ehci_hcd 0000:00:1d.7: Unlink after no-IRQ?  Controller is probably using the wrong IRQ.

Cheers,

	Brandon

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Alan Stern]

On Sat, 7 Mar 2009, Brandon Philips wrote:

> On 21:26 Fri 06 Mar 2009, Greg KH wrote:
> > On Fri, Mar 06, 2009 at 11:11:22AM -0800, Brandon Philips wrote:
> > > Hello-
> > > 
> > > When an UVC device is open and a S4 is attempted the thaw hangs (see the
> > > stack below). I don't see what the UVC driver is doing wrong to cause
> > > this to happen though.
> > 
> > I don't think this is a uvc driver issue, it looks like all you are
> > trying to do is a usb control message when things hang.
> 
> Indeed. When I was poking at this I tried to supress the control message coming
> out of the uvcvideo driver after the suspend was issued to see what would
> happen and the control messages after the resume locked up instead. Eh.

Have you tried suspending just the two devices plugged into that EHCI 
controller instead of suspending the entire system?  That would make it 
a lot easier to carry out testing.

> > It looks like things die right after this message:
> > 	ehci_hcd 0000:00:1d.7: Unlink after no-IRQ?  Controller is probably using the wrong IRQ.

It could be that the host controller isn't behaving correctly.  But 
even then, a timer should keep things running.  So I don't know why the 
system hanged.

BTW, all those extra debugging messages in your log made it very 
difficult to read, and they didn't help much in pinpointing the 
problem.  You should remove all of them before doing the next test.  
Instead you could use usbmon to capture the USB traffic.

Alan Stern

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Brandon Philips]

On 12:37 Sat 07 Mar 2009, Alan Stern wrote:
> On Sat, 7 Mar 2009, Brandon Philips wrote:
> > On 21:26 Fri 06 Mar 2009, Greg KH wrote:
> > > On Fri, Mar 06, 2009 at 11:11:22AM -0800, Brandon Philips wrote:
> > > > When an UVC device is open and a S4 is attempted the thaw hangs (see the
> > > > stack below). I don't see what the UVC driver is doing wrong to cause
> > > > this to happen though.
> > > 
> > > I don't think this is a uvc driver issue, it looks like all you are
> > > trying to do is a usb control message when things hang.
> > 
> > Indeed. When I was poking at this I tried to supress the control message coming
> > out of the uvcvideo driver after the suspend was issued to see what would
> > happen and the control messages after the resume locked up instead. Eh.
> 
> Have you tried suspending just the two devices plugged into that EHCI 
> controller instead of suspending the entire system?  That would make it 
> a lot easier to carry out testing.

I tried to reproduce with s2ram suspend, echo suspend >
/sys/bus/usb/devices/.../power/level and /sys/power/pm_test levels but none of
them reproduced it. So, at this point the only way I can reproduce this is with
a full S4.

Is there some other method I missed of testing?

Thanks,

	Brandon

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Alan Stern]

On Sat, 7 Mar 2009, Brandon Philips wrote:

> > Have you tried suspending just the two devices plugged into that EHCI 
> > controller instead of suspending the entire system?  That would make it 
> > a lot easier to carry out testing.
> 
> I tried to reproduce with s2ram suspend, echo suspend >
> /sys/bus/usb/devices/.../power/level and /sys/power/pm_test levels but none of
> them reproduced it. So, at this point the only way I can reproduce this is with
> a full S4.

That's a little misleading.  Unless I misunderstood your log, the hang 
occurred _before_ your system entered S4.  In fact, it occurred before 
the memory image was written out to the disk.

> Is there some other method I missed of testing?

How about echo disk >/sys/power/state with various settings in 
/sys/power/disk?

Alan Stern

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Brandon Philips]

On 12:43 Sun 08 Mar 2009, Alan Stern wrote:
> On Sat, 7 Mar 2009, Brandon Philips wrote:
> > > Have you tried suspending just the two devices plugged into that EHCI 
> > > controller instead of suspending the entire system?  That would make it 
> > > a lot easier to carry out testing.
> > 
> > I tried to reproduce with s2ram suspend, echo suspend >
> > /sys/bus/usb/devices/.../power/level and /sys/power/pm_test levels but none of
> > them reproduced it. So, at this point the only way I can reproduce this is with
> > a full S4.
> 
> That's a little misleading.

Sorry, what I meant by "full" was `echo disk > /sys/power/state` with
none in /sys/power/pm_test

> Unless I misunderstood your log, the hang occurred _before_ your
> system entered S4.  In fact, it occurred before the memory image was
> written out to the disk.

Yes, this is correct. It freezes before the image is written.

> > Is there some other method I missed of testing?
> 
> How about echo disk >/sys/power/state with various settings in 
> /sys/power/disk?

First observation: I can't reproduce this bug with console=ttyS0,115200
console=tty0. Everything works great actually. Is writing to the serial
port causing just enough delay to hide the bug?

/sys/power/disk tests
---------------------
testproc	# OK
test		# Unlink after no-IRQ? ...
platform	# Unlink after no-IRQ? ...
reboot		# Unlink after no-IRQ? ...
shutdown	# Unlink after no-IRQ? ...

Cheers,

	Brandon

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Alan Stern]

On Tue, 10 Mar 2009, Brandon Philips wrote:

> First observation: I can't reproduce this bug with console=ttyS0,115200
> console=tty0. Everything works great actually. Is writing to the serial
> port causing just enough delay to hide the bug?

Maybe it is, maybe it isn't.  There's no way to know at present.

If you can't reproduce the bug when using a serial console, how did you 
acquire the system log you posted earlier?  Network console?

> /sys/power/disk tests
> ---------------------
> testproc	# OK
> test		# Unlink after no-IRQ? ...
> platform	# Unlink after no-IRQ? ...
> reboot		# Unlink after no-IRQ? ...
> shutdown	# Unlink after no-IRQ? ...

Okay, so "test" is the thing to use.  Although since your system hangs, 
it doesn't make much difference...

The next thing to try is to make sure the bug is still present with the 
lastest development kernel.  That would be 2.6.29-rc7 together with

http://www.kernel.org/pub/linux/kernel/people/gregkh/gregkh-2.6/gregkh-all-2.6.29-rc7.patch

If it is then we'll have to try some diagnostic patches to find out 
what's going wrong.

Alan Stern

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Brandon Philips]

On 11:30 Wed 11 Mar 2009, Alan Stern wrote:
> On Tue, 10 Mar 2009, Brandon Philips wrote:
> > First observation: I can't reproduce this bug with console=ttyS0,115200
> > console=tty0. Everything works great actually. Is writing to the serial
> > port causing just enough delay to hide the bug?
> 
> Maybe it is, maybe it isn't.  There's no way to know at present.
> 
> If you can't reproduce the bug when using a serial console, how did you 
> acquire the system log you posted earlier?  Network console?

Yes, I used netconsole.

> > /sys/power/disk tests
> > ---------------------
> > testproc	# OK
> > test		# Unlink after no-IRQ? ...
> > platform	# Unlink after no-IRQ? ...
> > reboot		# Unlink after no-IRQ? ...
> > shutdown	# Unlink after no-IRQ? ...
> 
> Okay, so "test" is the thing to use.  Although since your system hangs, 
> it doesn't make much difference...
> 
> The next thing to try is to make sure the bug is still present with the 
> lastest development kernel.  That would be 2.6.29-rc7 together with
> 
> http://www.kernel.org/pub/linux/kernel/people/gregkh/gregkh-2.6/gregkh-all-2.6.29-rc7.patch
> 
> If it is then we'll have to try some diagnostic patches to find out 
> what's going wrong.

It still locks up with "Unlink after no-IRQ" with -rc7 + greg's patches
and test in /sys/power/disk.

One of the times when I booted up this new Kernel I got some errors out
of ehci_hcd/khubd: http://ifup.org/~philips/467317/khubd.timeout It only
happened on that boot and I haven't seen those ehci_hcd/khubd errors
again since.

Thanks,

	Brandon

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Alan Stern]

On Wed, 11 Mar 2009, Brandon Philips wrote:

> It still locks up with "Unlink after no-IRQ" with -rc7 + greg's patches
> and test in /sys/power/disk.
> 
> One of the times when I booted up this new Kernel I got some errors out
> of ehci_hcd/khubd: http://ifup.org/~philips/467317/khubd.timeout It only
> happened on that boot and I haven't seen those ehci_hcd/khubd errors
> again since.

I have no idea what caused that.  Some brief glitch, apparently.

Okay, here's a diagnostic patch meant to apply on top of 
gregkh-all-2.6.29-rc7.  Let's see what it says...

Alan Stern


Index: usb-2.6/drivers/usb/host/ehci-hcd.c
===================================================================
--- usb-2.6.orig/drivers/usb/host/ehci-hcd.c
+++ usb-2.6/drivers/usb/host/ehci-hcd.c
@@ -108,6 +108,8 @@ MODULE_PARM_DESC (ignore_oc, "ignore bog
 #include "ehci.h"
 #include "ehci-dbg.c"
 
+static int alantest;
+
 /*-------------------------------------------------------------------------*/
 
 static void
@@ -301,12 +303,19 @@ static void ehci_iaa_watchdog(unsigned l
 	unsigned long		flags;
 
 	spin_lock_irqsave (&ehci->lock, flags);
+	if (alantest == 2)
+		alantest = 3;
 
 	/* Lost IAA irqs wedge things badly; seen first with a vt8235.
 	 * So we need this watchdog, but must protect it against both
 	 * (a) SMP races against real IAA firing and retriggering, and
 	 * (b) clean HC shutdown, when IAA watchdog was pending.
 	 */
+	if (alantest == 3)
+		ehci_info(ehci, "IAA watchdog: reclaim %p pending %d state %d\n",
+				ehci->reclaim,
+				timer_pending(&ehci->iaa_watchdog),
+				ehci_to_hcd(ehci)->state);
 	if (ehci->reclaim
 			&& !timer_pending(&ehci->iaa_watchdog)
 			&& HC_IS_RUNNING(ehci_to_hcd(ehci)->state)) {
@@ -337,9 +346,15 @@ static void ehci_iaa_watchdog(unsigned l
 
 		ehci_vdbg(ehci, "IAA watchdog: status %x cmd %x\n",
 				status, cmd);
+		if (alantest == 3)
+			ehci_info(ehci, "IAA watchdog: status %x cmd %x\n",
+					status, cmd);
+
 		end_unlink_async(ehci);
 	}
 
+	if (alantest == 3)
+		alantest = 0;
 	spin_unlock_irqrestore(&ehci->lock, flags);
 }
 
@@ -729,6 +744,8 @@ static irqreturn_t ehci_irq (struct usb_
 					&ehci->regs->command);
 			ehci_dbg(ehci, "IAA with IAAD still set?\n");
 		}
+		if (alantest == 2)
+			ehci_info(ehci, "IAA: reclaim %p\n", ehci->reclaim);
 		if (ehci->reclaim) {
 			COUNT(ehci->stats.reclaim);
 			end_unlink_async(ehci);
@@ -864,6 +881,8 @@ static void unlink_async (struct ehci_hc
 			continue;
 		qh->qh_state = QH_STATE_UNLINK_WAIT;
 		last->reclaim = qh;
+		if (alantest == 2)
+			ehci_info(ehci, "unlink_async: add to reclaim\n");
 
 	/* start IAA cycle */
 	} else
@@ -891,6 +910,10 @@ static int ehci_urb_dequeue(struct usb_h
 	// case PIPE_BULK:
 	default:
 		qh = (struct ehci_qh *) urb->hcpriv;
+		if (alantest == 1) {
+			alantest = 2;
+			ehci_info(ehci, "dequeue: qh %p\n", qh);
+		}
 		if (!qh)
 			break;
 		switch (qh->qh_state) {
Index: usb-2.6/drivers/usb/host/ehci-pci.c
===================================================================
--- usb-2.6.orig/drivers/usb/host/ehci-pci.c
+++ usb-2.6/drivers/usb/host/ehci-pci.c
@@ -314,6 +314,8 @@ static int ehci_pci_resume(struct usb_hc
 	struct ehci_hcd		*ehci = hcd_to_ehci(hcd);
 	struct pci_dev		*pdev = to_pci_dev(hcd->self.controller);
 
+	if (alantest == 0)
+		alantest = 1;
 	// maybe restore FLADJ
 
 	if (time_before(jiffies, ehci->next_statechange))
Index: usb-2.6/drivers/usb/host/ehci-q.c
===================================================================
--- usb-2.6.orig/drivers/usb/host/ehci-q.c
+++ usb-2.6/drivers/usb/host/ehci-q.c
@@ -453,6 +453,8 @@ halt:
 		/* reinit the xacterr counter for the next qtd */
 		qh->xacterrs = QH_XACTERR_MAX;
 	}
+	if (alantest == 3)
+		ehci_info(ehci, "qh_completions: qh %p last %p\n", qh, last);
 
 	/* last urb's completion might still need calling */
 	if (likely (last != NULL)) {
@@ -1062,7 +1064,13 @@ static void end_unlink_async (struct ehc
 	ehci->reclaim = next;
 	qh->reclaim = NULL;
 
+	if (alantest == 2) {
+		alantest = 3;
+		ehci_info(ehci, "end_unlink_async: qh %p\n", qh);
+	}
 	qh_completions (ehci, qh);
+	if (alantest == 3)
+		alantest = 0;
 
 	if (!list_empty (&qh->qtd_list)
 			&& HC_IS_RUNNING (ehci_to_hcd(ehci)->state))
@@ -1131,6 +1139,8 @@ static void start_unlink_async (struct e
 		/* if (unlikely (qh->reclaim != 0))
 		 *	this will recurse, probably not much
 		 */
+		if (alantest == 2)
+			ehci_info(ehci, "start_unlink_async: halted\n");
 		end_unlink_async (ehci);
 		return;
 	}
@@ -1139,6 +1149,8 @@ static void start_unlink_async (struct e
 	ehci_writel(ehci, cmd, &ehci->regs->command);
 	(void)ehci_readl(ehci, &ehci->regs->command);
 	iaa_watchdog_start(ehci);
+	if (alantest == 2)
+		ehci_info(ehci, "start_unlink_async: IAA started\n");
 }
 
 /*-------------------------------------------------------------------------*/

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Brandon Philips]

On 15:46 Wed 11 Mar 2009, Alan Stern wrote:
> On Wed, 11 Mar 2009, Brandon Philips wrote:
> Okay, here's a diagnostic patch meant to apply on top of 
> gregkh-all-2.6.29-rc7.  Let's see what it says...

Here is the log:
 http://ifup.org/~philips/467317/pearl-alan-debug.log

>  	default:
>  		qh = (struct ehci_qh *) urb->hcpriv;
> +		if (alantest == 1) {
> +			alantest = 2;
> +			ehci_info(ehci, "dequeue: qh %p\n", qh);
> +		}

This was the last thing printed before I dumped the task states with sysrq
keys.

Thanks,

	Brandon

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Alan Stern]

On Wed, 11 Mar 2009, Brandon Philips wrote:

> On 15:46 Wed 11 Mar 2009, Alan Stern wrote:
> > On Wed, 11 Mar 2009, Brandon Philips wrote:
> > Okay, here's a diagnostic patch meant to apply on top of 
> > gregkh-all-2.6.29-rc7.  Let's see what it says...
> 
> Here is the log:
>  http://ifup.org/~philips/467317/pearl-alan-debug.log
> 
> >  	default:
> >  		qh = (struct ehci_qh *) urb->hcpriv;
> > +		if (alantest == 1) {
> > +			alantest = 2;
> > +			ehci_info(ehci, "dequeue: qh %p\n", qh);
> > +		}
> 
> This was the last thing printed before I dumped the task states with sysrq
> keys.

Okay, not much information there but it's a start.  Here's a more 
informative patch to try instead.

Alan Stern



Index: usb-2.6/drivers/usb/host/ehci-hcd.c
===================================================================
--- usb-2.6.orig/drivers/usb/host/ehci-hcd.c
+++ usb-2.6/drivers/usb/host/ehci-hcd.c
@@ -108,6 +108,8 @@ MODULE_PARM_DESC (ignore_oc, "ignore bog
 #include "ehci.h"
 #include "ehci-dbg.c"
 
+static int alantest;
+
 /*-------------------------------------------------------------------------*/
 
 static void
@@ -301,12 +303,19 @@ static void ehci_iaa_watchdog(unsigned l
 	unsigned long		flags;
 
 	spin_lock_irqsave (&ehci->lock, flags);
+	if (alantest == 2)
+		alantest = 3;
 
 	/* Lost IAA irqs wedge things badly; seen first with a vt8235.
 	 * So we need this watchdog, but must protect it against both
 	 * (a) SMP races against real IAA firing and retriggering, and
 	 * (b) clean HC shutdown, when IAA watchdog was pending.
 	 */
+	if (alantest == 3)
+		ehci_info(ehci, "IAA watchdog: reclaim %p pending %d state %d\n",
+				ehci->reclaim,
+				timer_pending(&ehci->iaa_watchdog),
+				ehci_to_hcd(ehci)->state);
 	if (ehci->reclaim
 			&& !timer_pending(&ehci->iaa_watchdog)
 			&& HC_IS_RUNNING(ehci_to_hcd(ehci)->state)) {
@@ -337,9 +346,15 @@ static void ehci_iaa_watchdog(unsigned l
 
 		ehci_vdbg(ehci, "IAA watchdog: status %x cmd %x\n",
 				status, cmd);
+		if (alantest == 3)
+			ehci_info(ehci, "IAA watchdog: status %x cmd %x\n",
+					status, cmd);
+
 		end_unlink_async(ehci);
 	}
 
+	if (alantest == 3)
+		alantest = 0;
 	spin_unlock_irqrestore(&ehci->lock, flags);
 }
 
@@ -729,6 +744,8 @@ static irqreturn_t ehci_irq (struct usb_
 					&ehci->regs->command);
 			ehci_dbg(ehci, "IAA with IAAD still set?\n");
 		}
+		if (alantest == 2)
+			ehci_info(ehci, "IAA: reclaim %p\n", ehci->reclaim);
 		if (ehci->reclaim) {
 			COUNT(ehci->stats.reclaim);
 			end_unlink_async(ehci);
@@ -847,12 +864,17 @@ static int ehci_urb_enqueue (
 static void unlink_async (struct ehci_hcd *ehci, struct ehci_qh *qh)
 {
 	/* failfast */
-	if (!HC_IS_RUNNING(ehci_to_hcd(ehci)->state) && ehci->reclaim)
+	if (!HC_IS_RUNNING(ehci_to_hcd(ehci)->state) && ehci->reclaim) {
+		if (alantest == 2)
+			ehci_info(ehci, "call end_unlink_async\n");
 		end_unlink_async(ehci);
+	}
 
 	/* if it's not linked then there's nothing to do */
-	if (qh->qh_state != QH_STATE_LINKED)
-		;
+	if (qh->qh_state != QH_STATE_LINKED) {
+		if (alantest == 2)
+			ehci_info(ehci, "not linked\n");
+	}
 
 	/* defer till later if busy */
 	else if (ehci->reclaim) {
@@ -864,10 +886,15 @@ static void unlink_async (struct ehci_hc
 			continue;
 		qh->qh_state = QH_STATE_UNLINK_WAIT;
 		last->reclaim = qh;
+		if (alantest == 2)
+			ehci_info(ehci, "unlink_async: add to reclaim\n");
 
 	/* start IAA cycle */
-	} else
+	} else {
+		if (alantest == 2)
+			ehci_info(ehci, "call start_unlink_async\n");
 		start_unlink_async (ehci, qh);
+	}
 }
 
 /* remove from hardware lists
@@ -891,16 +918,28 @@ static int ehci_urb_dequeue(struct usb_h
 	// case PIPE_BULK:
 	default:
 		qh = (struct ehci_qh *) urb->hcpriv;
+		if (alantest == 1) {
+			alantest = 2;
+			ehci_info(ehci, "dequeue: qh %p state %d\n", qh,
+				qh->qh_state);
+		}
 		if (!qh)
 			break;
 		switch (qh->qh_state) {
 		case QH_STATE_LINKED:
 		case QH_STATE_COMPLETING:
+			if (alantest == 2)
+				ehci_info(ehci, "call unlink_async\n");
 			unlink_async(ehci, qh);
 			break;
 		case QH_STATE_UNLINK:
 		case QH_STATE_UNLINK_WAIT:
 			/* already started */
+			if (alantest == 2) {
+				alantest = 3;
+				ehci_info(ehci, "unlink already started, pending %d\n",
+					timer_pending(&ehci->iaa_watchdog));
+			}
 			break;
 		case QH_STATE_IDLE:
 			WARN_ON(1);
Index: usb-2.6/drivers/usb/host/ehci-pci.c
===================================================================
--- usb-2.6.orig/drivers/usb/host/ehci-pci.c
+++ usb-2.6/drivers/usb/host/ehci-pci.c
@@ -314,6 +314,8 @@ static int ehci_pci_resume(struct usb_hc
 	struct ehci_hcd		*ehci = hcd_to_ehci(hcd);
 	struct pci_dev		*pdev = to_pci_dev(hcd->self.controller);
 
+	if (alantest == 0)
+		alantest = 1;
 	// maybe restore FLADJ
 
 	if (time_before(jiffies, ehci->next_statechange))
Index: usb-2.6/drivers/usb/host/ehci-q.c
===================================================================
--- usb-2.6.orig/drivers/usb/host/ehci-q.c
+++ usb-2.6/drivers/usb/host/ehci-q.c
@@ -453,6 +453,8 @@ halt:
 		/* reinit the xacterr counter for the next qtd */
 		qh->xacterrs = QH_XACTERR_MAX;
 	}
+	if (alantest == 3)
+		ehci_info(ehci, "qh_completions: qh %p last %p\n", qh, last);
 
 	/* last urb's completion might still need calling */
 	if (likely (last != NULL)) {
@@ -1062,7 +1064,13 @@ static void end_unlink_async (struct ehc
 	ehci->reclaim = next;
 	qh->reclaim = NULL;
 
+	if (alantest == 2) {
+		alantest = 3;
+		ehci_info(ehci, "end_unlink_async: qh %p\n", qh);
+	}
 	qh_completions (ehci, qh);
+	if (alantest == 3)
+		alantest = 0;
 
 	if (!list_empty (&qh->qtd_list)
 			&& HC_IS_RUNNING (ehci_to_hcd(ehci)->state))
@@ -1131,6 +1139,8 @@ static void start_unlink_async (struct e
 		/* if (unlikely (qh->reclaim != 0))
 		 *	this will recurse, probably not much
 		 */
+		if (alantest == 2)
+			ehci_info(ehci, "start_unlink_async: halted\n");
 		end_unlink_async (ehci);
 		return;
 	}
@@ -1139,6 +1149,8 @@ static void start_unlink_async (struct e
 	ehci_writel(ehci, cmd, &ehci->regs->command);
 	(void)ehci_readl(ehci, &ehci->regs->command);
 	iaa_watchdog_start(ehci);
+	if (alantest == 2)
+		ehci_info(ehci, "start_unlink_async: IAA started\n");
 }
 
 /*-------------------------------------------------------------------------*/

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Brandon Philips]

On 10:35 Fri 13 Mar 2009, Alan Stern wrote:
> On Wed, 11 Mar 2009, Brandon Philips wrote:
> 
> > On 15:46 Wed 11 Mar 2009, Alan Stern wrote:
> > > On Wed, 11 Mar 2009, Brandon Philips wrote:
> > > Okay, here's a diagnostic patch meant to apply on top of 
> > > gregkh-all-2.6.29-rc7.  Let's see what it says...
> > 
> > Here is the log:
> >  http://ifup.org/~philips/467317/pearl-alan-debug.log
> > 
> > >  	default:
> > >  		qh = (struct ehci_qh *) urb->hcpriv;
> > > +		if (alantest == 1) {
> > > +			alantest = 2;
> > > +			ehci_info(ehci, "dequeue: qh %p\n", qh);
> > > +		}
> > 
> > This was the last thing printed before I dumped the task states with sysrq
> > keys.
> 
> Okay, not much information there but it's a start.  Here's a more 
> informative patch to try instead.

Here is the log:
 http://ifup.org/~philips/467317/pearl-alan-debug-2.log

Thanks,

	Brandon

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Alan Stern]

On Fri, 13 Mar 2009, Brandon Philips wrote:

> > Okay, not much information there but it's a start.  Here's a more 
> > informative patch to try instead.
> 
> Here is the log:
>  http://ifup.org/~philips/467317/pearl-alan-debug-2.log

I still can't tell what's happening.  Here's yet another patch.

Alan Stern



Index: usb-2.6/drivers/usb/host/ehci-hcd.c
===================================================================
--- usb-2.6.orig/drivers/usb/host/ehci-hcd.c
+++ usb-2.6/drivers/usb/host/ehci-hcd.c
@@ -108,6 +108,8 @@ MODULE_PARM_DESC (ignore_oc, "ignore bog
 #include "ehci.h"
 #include "ehci-dbg.c"
 
+static int alantest;
+
 /*-------------------------------------------------------------------------*/
 
 static void
@@ -301,12 +303,19 @@ static void ehci_iaa_watchdog(unsigned l
 	unsigned long		flags;
 
 	spin_lock_irqsave (&ehci->lock, flags);
+	if (alantest == 2)
+		alantest = 3;
 
 	/* Lost IAA irqs wedge things badly; seen first with a vt8235.
 	 * So we need this watchdog, but must protect it against both
 	 * (a) SMP races against real IAA firing and retriggering, and
 	 * (b) clean HC shutdown, when IAA watchdog was pending.
 	 */
+	if (alantest > 0)
+		ehci_info(ehci, "IAA watchdog: reclaim %p pending %d state %d\n",
+				ehci->reclaim,
+				timer_pending(&ehci->iaa_watchdog),
+				ehci_to_hcd(ehci)->state);
 	if (ehci->reclaim
 			&& !timer_pending(&ehci->iaa_watchdog)
 			&& HC_IS_RUNNING(ehci_to_hcd(ehci)->state)) {
@@ -337,9 +346,15 @@ static void ehci_iaa_watchdog(unsigned l
 
 		ehci_vdbg(ehci, "IAA watchdog: status %x cmd %x\n",
 				status, cmd);
+		if (alantest > 0)
+			ehci_info(ehci, "IAA watchdog: status %x cmd %x\n",
+					status, cmd);
+
 		end_unlink_async(ehci);
 	}
 
+	if (alantest == 3)
+		alantest = 0;
 	spin_unlock_irqrestore(&ehci->lock, flags);
 }
 
@@ -729,6 +744,8 @@ static irqreturn_t ehci_irq (struct usb_
 					&ehci->regs->command);
 			ehci_dbg(ehci, "IAA with IAAD still set?\n");
 		}
+		if (alantest > 0)
+			ehci_info(ehci, "IAA: reclaim %p\n", ehci->reclaim);
 		if (ehci->reclaim) {
 			COUNT(ehci->stats.reclaim);
 			end_unlink_async(ehci);
@@ -846,13 +863,21 @@ static int ehci_urb_enqueue (
 
 static void unlink_async (struct ehci_hcd *ehci, struct ehci_qh *qh)
 {
+	if (alantest > 0)
+		ehci_info(ehci, "unlink_async: qh %p state %d\n",
+			qh, qh->qh_state);
 	/* failfast */
-	if (!HC_IS_RUNNING(ehci_to_hcd(ehci)->state) && ehci->reclaim)
+	if (!HC_IS_RUNNING(ehci_to_hcd(ehci)->state) && ehci->reclaim) {
+		if (alantest > 0)
+			ehci_info(ehci, "call end_unlink_async\n");
 		end_unlink_async(ehci);
+	}
 
 	/* if it's not linked then there's nothing to do */
-	if (qh->qh_state != QH_STATE_LINKED)
-		;
+	if (qh->qh_state != QH_STATE_LINKED) {
+		if (alantest > 0)
+			ehci_info(ehci, "not linked\n");
+	}
 
 	/* defer till later if busy */
 	else if (ehci->reclaim) {
@@ -864,10 +889,15 @@ static void unlink_async (struct ehci_hc
 			continue;
 		qh->qh_state = QH_STATE_UNLINK_WAIT;
 		last->reclaim = qh;
+		if (alantest > 0)
+			ehci_info(ehci, "unlink_async: add to reclaim\n");
 
 	/* start IAA cycle */
-	} else
+	} else {
+		if (alantest > 0)
+			ehci_info(ehci, "call start_unlink_async\n");
 		start_unlink_async (ehci, qh);
+	}
 }
 
 /* remove from hardware lists
@@ -891,16 +921,28 @@ static int ehci_urb_dequeue(struct usb_h
 	// case PIPE_BULK:
 	default:
 		qh = (struct ehci_qh *) urb->hcpriv;
+		if (alantest == 1) {
+			alantest = 2;
+			ehci_info(ehci, "dequeue: urb %p qh %p state %d\n",
+				urb, qh, qh->qh_state);
+		}
 		if (!qh)
 			break;
 		switch (qh->qh_state) {
 		case QH_STATE_LINKED:
 		case QH_STATE_COMPLETING:
+			if (alantest > 0)
+				ehci_info(ehci, "call unlink_async\n");
 			unlink_async(ehci, qh);
 			break;
 		case QH_STATE_UNLINK:
 		case QH_STATE_UNLINK_WAIT:
 			/* already started */
+			if (alantest == 2) {
+				alantest = 3;
+				ehci_info(ehci, "unlink already started, pending %d\n",
+					timer_pending(&ehci->iaa_watchdog));
+			}
 			break;
 		case QH_STATE_IDLE:
 			WARN_ON(1);
Index: usb-2.6/drivers/usb/host/ehci-pci.c
===================================================================
--- usb-2.6.orig/drivers/usb/host/ehci-pci.c
+++ usb-2.6/drivers/usb/host/ehci-pci.c
@@ -314,6 +314,8 @@ static int ehci_pci_resume(struct usb_hc
 	struct ehci_hcd		*ehci = hcd_to_ehci(hcd);
 	struct pci_dev		*pdev = to_pci_dev(hcd->self.controller);
 
+	if (alantest == 0)
+		alantest = 1;
 	// maybe restore FLADJ
 
 	if (time_before(jiffies, ehci->next_statechange))
Index: usb-2.6/drivers/usb/host/ehci-q.c
===================================================================
--- usb-2.6.orig/drivers/usb/host/ehci-q.c
+++ usb-2.6/drivers/usb/host/ehci-q.c
@@ -453,9 +453,13 @@ halt:
 		/* reinit the xacterr counter for the next qtd */
 		qh->xacterrs = QH_XACTERR_MAX;
 	}
+	if (alantest > 0)
+		ehci_info(ehci, "qh_completions: qh %p\n", qh);
 
 	/* last urb's completion might still need calling */
 	if (likely (last != NULL)) {
+		if (alantest > 0)
+			ehci_info(ehci, "urb done: urb %p\n", last->urb);
 		ehci_urb_done(ehci, last->urb, last_status);
 		count++;
 		ehci_qtd_free (ehci, last);
@@ -463,6 +467,8 @@ halt:
 
 	/* restore original state; caller must unlink or relink */
 	qh->qh_state = state;
+	if (alantest > 0)
+		ehci_info(ehci, "restore state %d\n", state);
 
 	/* be sure the hardware's done with the qh before refreshing
 	 * it after fault cleanup, or recovering from silicon wrongly
@@ -1034,6 +1040,9 @@ submit_async (
 	 */
 	if (likely (qh->qh_state == QH_STATE_IDLE))
 		qh_link_async (ehci, qh_get (qh));
+	if (alantest > 0)
+		ehci_info(ehci, "submit urb %p qh %p state %d\n",
+			urb, qh, qh->qh_state);
  done:
 	spin_unlock_irqrestore (&ehci->lock, flags);
 	if (unlikely (qh == NULL))
@@ -1062,7 +1071,11 @@ static void end_unlink_async (struct ehc
 	ehci->reclaim = next;
 	qh->reclaim = NULL;
 
+	if (alantest > 0)
+		ehci_info(ehci, "end_unlink_async: qh %p\n", qh);
 	qh_completions (ehci, qh);
+	if (alantest == 2)
+		alantest = 0;
 
 	if (!list_empty (&qh->qtd_list)
 			&& HC_IS_RUNNING (ehci_to_hcd(ehci)->state))
@@ -1131,10 +1144,14 @@ static void start_unlink_async (struct e
 		/* if (unlikely (qh->reclaim != 0))
 		 *	this will recurse, probably not much
 		 */
+		if (alantest > 0)
+			ehci_info(ehci, "start_unlink_async: halted\n");
 		end_unlink_async (ehci);
 		return;
 	}
 
+	if (alantest > 0)
+		ehci_info(ehci, "start_unlink_async: IAA started\n");
 	cmd |= CMD_IAAD;
 	ehci_writel(ehci, cmd, &ehci->regs->command);
 	(void)ehci_readl(ehci, &ehci->regs->command);

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Brandon Philips]

On 14:03 Fri 13 Mar 2009, Alan Stern wrote:
> On Fri, 13 Mar 2009, Brandon Philips wrote:
> 
> > > Okay, not much information there but it's a start.  Here's a more 
> > > informative patch to try instead.
> > 
> > Here is the log:
> >  http://ifup.org/~philips/467317/pearl-alan-debug-2.log
> 
> I still can't tell what's happening.  Here's yet another patch.

http://ifup.org/~philips/467317/pearl-alan-debug-3.log

Thanks, Brandon

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Alan Stern]

On Fri, 13 Mar 2009, Brandon Philips wrote:

> On 14:03 Fri 13 Mar 2009, Alan Stern wrote:
> > On Fri, 13 Mar 2009, Brandon Philips wrote:
> > 
> > > > Okay, not much information there but it's a start.  Here's a more 
> > > > informative patch to try instead.
> > > 
> > > Here is the log:
> > >  http://ifup.org/~philips/467317/pearl-alan-debug-2.log
> > 
> > I still can't tell what's happening.  Here's yet another patch.
> 
> http://ifup.org/~philips/467317/pearl-alan-debug-3.log

I think I see the problem; the patch below is an attempted fix.
Hopefully it will get your system working.

Alan Stern



Index: usb-2.6/drivers/usb/host/ehci-q.c
===================================================================
--- usb-2.6.orig/drivers/usb/host/ehci-q.c
+++ usb-2.6/drivers/usb/host/ehci-q.c
@@ -1127,7 +1127,7 @@ static void start_unlink_async (struct e
 	prev->qh_next = qh->qh_next;
 	wmb ();
 
-	if (unlikely (ehci_to_hcd(ehci)->state == HC_STATE_HALT)) {
+	if (unlikely(!HC_IS_RUNNING(ehci_to_hcd(ehci)->state))) {
 		/* if (unlikely (qh->reclaim != 0))
 		 *	this will recurse, probably not much
 		 */

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Brandon Philips]

On 16:50 Fri 13 Mar 2009, Alan Stern wrote:
> On Fri, 13 Mar 2009, Brandon Philips wrote:
> 
> > On 14:03 Fri 13 Mar 2009, Alan Stern wrote:
> > > On Fri, 13 Mar 2009, Brandon Philips wrote:
> > > 
> > > > > Okay, not much information there but it's a start.  Here's a more 
> > > > > informative patch to try instead.
> > > > 
> > > > Here is the log:
> > > >  http://ifup.org/~philips/467317/pearl-alan-debug-2.log
> > > 
> > > I still can't tell what's happening.  Here's yet another patch.
> > 
> > http://ifup.org/~philips/467317/pearl-alan-debug-3.log
> 
> I think I see the problem; the patch below is an attempted fix.
> Hopefully it will get your system working.

That fixes it, thanks. This was originally found in a 2.6.27 based
Kernel so the fix can go off to stable@ too.

Tested-by: Brandon Philips <bphilips@suse.de>

> Index: usb-2.6/drivers/usb/host/ehci-q.c
> ===================================================================
> --- usb-2.6.orig/drivers/usb/host/ehci-q.c
> +++ usb-2.6/drivers/usb/host/ehci-q.c
> @@ -1127,7 +1127,7 @@ static void start_unlink_async (struct e
>  	prev->qh_next = qh->qh_next;
>  	wmb ();
>  
> -	if (unlikely (ehci_to_hcd(ehci)->state == HC_STATE_HALT)) {
> +	if (unlikely(!HC_IS_RUNNING(ehci_to_hcd(ehci)->state))) {
>  		/* if (unlikely (qh->reclaim != 0))
>  		 *	this will recurse, probably not much
>  		 */
> 

Re: S4 hang with uvcvideo causing "Unlink after no-IRQ? Controller is probably using the wrong IRQ."

[Alan Stern]

On Fri, 6 Mar 2009, Greg KH wrote:

> On Fri, Mar 06, 2009 at 11:11:22AM -0800, Brandon Philips wrote:
> > Hello-
> > 
> > When an UVC device is open and a S4 is attempted the thaw hangs (see the
> > stack below). I don't see what the UVC driver is doing wrong to cause
> > this to happen though.
> 
> I don't think this is a uvc driver issue, it looks like all you are
> trying to do is a usb control message when things hang.

Agreed.

> But the problem is the khubd is asleep, from your log file:
> 
> khubd         D 0000000000000000     0   255      2
>  ffff880037509d80 0000000000000046 ffff88007864ba80 ffffffff8088fcf8
>  ffffffff80816f00 ffffffff80816f00 ffff8800375b0380 ffff8800375b06f8
>  0000000080816f00 ffff88007bb9c040 ffff8800375b0380 ffff8800375b06f8
> Call Trace:
>  [<ffffffff802253a5>] ? default_spin_lock_flags+0x17/0x1a
>  [<ffffffff8025e7a9>] refrigerator+0x170/0x1cf
>  [<ffffffffa01187ab>] hub_thread+0x1370/0x13bd [usbcore]
>  [<ffffffff8020a7c2>] ? __switch_to+0xd4/0x4b3
>  [<ffffffff80258ca4>] ? autoremove_wake_function+0x0/0x38
>  [<ffffffffa011743b>] ? hub_thread+0x0/0x13bd [usbcore]
>  [<ffffffff8025890b>] kthread+0x49/0x76
>  [<ffffffff8020d69a>] child_rip+0xa/0x20
>  [<ffffffff802588c2>] ? kthread+0x0/0x76
>  [<ffffffff8020d690>] ? child_rip+0x0/0x20
> 
> udevd is also stuck in the refrigerator, which seems wierd as well.
> a.out is also stuck, is that your test program?
> 
> It looks like things die right after this message:
> 	ehci_hcd 0000:00:1d.7: Unlink after no-IRQ?  Controller is probably using the wrong IRQ.
> 
> Alan, what causes this at resume time?

This isn't really resume time.  It's at "thaw" time, which is part of 
hibernation.  After the memory snapshot is created, the system thaws 
all the suspended devices so that the snapshot can be written to disk.  
That's when the hang occurred.

And that's why all those tasks are still in the refrigerator; they
remain there until the end of the resume from hibernation.

Alan Stern