2.5.25 uhci-hcd very bad

DISCUSSION Pierre Rousselet 4 participants 9 messages Jul 13, 2002 – Jul 18, 2002

Share & tools

Pierre Rousselet

author

2002-07-13 20:12 UTC #0 lore raw

usb inboard Abit BE6, ADSL modem Speedtouch usb.

I used to use satisfactorily usb-uhci-hcd before 2.5.25, switching to uhci-hcd halts the adsl modem after a few minutes with this message:

kernel: uhci-hcd.c: c000: host controller process error. something bad happened
kernel: uhci-hcd.c: c000: host controller halted. very bad

2.5.24 is not happy too with uhci-hcd.

What should I look at ?

Pierre

Signature · 3 lines

------------------------------------------------
 Pierre Rousselet <[email protected]>
------------------------------------------------

Greg KH

2002-07-17 21:31 UTC #1 lore raw

Quoted 5 lines · Pierre Rousselet

usb inboard Abit BE6, ADSL modem Speedtouch usb.
I used to use satisfactorily usb-uhci-hcd before 2.5.25, switching to uhci-hcd halts the adsl modem after a few minutes with this message:

Quoted 7 lines

kernel: uhci-hcd.c: c000: host controller process error. something bad happened
kernel: uhci-hcd.c: c000: host controller halted. very bad
2.5.24 is not happy too with uhci-hcd.
What should I look at ?

Is this the usbfs userspace ASDL driver? Or the kernel driver?

thanks,

greg k-h

Pierre ROUSSELET

author

2002-07-18 05:32 UTC #2 lore raw

The driver is made of a kernel module speedtch.o (built outside of the tree) and of userspace modem firmware loader and management daemon speedmgt.

Quoted 18 lines

Messsage du 17/07/2002 23:33
De : Greg KH <[email protected]>
A : Pierre Rousselet <[email protected]> Copie à : lkml <[email protected]> Objet : Re: 2.5.25 uhci-hcd very bad
Quoted 11 lines · Pierre Rousselet
usb inboard Abit BE6, ADSL modem Speedtouch usb.
I used to use satisfactorily usb-uhci-hcd before 2.5.25, switching to uhci-hcd halts the adsl modem after a few minutes with this message:
kernel: uhci-hcd.c: c000: host controller process error. something bad happened
kernel: uhci-hcd.c: c000: host controller halted. very bad
2.5.24 is not happy too with uhci-hcd.

Quoted 8 lines

Quoted 1 line
What should I look at ?
Is this the usbfs userspace ASDL driver? Or the kernel driver?
thanks,
greg k-h

Pierre

Greg KH

2002-07-18 06:04 UTC #3 lore raw

Quoted 3 lines · Pierre ROUSSELET

The driver is made of a kernel module speedtch.o (built outside of the tree) and of userspace modem firmware loader and management daemon speedmgt.

I'd suggest asking the authors of the driver about this.

Good luck,

greg k-h

Pierre ROUSSELET

author

2002-07-18 06:33 UTC #4 lore raw

The driver is OK with usb-uhci-hcd up to 2.5.24, you might as well suggest to un-plug it...

Quoted 22 lines

Messsage du 18/07/2002 08:05
De : Greg KH <[email protected]>
A : Pierre ROUSSELET <[email protected]> Copie à : <[email protected]> Objet : Re: 2.5.25 uhci-hcd very bad
Quoted 3 lines · Pierre ROUSSELET
The driver is made of a kernel module speedtch.o (built outside of the tree) and of userspace modem firmware loader and management daemon speedmgt.
I'd suggest asking the authors of the driver about this.
Good luck,
greg k-h
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Peter Osterlund

2002-07-18 11:19 UTC #5 lore raw

In reply to Greg KH

Quoted 6 lines · Greg KH

Quoted 3 lines · Pierre ROUSSELET
The driver is made of a kernel module speedtch.o (built outside of the tree) and of userspace modem firmware loader and management daemon speedmgt.
I'd suggest asking the authors of the driver about this.

I also get the "very bad" message when booting 2.5.25 and 2.5.26, even if no usb devices are connected. From dmesg:

Freeing unused kernel memory: 200k freed
Adding 104824k swap on /dev/hda3. Priority:-1 extents:1 usb.c: registered new driver usbfs
usb.c: registered new driver hub
uhci-hcd.c: USB Universal Host Controller Interface driver v2.0
PCI: Assigned IRQ 10 for device 00:07.2
hcd-pci.c: uhci-hcd @ 00:07.2, Intel Corp. 82371AB PIIX4 USB hcd-pci.c: irq 10, io base 0000f300
hcd.c: new USB bus registered, assigned bus number 1 uhci-hcd.c: detected 2 ports
hcd.c: 00:07.2 root hub device address 1
usb.c: new device strings: Mfr=3, Product=2, SerialNumber=1
Product: Intel Corp. 82371AB PIIX4 USB
Manufacturer: Linux 2.5.26-packet uhci-hcd
SerialNumber: 00:07.2
hub.c: USB hub found at /
hub.c: 2 ports detected
hub.c: standalone hub
hub.c: ganged power switching
hub.c: global over-current protection
hub.c: Port indicators are not supported
hub.c: power on to power good time: 2ms
hub.c: hub controller current requirement: 0mA hub.c: port removable status: RR
hub.c: local power source is good
hub.c: no over-current condition exists
hub.c: enabling power on all ports
usb.c: hub driver claimed interface c10ce460
usb.c: kusbd: /sbin/hotplug add 1
uhci-hcd.c: f300: suspend_hc
uhci-hcd.c: f300: wakeup_hc
uhci-hcd.c: f300: suspend_hc
uhci-hcd.c: f300: wakeup_hc
... (usually repeated about 50 times)
uhci-hcd.c: f300: suspend_hc
uhci-hcd.c: f300: host controller halted. very bad uhci-hcd.c: f300: wakeup_hc

This happens both with preemtible and non-preemtible kernels. I can still use a Freecom usb cdrw drive though, so maybe this is not a problem, even though the message indicates that it is.

I also have a performance problem with the uhci-hcd driver. When writing data to a CDRW in packet writing mode, usb_stor_freecom_reset is called quite often, see logs below. This happens in both 2.5.25 and 2.5.26. I tested with the usb-uhci-hcd driver in 2.5.25 (edited the Makefile) just to rule out kernel changes and other usb changes, but that driver didn't have this problem. I saw one or two freecom reset messages though, so it's possible that the new driver just makes an old problem much more frequent.

pengo:/home/petero# tail -f -n 10000 /var/log/debug | egrep 'Command |reset'
        ...
        Jul 18 12:57:04 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:05 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:05 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:05 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:05 pengo kernel: freecom reset called
        Jul 18 12:57:05 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:06 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:06 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:06 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:07 pengo kernel: freecom reset called
        Jul 18 12:57:07 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:08 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:08 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:08 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:08 pengo kernel: freecom reset called
        Jul 18 12:57:08 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:10 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:10 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:10 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:10 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:11 pengo kernel: freecom reset called
        Jul 18 12:57:11 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:13 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:13 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:13 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:13 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:15 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:15 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:16 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:16 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:16 pengo kernel: freecom reset called
        Jul 18 12:57:16 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:17 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:20 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:20 pengo kernel: freecom reset called
        Jul 18 12:57:20 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:20 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:21 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
        Jul 18 12:57:21 pengo kernel: freecom reset called
        ...

Quoted 1 line

From /var/log/debug:

Jul 18 12:18:11 pengo kernel: usb-storage: queuecommand() called
Jul 18 12:18:11 pengo kernel: usb-storage: *** thread sleeping.
Jul 18 12:18:11 pengo kernel: usb-storage: *** thread awakened.
Jul 18 12:18:11 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
Jul 18 12:18:11 pengo kernel: usb-storage: 2a 00 00 00 1b e0 00 00 20 00 00 00
Jul 18 12:18:11 pengo kernel: usb-storage: Freecom TRANSPORT STARTED
Jul 18 12:18:11 pengo kernel: usb-storage: 00000000: 2a 00 00 00 1b e0 00 00 - 20 00 00 00             - *....... ...
Jul 18 12:18:11 pengo kernel: usb-storage: foo Status result 0 4
Jul 18 12:18:11 pengo kernel: usb-storage: 00000000: 4a 00 00 f8                                       - J...
Jul 18 12:18:11 pengo kernel: usb-storage: Device indicates that it has 63488 bytes available
Jul 18 12:18:11 pengo kernel: usb-storage: SCSI requested 65536
Jul 18 12:18:11 pengo kernel: usb-storage: Write data Freecom! (c=65536)
Jul 18 12:18:11 pengo kernel: usb-storage: Done issuing write request: 0 64
Jul 18 12:18:11 pengo kernel: usb-storage: Start of write
Jul 18 12:18:11 pengo kernel: usb-storage: transfer_amount: 65536 and total_transferred: 0
Jul 18 12:18:11 pengo kernel: usb-storage: usb_stor_transfer_partial(): xfer 4096 bytes
Jul 18 12:18:11 pengo kernel: usb-storage: usb_stor_bulk_msg() returned 0 xferred 4096/4096
Jul 18 12:18:11 pengo kernel: usb-storage: usb_stor_transfer_partial(): transfer complete
Jul 18 12:18:11 pengo kernel: usb-storage: transfer_amount: 65536 and total_transferred: 4096
... [cut]
Jul 18 12:18:11 pengo kernel: usb-storage: transfer_amount: 65536 and total_transferred: 61440
Jul 18 12:18:11 pengo kernel: usb-storage: usb_stor_transfer_partial(): xfer 4096 bytes
Jul 18 12:18:11 pengo kernel: usb-storage: usb_stor_bulk_msg() returned 0 xferred 4096/4096
Jul 18 12:18:11 pengo kernel: usb-storage: usb_stor_transfer_partial(): transfer complete
Jul 18 12:18:11 pengo kernel: usb-storage: freecom_writedata done!
Jul 18 12:18:11 pengo kernel: usb-storage: FCM: Waiting for status
Jul 18 12:18:11 pengo kernel: usb-storage: operation failed
Jul 18 12:18:11 pengo kernel: usb-storage: -- transport indicates command failure
Jul 18 12:18:11 pengo kernel: usb-storage: Issuing auto-REQUEST_SENSE
Jul 18 12:18:11 pengo kernel: usb-storage: Freecom TRANSPORT STARTED
Jul 18 12:18:11 pengo kernel: usb-storage: 00000000: 03 00 00 00 12 00 00 00 - 20 00 00 00             - ........ ...
Jul 18 12:18:11 pengo kernel: usb-storage: foo Status result 0 4
Jul 18 12:18:11 pengo kernel: usb-storage: 00000000: 52 03 ff ff                                       - R...
Jul 18 12:18:11 pengo kernel: usb-storage: Device indicates that it has 65535 bytes available
Jul 18 12:18:11 pengo kernel: usb-storage: SCSI requested 18
Jul 18 12:18:11 pengo kernel: usb-storage: Truncating request to match buffer length: 18
Jul 18 12:18:11 pengo kernel: usb-storage: SCSI wants data, drive doesn't have any
Jul 18 12:18:11 pengo kernel: usb-storage: -- auto-sense failure
Jul 18 12:18:11 pengo kernel: freecom reset called
Jul 18 12:18:11 pengo kernel: usb-storage: scsi cmd done, result=0x70000
Jul 18 12:18:11 pengo kernel: usb-storage: queuecommand() called
Jul 18 12:18:11 pengo kernel: usb-storage: *** thread sleeping.
Jul 18 12:18:11 pengo kernel: usb-storage: *** thread awakened.
Jul 18 12:18:11 pengo kernel: usb-storage: Command WRITE_10 (10 bytes)
Jul 18 12:18:11 pengo kernel: usb-storage: 2a 00 00 00 1b e0 00 00 20 00 00 00
Jul 18 12:18:11 pengo kernel: usb-storage: Freecom TRANSPORT STARTED
Jul 18 12:18:11 pengo kernel: usb-storage: 00000000: 2a 00 00 00 1b e0 00 00 - 20 00 00 00             - *....... ...
Jul 18 12:18:11 pengo kernel: usb-storage: foo Status result 0 4
Jul 18 12:18:11 pengo kernel: usb-storage: 00000000: 4a 00 00 f8                                       - J...
Jul 18 12:18:11 pengo kernel: usb-storage: Device indicates that it has 63488 bytes available
Jul 18 12:18:11 pengo kernel: usb-storage: SCSI requested 65536
Jul 18 12:18:11 pengo kernel: usb-storage: Write data Freecom! (c=65536)
Jul 18 12:18:11 pengo kernel: usb-storage: Done issuing write request: 0 64
Jul 18 12:18:11 pengo kernel: usb-storage: Start of write
Jul 18 12:18:11 pengo kernel: usb-storage: transfer_amount: 65536 and total_transferred: 0
Jul 18 12:18:11 pengo kernel: usb-storage: usb_stor_transfer_partial(): xfer 4096 bytes
Jul 18 12:18:11 pengo kernel: usb-storage: usb_stor_bulk_msg() returned 0 xferred 4096/4096
Jul 18 12:18:11 pengo kernel: usb-storage: usb_stor_transfer_partial(): transfer complete
Jul 18 12:18:11 pengo kernel: usb-storage: transfer_amount: 65536 and total_transferred: 4096
... [cut]
Jul 18 12:18:11 pengo kernel: usb-storage: transfer_amount: 65536 and total_transferred: 61440
Jul 18 12:18:11 pengo kernel: usb-storage: usb_stor_transfer_partial(): xfer 4096 bytes
Jul 18 12:18:11 pengo kernel: usb-storage: usb_stor_bulk_msg() returned 0 xferred 4096/4096
Jul 18 12:18:11 pengo kernel: usb-storage: usb_stor_transfer_partial(): transfer complete
Jul 18 12:18:11 pengo kernel: usb-storage: freecom_writedata done!
Jul 18 12:18:11 pengo kernel: usb-storage: FCM: Waiting for status
Jul 18 12:18:12 pengo kernel: usb-storage: Transfer happy
Jul 18 12:18:12 pengo kernel: usb-storage: scsi cmd done, result=0x0
Jul 18 12:18:12 pengo kernel: usb-storage: *** thread sleeping.

Signature · 2 lines

Peter Osterlund - [email protected]
http://w1.894.telia.com/~u89404340

Duncan Sands

2002-07-18 06:07 UTC #6 lore raw

In reply to Pierre ROUSSELET

Quoted 3 lines · Pierre ROUSSELET

The driver is made of a kernel module speedtch.o (built outside of the tree) and of userspace modem firmware loader and management daemon speedmgt.

Is your kernel preemptive?

Duncan.

Pierre ROUSSELET

author

2002-07-18 06:35 UTC #7 lore raw

Yes it is.

Quoted 20 lines

Messsage du 18/07/2002 08:10
De : Duncan Sands <[email protected]>
A : Pierre ROUSSELET <[email protected]>, <[email protected]> Copie à : <[email protected]>
Objet : Re: 2.5.25 uhci-hcd very bad
Quoted 3 lines · Pierre ROUSSELET
The driver is made of a kernel module speedtch.o (built outside of the tree) and of userspace modem firmware loader and management daemon speedmgt.
Is your kernel preemptive?
Duncan.
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Duncan Sands

2002-07-18 06:59 UTC #8 lore raw

In answer to the question, "is your kernel preemptive":

Quoted 1 line · Pierre ROUSSELET

Yes it is.

Well, the original module code contains several races. I spent some time cleaning these up (because it would sometimes oops on a preemptive system), until I cracked and went over to the user space driver... But maybe you are not using the original code?

All the best,

Duncan.