2001-11-18 04:20:10

by Thomas Winischhofer

[permalink] [raw]
Subject: USB-OHCI + USB broken in 2.4.14/15pre2?


Resume from suspend does not work correctly on my machine. Here's what
the log says:

----
Nov 18 04:33:52 oland cardmgr[188]: executing: './network suspend eth1'
Nov 18 04:33:52 oland kernel: usb-ohci.c: USB suspend: usb-00:01.2
Nov 18 04:33:52 oland kernel: NETDEV WATCHDOG: eth1: transmit timed out
Nov 18 04:33:52 oland kernel: eth1: Transmit timeout.
Nov 18 04:33:52 oland kernel: usb-ohci.c: Bus suspended
Nov 18 04:33:52 oland kernel: usb-ohci.c: USB suspend: usb-00:01.3
Nov 18 04:33:53 oland kernel: usb-ohci.c: Bus suspended
Nov 18 04:33:57 oland logger: Storing ALSA mixer settings...done.
Nov 18 04:33:58 oland logger: Shutting down ALSA sound driver (version
0.9.0beta9): done.
Nov 18 04:33:59 oland apmd[349]: User Suspend
Nov 18 04:34:09 oland kernel: usb-ohci.c: odd PCI resume for usb-00:01.2
Nov 18 04:34:09 oland kernel: usb-ohci.c: odd PCI resume for usb-00:01.3
Nov 18 04:34:09 oland kernel: APIC error on CPU0: 00(40)
Nov 18 04:34:10 oland cardmgr[188]: executing: './network resume eth1'
Nov 18 04:34:11 oland logger: ALSA driver (version 0.9.0beta9) is
already running.
Nov 18 04:34:13 oland kernel: PCI: Found IRQ 11 for device 00:01.4
Nov 18 04:34:13 oland kernel: PCI: Sharing IRQ 11 with 00:03.0
Nov 18 04:34:14 oland apmd[349]: Normal Resume after 00:00:15 (99%
unknown) AC power
----

(Don't care about eth1 errors. ALSA doesn't matter either, although I
never saw this behavior (driver already running after stopping them?!)
before I started using the USB drivers. However, don't bother....)

Anyway: Machine gets up, but - needless to say - my usb mouse (or any
other usb device) does not work after resume:

----
Nov 18 04:44:40 oland kernel: hub.c: USB new device connect on bus2/1,
assigned device number 2
Nov 18 04:44:43 oland kernel: usb_control/bulk_msg: timeout
Nov 18 04:44:43 oland kernel: usb-ohci.c: unlink URB timeout
Nov 18 04:44:43 oland kernel: usb.c: USB device not accepting new
address=2 (error=-110)
Nov 18 04:44:43 oland kernel: hub.c: USB new device connect on bus2/1,
assigned device number 3
Nov 18 04:44:46 oland kernel: usb_control/bulk_msg: timeout
Nov 18 04:44:46 oland kernel: usb-ohci.c: unlink URB timeout
Nov 18 04:44:46 oland kernel: usb.c: USB device not accepting new
address=3 (error=-110)
----

The APIC error (shown in the first log) does not appear if I compile the
kernel without APIC (duh!). Situation regarding the USB is the same in
either case.

Although the bus gets suspended (ohci_pci_suspend() works correctly, I
doublechecked this by simply replacing dbg() with info() in
ohci_pci_suspend(), thus the log entry at 04:33:53), it seems that the
control flags are for some reason (already) set to OHCI_USB_OPER (as the
only value capable of causing "odd PCI resume" messages) when the resume
procedure in usb_ohci.c is called.

I tried to "recover" this behavior by temporarily patching
ohci_pci_resume() so that it does a brutal hc_restart(ohci) instead of
nothing when detecting this "odd PCI resume" situation - without any
success.

Configuration (imho relevant parts):

Laptop (Celeron 1Ghz) with SiS630 chipset, including two SiS 7001 USB
controllers. USB controllers share IRQ (11) with cardbus and sound (and
unused winmodem).

# lspci -vv
00:01.2 USB Controller: Silicon Integrated Systems [SiS] 7001 (rev 07)
(prog-if 10 [OHCI])
Subsystem: Silicon Integrated Systems [SiS] 7001
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV+ VGASnoop- ParErr-
Stepping- SERR+ FastB2B-
Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
Latency: 32 (20000ns max), cache line size 08
Interrupt: pin D routed to IRQ 11
Region 0: Memory at dffd0000 (32-bit, non-prefetchable) [size=4K]

00:01.3 USB Controller: Silicon Integrated Systems [SiS] 7001 (rev 07)
(prog-if 10 [OHCI])
Subsystem: Silicon Integrated Systems [SiS]: Unknown device 7000
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV+ VGASnoop- ParErr-
Stepping- SERR+ FastB2B-
Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
Latency: 32 (20000ns max), cache line size 08
Interrupt: pin D routed to IRQ 11
Region 0: Memory at dffe0000 (32-bit, non-prefetchable) [size=4K]

I am running kernel 2.4.15pre2 but I did not see any relevant changes in
usb-ohci since then up to pre6.

Any further information will, of course, be supplied on request.

The Usual Questions(tm): Did I miss anything obvious? Is this a known
bug? Any ideas?

Thomas

--
Thomas Winischhofer
Vienna/Austria Check it out:
mailto:[email protected] *** http://www.webit.com/tw


2001-11-18 06:23:38

by Linus Torvalds

[permalink] [raw]
Subject: Re: USB-OHCI + USB broken in 2.4.14/15pre2?

In article <[email protected]> you write:
>
>I tried to "recover" this behavior by temporarily patching
>ohci_pci_resume() so that it does a brutal hc_restart(ohci) instead of
>nothing when detecting this "odd PCI resume" situation - without any
>success.

I would suggest trying to do a "pci_enable_device(dev);" at the very top
of ohci_pci_resume(). It sounds like your suspend/resume doesn't
re-enable PCI interrupt routing, and doing the device enable will make
the kernel re-route the interrupt for you.

If that helps, please send me the tested patch, and forward it to the
appropriate USB people too.

Linus

2001-11-18 13:30:11

by Thomas Winischhofer

[permalink] [raw]
Subject: Re: USB-OHCI + USB broken in 2.4.14/15pre2?

Linus Torvalds wrote:
> In article <[email protected]> you write:
> >
> >I tried to "recover" this behavior by temporarily patching
> >ohci_pci_resume() so that it does a brutal hc_restart(ohci) instead of
> >nothing when detecting this "odd PCI resume" situation - without any
> >success.

> I would suggest trying to do a "pci_enable_device(dev);" at the
> very top of ohci_pci_resume(). It sounds like your suspend/resume doesn't
> re-enable PCI interrupt routing, and doing the device enable will make
> the kernel re-route the interrupt for you. If that helps, please send me
> the tested patch, and forward it to the appropriate USB people too.

Kiitos/tack; however, to make it actually work on my particular machine
I needed to

1) call hc_restart(ohci) in default section of switch statement AND

2) like you said, insert "pci_enable_device(dev);" right after the
declarations in ohci_pci_resume(). (I think this should be done after
the check for concurrent resumes, anyway).

This is what the log says this time:

----
Nov 18 13:40:46 oland cardmgr[189]: executing: './network suspend eth1'
Nov 18 13:40:46 oland kernel: usb-ohci.c: USB suspend: usb-00:01.2
Nov 18 13:40:46 oland kernel: NETDEV WATCHDOG: eth1: transmit timed out
Nov 18 13:40:46 oland kernel: eth1: Transmit timeout.
Nov 18 13:40:46 oland kernel: usb-ohci.c: Bus suspended
Nov 18 13:40:46 oland kernel: usb-ohci.c: USB suspend: usb-00:01.3
Nov 18 13:40:47 oland kernel: usb-ohci.c: Bus suspended
Nov 18 13:40:51 oland logger: Storing ALSA mixer settings...done.
Nov 18 13:40:52 oland logger: Shutting down ALSA sound driver (version
0.9.0beta9): done.
Nov 18 13:40:53 oland apmd[350]: User Suspend
Nov 18 13:40:57 oland kernel: PCI: Found IRQ 11 for device 00:01.2
Nov 18 13:40:57 oland kernel: PCI: Sharing IRQ 11 with 00:01.3
Nov 18 13:40:57 oland kernel: usb-ohci.c: odd PCI resume for usb-00:01.2
Nov 18 13:40:57 oland kernel: usb.c: USB disconnect on device 1
Nov 18 13:40:58 oland kernel: hub.c: USB hub found
Nov 18 13:40:58 oland kernel: hub.c: 3 ports detected
Nov 18 13:40:58 oland kernel: PCI: Found IRQ 11 for device 00:01.3
Nov 18 13:40:58 oland kernel: PCI: Sharing IRQ 11 with 00:01.2
Nov 18 13:40:58 oland kernel: usb-ohci.c: odd PCI resume for usb-00:01.3
Nov 18 13:40:58 oland kernel: usb.c: USB disconnect on device 1
Nov 18 13:40:58 oland kernel: usb.c: USB disconnect on device 2
Nov 18 13:40:58 oland kernel: usb-ohci.c: TD leak, 1
Nov 18 13:40:58 oland kernel: hub.c: USB hub found
Nov 18 13:40:58 oland kernel: hub.c: 3 ports detected
Nov 18 13:40:58 oland kernel: APIC error on CPU0: 00(40)
Nov 18 13:40:59 oland cardmgr[189]: executing: './network resume eth1'
Nov 18 13:41:00 oland kernel: hub.c: USB new device connect on bus2/1,
assigned device number 4
Nov 18 13:41:00 oland kernel: input0: USB HID v1.10 Mouse [Logitech USB
Mouse] on usb2:4.0
Nov 18 13:41:00 oland logger: ALSA driver (version 0.9.0beta9) is
already running.
Nov 18 13:41:01 oland kernel: PCI: Found IRQ 11 for device 00:01.4
Nov 18 13:41:01 oland kernel: PCI: Sharing IRQ 11 with 00:03.0
Nov 18 13:41:03 oland apmd[350]: Normal Resume after 00:00:10 (99%
unknown) AC power
Nov 18 13:41:04 oland logger: ALSA driver (version 0.9.0beta9) is
already running.
Nov 18 13:41:05 oland apmd[350]: Normal Resume after 00:00:12 (99%
unknown) AC power
----

As you can see, the APIC error still shows up in the log, although AFTER
hub.c says that it found a hub a the ports (ie. after
re-initialization).

Wondering what "TD leak, 1" means...?

I think this is more a dirty work-around than an appropriate solution;
or is it ok to assume that the control flags are corrupted (or reset to
OHCI_USB_OPER) after pci_enable_device() leading into "odd PCI
resume"...? (In this case I would be glad to submit a patch...)

Thomas

--
Thomas Winischhofer
Vienna/Austria Check it out:
mailto:[email protected] *** http://www.webit.com/tw

2001-11-18 19:20:21

by Thomas Winischhofer

[permalink] [raw]
Subject: Re: USB-OHCI + USB broken in 2.4.14/15pre2?



Thomas Winischhofer wrote:
>
> Kiitos/tack; however, to make it actually work on my particular machine
> I needed to
>
> 1) call hc_restart(ohci) in default section of switch statement AND
>
> 2) like you said, insert "pci_enable_device(dev);" right after the
> declarations in ohci_pci_resume(). (I think this should be done after
> the check for concurrent resumes, anyway).

WRONG. This does as a matter of fact _not_ work:

When a device is connected to the bus at the time of suspend, using my
somewhat brutal method recovers that device at resume from suspend. So
far so good.

But: When there's _no_ device connected to the usb at the time of
suspend, the bus does NOT recover properly and produces errors after
resume whenever I try to connect a device.

Here's what I did:

----
--- /root/usb-ohci.c Sun Nov 18 19:26:00 2001
+++ /usr/src/linux/drivers/usb/usb-ohci.c Sun Nov 18 19:37:27 2001
@@ -2678,16 +2678,16 @@
mdelay (500); /* No schedule here ! */
switch (readl (&ohci->regs->control) & OHCI_CTRL_HCFS) {
case OHCI_USB_RESET: /* dbg statt info!/TW */
- dbg("Bus in reset phase ???");
+ info("Bus in reset phase ???");
break;
case OHCI_USB_RESUME:
- dbg("Bus in resume phase ???");
+ info("Bus in resume phase ???");
break;
case OHCI_USB_OPER:
- dbg("Bus in operational phase ???");
+ info("Bus in operational phase ???");
break;
case OHCI_USB_SUSPEND:
- dbg("Bus suspended");
+ info("Bus suspended");
break;
}
/* In some rare situations, Apple's OHCI have happily trashed
@@ -2719,6 +2719,8 @@
int temp;
unsigned long flags;

+ pci_enable_device(dev);
+
/* guard against multiple resumes */
atomic_inc (&ohci->resume_count);
if (atomic_read (&ohci->resume_count) != 1) {
@@ -2812,6 +2814,7 @@

default:
warn ("odd PCI resume for usb-%s", dev->slot_name);
+ hc_restart (ohci);
}

/* controller is operational, extra resumes are harmless */

----

The log:

---- suspending:
Nov 18 19:45:00 oland cardmgr[189]: executing: './network suspend eth1'
Nov 18 19:45:00 oland kernel: NETDEV WATCHDOG: eth1: transmit timed out
Nov 18 19:45:00 oland kernel: eth1: Transmit timeout.
Nov 18 19:45:00 oland kernel: usb-ohci.c: USB suspend: usb-00:01.2
Nov 18 19:45:01 oland kernel: usb-ohci.c: Bus suspended
Nov 18 19:45:01 oland kernel: usb-ohci.c: USB suspend: usb-00:01.3
Nov 18 19:45:01 oland kernel: usb-ohci.c: Bus suspended
Nov 18 19:45:06 oland apmd[350]: User Suspend
----

---- resuming:
Nov 18 19:45:13 oland kernel: PCI: Found IRQ 11 for device 00:01.2
Nov 18 19:45:13 oland kernel: PCI: Sharing IRQ 11 with 00:01.3
Nov 18 19:45:13 oland kernel: usb-ohci.c: odd PCI resume for usb-00:01.2
Nov 18 19:45:13 oland kernel: usb.c: USB disconnect on device 1
Nov 18 19:45:14 oland kernel: hub.c: USB hub found
Nov 18 19:45:14 oland kernel: hub.c: 3 ports detected
Nov 18 19:45:14 oland kernel: PCI: Found IRQ 11 for device 00:01.3
Nov 18 19:45:14 oland kernel: PCI: Sharing IRQ 11 with 00:01.2
Nov 18 19:45:14 oland kernel: usb-ohci.c: odd PCI resume for usb-00:01.3
Nov 18 19:45:14 oland kernel: usb.c: USB disconnect on device 1
Nov 18 19:45:14 oland kernel: hub.c: USB hub found
Nov 18 19:45:14 oland kernel: hub.c: 3 ports detected
Nov 18 19:45:14 oland kernel: APIC error on CPU0: 00(40)
Nov 18 19:45:15 oland cardmgr[189]: executing: './network resume eth1'
Nov 18 19:45:16 oland apmd[350]: Normal Resume after 00:00:10 (99%
unknown) AC power
Nov 18 19:45:17 oland apmd[350]: Normal Resume after 00:00:11 (99%
unknown) AC power
----

(Why resume twice?)

---- connecting device (mouse)
Nov 18 19:45:29 oland kernel: hub.c: USB new device connect on bus1/3,
assigned device number 3
Nov 18 19:45:32 oland kernel: usb_control/bulk_msg: timeout
Nov 18 19:45:32 oland kernel: usb.c: USB device not accepting new
address=3 (error=-110)
Nov 18 19:45:33 oland kernel: hub.c: USB new device connect on bus1/3,
assigned device number 4
Nov 18 19:45:36 oland kernel: usb_control/bulk_msg: timeout
Nov 18 19:45:36 oland kernel: usb.c: USB device not accepting new
address=4 (error=-110)
----

There we are again. What do the ohci gurus say?

Thomas

--
Thomas Winischhofer
Vienna/Austria Check it out:
mailto:[email protected] *** http://www.webit.com/tw

2001-11-19 23:16:10

by Thomas Winischhofer

[permalink] [raw]
Subject: Re: USB-OHCI + USB broken in 2.4.14/15pre2?


Now, I found out how to work around the problem:

The only way seems to be rmmod usb-ohci on suspend, insmod at resume...

This isn't quite a nice way doing.... but it works.

Anyway, can anyone confirm that usb-ohci resumes correctly on similar
hardware? (SiS630 chipset, 2xSiS7001 USB controller)

Thomas

--
Thomas Winischhofer
Vienna/Austria Check it out:
mailto:[email protected] *** http://www.webit.com/tw