2004-11-18 21:05:21

by Fabio Coatti

[permalink] [raw]
Subject: 2.6.10-rc2-mm2 usb storage still oopses

Just a reminder: it's possible to cause a kernel oops simply inserting and
removing a usb storage (flash pen); using ub driver doesn't improve the
situation; noticed in 2.6.9-rc4-mm1 and present in 2.6.10-rc2-mm2.
The same device works just fine with 2.6.8.1 (mdk cooker)
I can provide, as previously done, full log for oopses and other details, just
let me known. (the behaviour is quite the same as already reported, so I
don't want to waste bandwidth)

--
Fabio Coatti http://members.ferrara.linux.it/cova
Ferrara Linux Users Group http://ferrara.linux.it
GnuPG fp:9765 A5B6 6843 17BC A646 BE8C FA56 373A 5374 C703
Old SysOps never die... they simply forget their password.


2004-11-18 21:40:52

by Andrew Morton

[permalink] [raw]
Subject: Re: 2.6.10-rc2-mm2 usb storage still oopses

Fabio Coatti <[email protected]> wrote:
>
> Just a reminder: it's possible to cause a kernel oops simply inserting and
> removing a usb storage (flash pen); using ub driver doesn't improve the
> situation; noticed in 2.6.9-rc4-mm1 and present in 2.6.10-rc2-mm2.
> The same device works just fine with 2.6.8.1 (mdk cooker)

OK, that's something we'd like to get fixed prior to 2.6.10.

> I can provide, as previously done, full log for oopses and other details, just
> let me known. (the behaviour is quite the same as already reported, so I
> don't want to waste bandwidth)

We waste truckloads of bandwidth on far less important things than this ;)

Please resend the report, including the oops trace and be sure to cc both
linux-kernel and linux-usb-devel, thanks.

2004-11-18 22:01:50

by Pete Zaitcev

[permalink] [raw]
Subject: Re: 2.6.10-rc2-mm2 usb storage still oopses

On Thu, 18 Nov 2004 13:35:57 -0800, Andrew Morton <[email protected]> wrote:

> Fabio Coatti <[email protected]> wrote:
> >
> > Just a reminder: it's possible to cause a kernel oops simply inserting and
> > removing a usb storage (flash pen); using ub driver doesn't improve the
> > situation; noticed in 2.6.9-rc4-mm1 and present in 2.6.10-rc2-mm2.
> > The same device works just fine with 2.6.8.1 (mdk cooker)
>
> OK, that's something we'd like to get fixed prior to 2.6.10.

Actually Fabio told me that his oops was fixed by the patch present in
2.6.10-rc2. The problem is that his device needs special handling which
I do not know how to provide, so it does not work in the end. I hope it
will resolve itself eventually, as I get testers.

There was one last oops from Martin Schleminger ("Sahara") which I think
I fixed but I need a confirmation before pushing to Greg. Apparently, it
only happens on kernels with preempt enabled. If anyone knows of any other
problems, I'm all ears.

-- Pete

P.S. Current updates:

--- linux-2.6.10-rc2-usb/drivers/block/ub.c 2004-11-16 17:03:02.000000000 -0800
+++ linux-2.6.10-rc1-ub/drivers/block/ub.c 2004-11-07 19:01:03.000000000 -0800
@@ -36,7 +36,7 @@
#define DRV_NAME "ub"
#define DEVFS_NAME DRV_NAME

-#define UB_MAJOR 125 /* Stolen from Experimental range for a week - XXX */
+#define UB_MAJOR 180

/*
* Definitions which have to be scattered once we understand the layout better.
@@ -1535,8 +1535,11 @@

ub_revalidate(sc);
/* This is pretty much a long term P3 */
- printk(KERN_INFO "%s: device %u capacity nsec %ld bsize %u\n",
- sc->name, sc->dev->devnum, sc->capacity.nsec, sc->capacity.bsize);
+ if (!atomic_read(&sc->poison)) { /* Cover sc->dev */
+ printk(KERN_INFO "%s: device %u capacity nsec %ld bsize %u\n",
+ sc->name, sc->dev->devnum,
+ sc->capacity.nsec, sc->capacity.bsize);
+ }

/* XXX Support sector size switching like in sr.c */
blk_queue_hardsect_size(disk->queue, sc->capacity.bsize);

2004-11-18 23:53:42

by Fabio Coatti

[permalink] [raw]
Subject: Re: 2.6.10-rc2-mm2 usb storage still oopses

Alle 22:58, gioved? 18 novembre 2004, Pete Zaitcev ha scritto:
> On Thu, 18 Nov 2004 13:35:57 -0800, Andrew Morton <[email protected]> wrote:
> > Fabio Coatti <[email protected]> wrote:
> > > Just a reminder: it's possible to cause a kernel oops simply inserting
> > > and removing a usb storage (flash pen); using ub driver doesn't improve
> > > the situation; noticed in 2.6.9-rc4-mm1 and present in 2.6.10-rc2-mm2.
> > > The same device works just fine with 2.6.8.1 (mdk cooker)
> >
> > OK, that's something we'd like to get fixed prior to 2.6.10.
>
> Actually Fabio told me that his oops was fixed by the patch present in
> 2.6.10-rc2. The problem is that his device needs special handling which
> I do not know how to provide, so it does not work in the end. I hope it
> will resolve itself eventually, as I get testers.
>
> There was one last oops from Martin Schleminger ("Sahara") which I think
> I fixed but I need a confirmation before pushing to Greg. Apparently, it
> only happens on kernels with preempt enabled. If anyone knows of any other
> problems, I'm all ears.

Well, that's the whole story: in fact using ub driver with your patch applied
i can avoid oops (as said in this thread:
http://marc.theaimsgroup.com/?l=linux-kernel&m=109943374727804&w=2)

But the behaviour imho is still buggy and not related to ub driver; it sems
that something goes wrong before ub; in fact I get almost the same behaviour
without ub compiled in, scsi fails in the (quite) the same way, it seems that
something is activated twice. Anyway below I've posted the full syslog
cut&paste, with some comments.
in short: inserting and removing the device causes some errors (maybe
timeouts?) for some tries, (first part of logs) then suddenly, after 3/4
tries, the device is identified and then scsi layer gets activated (and
confused). this time, the removal of device causes a kernel oops. After, you
can also find the behavoiur with ub: no oopses, but the operation is not
complete. I've also tried to turn on the box with key inserted, but I'm
unable to report because the keyboard/mouse (ps/2) was dead, so maybe
something has gone wrong...but i can't tell what. Maybe I can try with serial
console to pickup some messages. Anyway, the key is perfectly working on
first try with another HW and with 2.6.8.1. I've also attached config.gz.
I've checked also config but I can't find something wrong or misconfigured.

anyway, if more infos (or test) are needed, just let me know.

Many thanks.


reports:

>No UB module compiled:

Nov 18 20:30:13 kefk kernel: hub 5-0:1.0: state 5 ports 8 chg ff00 evt 0008
Nov 18 20:30:13 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001803 POWER sig=j CSC CONNECT
Nov 18 20:30:13 kefk kernel: hub 5-0:1.0: port 3, status 0501, change 0001,
480 Mb/s
Nov 18 20:30:13 kefk kernel: hub 5-0:1.0: debounce: port 3: total 100ms stable
100ms status 0x501
Nov 18 20:30:13 kefk kernel: ehci_hcd 0000:00:1d.7: port 3 high speed
Nov 18 20:30:13 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001005 POWER sig=se0 PE CONNECT
Nov 18 20:30:13 kefk kernel: usb 5-3: new high speed USB device using ehci_hcd
and address 3
Nov 18 20:30:13 kefk kernel: ehci_hcd 0000:00:1d.7: devpath 3 ep0in 3strikes
Nov 18 20:30:13 kefk kernel: ehci_hcd 0000:00:1d.7: port 3 full speed -->
companion
Nov 18 20:30:13 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
003801 POWER OWNER sig=j CONNECT
Nov 18 20:30:13 kefk kernel: uhci_hcd 0000:00:1d.1: wakeup_hc
Nov 18 20:30:13 kefk kernel: hub 2-0:1.0: state 5 ports 2 chg fffc evt 0002
Nov 18 20:30:13 kefk kernel: uhci_hcd 0000:00:1d.1: port 1 portsc 0093,00
Nov 18 20:30:13 kefk kernel: hub 2-0:1.0: port 1, status 0101, change 0001, 12
Mb/s
Nov 18 20:30:13 kefk kernel: hub 2-0:1.0: debounce: port 1: total 100ms stable
100ms status 0x101
Nov 18 20:30:13 kefk kernel: usb 2-1: new full speed USB device using uhci_hcd
and address 2
Nov 18 20:30:13 kefk kernel: uhci_hcd 0000:00:1d.1: uhci_result_control:
failed with status 440000
Nov 18 20:30:13 kefk kernel: [f7a35240] link (37a351b2) element (37a31040)
Nov 18 20:30:13 kefk kernel: 0: [f7a31040] link (37a31080) e0 Stalled
CRC/Timeo Length=7 MaxLen=7 DT0 EndPt=0 Dev=0, PID=2d(SETUP) (buf=37caa7e0)
Nov 18 20:30:13 kefk kernel: 1: [f7a31080] link (37a310c0) e3 SPD Active
Length=0 MaxLen=3f DT1 EndPt=0 Dev=0, PID=69(IN) (buf=36b89200)
Nov 18 20:30:13 kefk kernel: 2: [f7a310c0] link (00000001) e3 IOC Active
Length=0 MaxLen=7ff DT1 EndPt=0 Dev=0, PID=e1(OUT) (buf=00000000)
Nov 18 20:30:13 kefk kernel:
Nov 18 20:30:13 kefk kernel: usb 2-1: device descriptor read/64, error -71
Nov 18 20:30:13 kefk kernel: uhci_hcd 0000:00:1d.1: uhci_result_control:
failed with status 440000
Nov 18 20:30:13 kefk kernel: [f7a35240] link (37a351b2) element (37a31040)
Nov 18 20:30:13 kefk kernel: 0: [f7a31040] link (37a31080) e0 Stalled
CRC/Timeo Length=7 MaxLen=7 DT0 EndPt=0 Dev=0, PID=2d(SETUP) (buf=368d9320)
Nov 18 20:30:13 kefk kernel: 1: [f7a31080] link (37a310c0) e3 SPD Active
Length=0 MaxLen=3f DT1 EndPt=0 Dev=0, PID=69(IN) (buf=36b89200)
Nov 18 20:30:13 kefk kernel: 2: [f7a310c0] link (00000001) e3 IOC Active
Length=0 MaxLen=7ff DT1 EndPt=0 Dev=0, PID=e1(OUT) (buf=00000000)
Nov 18 20:30:13 kefk kernel:
Nov 18 20:30:14 kefk kernel: usb 2-1: device descriptor read/64, error -71
Nov 18 20:30:14 kefk kernel: usb 2-1: new full speed USB device using uhci_hcd
and address 3
Nov 18 20:30:14 kefk kernel: uhci_hcd 0000:00:1d.1: uhci_result_control:
failed with status 440000
Nov 18 20:30:14 kefk kernel: [f7a35240] link (37a351b2) element (37a31040)
Nov 18 20:30:14 kefk kernel: 0: [f7a31040] link (37a31080) e0 Stalled
CRC/Timeo Length=7 MaxLen=7 DT0 EndPt=0 Dev=0, PID=2d(SETUP) (buf=368d9320)
Nov 18 20:30:14 kefk kernel: 1: [f7a31080] link (37a310c0) e3 SPD Active
Length=0 MaxLen=3f DT1 EndPt=0 Dev=0, PID=69(IN) (buf=36b89200)
Nov 18 20:30:14 kefk kernel: 2: [f7a310c0] link (00000001) e3 IOC Active
Length=0 MaxLen=7ff DT1 EndPt=0 Dev=0, PID=e1(OUT) (buf=00000000)
Nov 18 20:30:14 kefk kernel:
Nov 18 20:30:14 kefk kernel: usb 2-1: device descriptor read/64, error -71
Nov 18 20:30:14 kefk kernel: uhci_hcd 0000:00:1d.1: uhci_result_control:
failed with status 440000
Nov 18 20:30:14 kefk kernel: [f7a35240] link (37a351b2) element (37a31040)
Nov 18 20:30:14 kefk kernel: 0: [f7a31040] link (37a31080) e0 Stalled
CRC/Timeo Length=7 MaxLen=7 DT0 EndPt=0 Dev=0, PID=2d(SETUP) (buf=368d9320)
Nov 18 20:30:14 kefk kernel: 1: [f7a31080] link (37a310c0) e3 SPD Active
Length=0 MaxLen=3f DT1 EndPt=0 Dev=0, PID=69(IN) (buf=36b89200)
Nov 18 20:30:14 kefk kernel: 2: [f7a310c0] link (00000001) e3 IOC Active
Length=0 MaxLen=7ff DT1 EndPt=0 Dev=0, PID=e1(OUT) (buf=00000000)
Nov 18 20:30:14 kefk kernel:
Nov 18 20:30:14 kefk kernel: usb 2-1: device descriptor read/64, error -71
Nov 18 20:30:14 kefk kernel: hub 2-0:1.0: state 5 ports 2 chg fffc evt 0002

> the device is removed:

Nov 18 20:31:54 kefk kernel: hub 5-0:1.0: state 5 ports 8 chg ff00 evt 0008
Nov 18 20:31:54 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001002 POWER sig=se0 CSC
Nov 18 20:31:54 kefk kernel: hub 5-0:1.0: port 3, status 0100, change 0001, 12
Mb/s
Nov 18 20:31:54 kefk kernel: hub 5-0:1.0: debounce: port 3: total 100ms stable
100ms status 0x100
Nov 18 20:31:54 kefk kernel: hub 2-0:1.0: state 5 ports 2 chg fffc evt 0002
Nov 18 20:31:54 kefk kernel: uhci_hcd 0000:00:1d.1: port 1 portsc 0082,00
Nov 18 20:31:54 kefk kernel: hub 2-0:1.0: port 1, status 0100, change 0001, 12
Mb/s
Nov 18 20:31:55 kefk kernel: hub 2-0:1.0: debounce: port 1: total 100ms stable
100ms status 0x100
Nov 18 20:31:55 kefk kernel: uhci_hcd 0000:00:1d.1: suspend_hc

> several, (3/4) tries with the very same result

(...)

> something different this time, with some noise from kernel :)

Nov 18 20:32:59 kefk kernel: hub 5-0:1.0: state 5 ports 8 chg ff00 evt 0008
Nov 18 20:32:59 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001803 POWER sig=j CSC CONNECT
Nov 18 20:32:59 kefk kernel: hub 5-0:1.0: port 3, status 0501, change 0001,
480 Mb/s
Nov 18 20:32:59 kefk kernel: hub 5-0:1.0: debounce: port 3: total 100ms stable
100ms status 0x501
Nov 18 20:32:59 kefk kernel: ehci_hcd 0000:00:1d.7: port 3 high speed
Nov 18 20:32:59 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001005 POWER sig=se0 PE CONNECT
Nov 18 20:32:59 kefk kernel: usb 5-3: new high speed USB device using ehci_hcd
and address 7
Nov 18 20:32:59 kefk kernel: ehci_hcd 0000:00:1d.7: port 3 high speed
Nov 18 20:32:59 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001005 POWER sig=se0 PE CONNECT
Nov 18 20:32:59 kefk kernel: usb 5-3: new device strings: Mfr=1, Product=2,
SerialNumber=3
Nov 18 20:32:59 kefk kernel: usb 5-3: default language 0x0409
Nov 18 20:32:59 kefk kernel: usb 5-3: Product: Mass storage
Nov 18 20:32:59 kefk kernel: usb 5-3: Manufacturer: USB
Nov 18 20:32:59 kefk kernel: usb 5-3: SerialNumber: 142E19413C2FCA34
Nov 18 20:32:59 kefk kernel: usb 5-3: hotplug
Nov 18 20:32:59 kefk kernel: usb 5-3: adding 5-3:1.0 (config #1, interface 0)
Nov 18 20:32:59 kefk kernel: usb 5-3:1.0: hotplug
Nov 18 20:33:00 kefk kernel: Initializing USB Mass Storage driver...
Nov 18 20:33:00 kefk kernel: usb-storage 5-3:1.0: usb_probe_interface
Nov 18 20:33:00 kefk kernel: usb-storage 5-3:1.0: usb_probe_interface - got id
Nov 18 20:33:00 kefk kernel: scsi3 : SCSI emulation for USB Mass Storage
devices
Nov 18 20:33:00 kefk kernel: usbcore: registered new driver usb-storage
Nov 18 20:33:00 kefk kernel: USB Mass Storage support registered.
Nov 18 20:33:00 kefk kernel: usb-storage: device found at 7
Nov 18 20:33:00 kefk kernel: usb-storage: waiting for device to settle before
scanning
Nov 18 20:33:05 kefk kernel: Vendor: 512MB Model: USB2.0FlashDrive Rev:
2.00
Nov 18 20:33:05 kefk kernel: Type: Direct-Access ANSI
SCSI revision: 02
Nov 18 20:33:05 kefk kernel: sdb: Unit Not Ready, sense:
Nov 18 20:33:05 kefk kernel: : Current: sense key=0x6
Nov 18 20:33:05 kefk kernel: ASC=0x28 ASCQ=0x0
Nov 18 20:33:05 kefk kernel: sdb : READ CAPACITY failed.
Nov 18 20:33:05 kefk kernel: sdb : status=1, message=00, host=0, driver=08
Nov 18 20:33:05 kefk kernel: sd: Current: sense key=0x6
Nov 18 20:33:05 kefk kernel: ASC=0x28 ASCQ=0x0
Nov 18 20:33:05 kefk kernel: sdb: test WP failed, assume Write Enabled
Nov 18 20:33:05 kefk kernel: sdb: assuming drive cache: write through
Nov 18 20:33:05 kefk kernel: sdb: Unit Not Ready, sense:
Nov 18 20:33:05 kefk kernel: : Current: sense key=0x6
Nov 18 20:33:05 kefk kernel: ASC=0x28 ASCQ=0x0
Nov 18 20:33:05 kefk kernel: SCSI device sdb: 1024000 512-byte hdwr sectors
(524 MB)
Nov 18 20:33:05 kefk kernel: sdb: Write Protect is off
Nov 18 20:33:05 kefk kernel: sdb: Mode Sense: 03 00 00 00
Nov 18 20:33:05 kefk kernel: sdb: assuming drive cache: write through
Nov 18 20:33:05 kefk kernel: SCSI device sdb: 1024000 512-byte hdwr sectors
(524 MB)
Nov 18 20:33:05 kefk kernel: sdb: Write Protect is off
Nov 18 20:33:05 kefk kernel: sdb: Mode Sense: 03 00 00 00
Nov 18 20:33:05 kefk kernel: sdb: assuming drive cache: write through
Nov 18 20:33:05 kefk kernel: sdb: sdb1
Nov 18 20:33:05 kefk kernel: sdb: sdb1
Nov 18 20:33:05 kefk kernel: kobject_register failed for sdb1 (-17)
Nov 18 20:33:05 kefk kernel: [bitmap_parse+577/590]
kobject_register+0x51/0x5f
Nov 18 20:33:05 kefk kernel: [<c01f281f>] kobject_register+0x51/0x5f
Nov 18 20:33:05 kefk kernel: [show_stat+2489/2532] add_partition+0xbb/0xf0
Nov 18 20:33:05 kefk kernel: [<c01851b0>] add_partition+0xbb/0xf0
Nov 18 20:33:05 kefk kernel: [filesystems_read_proc+5/84]
register_disk+0xee/0x11d
Nov 18 20:33:05 kefk kernel: [<c0185328>] register_disk+0xee/0x11d
Nov 18 20:33:05 kefk kernel: [register_blkdev+278/338] add_disk+0x36/0x41
Nov 18 20:33:05 kefk kernel: [<c025770a>] add_disk+0x36/0x41
Nov 18 20:33:05 kefk kernel: [register_blkdev+204/338] exact_match+0x0/0x7
Nov 18 20:33:05 kefk kernel: [<c02576c0>] exact_match+0x0/0x7
Nov 18 20:33:05 kefk kernel: [register_blkdev+211/338] exact_lock+0x0/0xd
Nov 18 20:33:05 kefk kernel: [<c02576c7>] exact_lock+0x0/0xd
Nov 18 20:33:05 kefk kernel: [sd_probe+664/815] sd_probe+0x224/0x32f
Nov 18 20:33:05 kefk kernel: [<c02981e2>] sd_probe+0x224/0x32f
Nov 18 20:33:05 kefk kernel: [msdos_partition+303/804]
sysfs_make_dirent+0x1c/0x89
Nov 18 20:33:05 kefk kernel: [<c01868cf>] sysfs_make_dirent+0x1c/0x89
Nov 18 20:33:05 kefk kernel: [msdos_partition+303/804]
sysfs_make_dirent+0x1c/0x89
Nov 18 20:33:05 kefk kernel: [<c01868cf>] sysfs_make_dirent+0x1c/0x89
Nov 18 20:33:05 kefk kernel: [bus_remove_file+58/61]
driver_probe_device+0x29/0x6a
Nov 18 20:33:05 kefk kernel: [<c024eed4>] driver_probe_device+0x29/0x6a
Nov 18 20:33:05 kefk kernel: [__bus_for_each_drv+12/114]
device_attach+0x46/0xaa
Nov 18 20:33:05 kefk kernel: [<c024ef5b>] device_attach+0x46/0xaa
Nov 18 20:33:05 kefk kernel: [fcntl_setlk+245/707] dput+0x76/0x209
Nov 18 20:33:05 kefk kernel: [<c0168d8a>] dput+0x76/0x209
Nov 18 20:33:05 kefk kernel: [driver_attach+103/133] bus_add_device+0x55/0x97
Nov 18 20:33:05 kefk kernel: [<c024f222>] bus_add_device+0x55/0x97
Nov 18 20:33:05 kefk kernel: [dev_hotplug_filter+35/43] device_add+0xb9/0x15c
Nov 18 20:33:05 kefk kernel: [<c024e222>] device_add+0xb9/0x15c
Nov 18 20:33:05 kefk kernel: [scsi_sysfs_add_sdev+455/777]
scsi_sysfs_add_sdev+0xa0/0x309
Nov 18 20:33:05 kefk kernel: [<c0276585>] scsi_sysfs_add_sdev+0xa0/0x309
Nov 18 20:33:05 kefk kernel: [scsi_probe_and_add_lun+96/425]
scsi_add_lun+0x2d9/0x32f
Nov 18 20:33:05 kefk kernel: [<c0275138>] scsi_add_lun+0x2d9/0x32f
Nov 18 20:33:05 kefk kernel: [scsi_probe_and_add_lun+371/425]
scsi_probe_and_add_lun+0xbd/0x1c2
Nov 18 20:33:05 kefk kernel: [<c027524b>] scsi_probe_and_add_lun+0xbd/0x1c2
Nov 18 20:33:05 kefk kernel: [scsi_scan_channel+138/154]
scsi_scan_target+0x9a/0x106
Nov 18 20:33:05 kefk kernel: [<c02759c5>] scsi_scan_target+0x9a/0x106
Nov 18 20:33:05 kefk kernel: [scsi_scan_host+17/37]
scsi_scan_channel+0x7c/0x9a
Nov 18 20:33:05 kefk kernel: [<c0275aad>] scsi_scan_channel+0x7c/0x9a
Nov 18 20:33:05 kefk kernel: [scsi_get_host_dev+41/46]
scsi_scan_host_selected+0x6e/0xc7
Nov 18 20:33:05 kefk kernel: [<c0275b39>] scsi_scan_host_selected+0x6e/0xc7
Nov 18 20:33:05 kefk kernel: [.text.lock.scsi_scan+53/54]
scsi_scan_host+0x21/0x25
Nov 18 20:33:05 kefk kernel: [<c0275bb3>] scsi_scan_host+0x21/0x25
Nov 18 20:33:05 kefk kernel: [pg0+946550792/1069159424]
usb_stor_scan_thread+0x134/0x145 [usb_storage]
Nov 18 20:33:05 kefk kernel: [<f8b10808>] usb_stor_scan_thread+0x134/0x145
[usb_storage]
Nov 18 20:33:05 kefk kernel: [do_timer_gettime+100/297]
autoremove_wake_function+0x0/0x43
Nov 18 20:33:05 kefk kernel: [<c012cfad>] autoremove_wake_function+0x0/0x43
Nov 18 20:33:05 kefk kernel: [copy_thread+542/592] ret_from_fork+0x6/0x14
Nov 18 20:33:05 kefk kernel: [<c0102506>] ret_from_fork+0x6/0x14
Nov 18 20:33:05 kefk kernel: [do_timer_gettime+100/297]
autoremove_wake_function+0x0/0x43
Nov 18 20:33:05 kefk kernel: [<c012cfad>] autoremove_wake_function+0x0/0x43
Nov 18 20:33:05 kefk kernel: [pg0+946550484/1069159424]
usb_stor_scan_thread+0x0/0x145 [usb_storage]
Nov 18 20:33:05 kefk kernel: [<f8b106d4>] usb_stor_scan_thread+0x0/0x145
[usb_storage]
Nov 18 20:33:05 kefk kernel: [huft_build+637/1249]
kernel_thread_helper+0x5/0xb
Nov 18 20:33:05 kefk kernel: [<c01008a5>] kernel_thread_helper+0x5/0xb
Nov 18 20:33:05 kefk kernel: Attached scsi removable disk sdb at scsi3,
channel 0, id 0, lun 0
Nov 18 20:33:05 kefk kernel: Attached scsi generic sg4 at scsi3, channel 0, id
0, lun 0, type 0
Nov 18 20:33:05 kefk kernel: usb-storage: device scan complete
Nov 18 20:33:05 kefk scsi.agent[7530]: disk
at /devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/host3/target3:0:0/3:0:0:0

> now, removing the thing, the kernel is not so happy
(maybe to have twice the lines:

================================
Nov 18 20:33:05 kefk kernel: sdb: Write Protect is off
Nov 18 20:33:05 kefk kernel: sdb: Mode Sense: 03 00 00 00
Nov 18 20:33:05 kefk kernel: sdb: assuming drive cache: write through
Nov 18 20:33:05 kefk kernel: SCSI device sdb: 1024000 512-byte hdwr sectors
(524 MB)
Nov 18 20:33:05 kefk kernel: sdb: Write Protect is off
Nov 18 20:33:05 kefk kernel: sdb: Mode Sense: 03 00 00 00
Nov 18 20:33:05 kefk kernel: sdb: assuming drive cache: write through
Nov 18 20:33:05 kefk kernel: sdb: sdb1
Nov 18 20:33:05 kefk kernel: sdb: sdb1
================================
is not a good sign...)


Nov 18 20:35:24 kefk kernel: hub 5-0:1.0: state 5 ports 8 chg ff00 evt 0008
Nov 18 20:35:24 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001002 POWER sig=se0 CSC
Nov 18 20:35:24 kefk kernel: hub 5-0:1.0: port 3, status 0100, change 0001, 12
Mb/s
Nov 18 20:35:24 kefk kernel: usb 5-3: USB disconnect, address 7
Nov 18 20:35:24 kefk kernel: usb 5-3: usb_disable_device nuking all URBs
Nov 18 20:35:24 kefk kernel: usb 5-3: unregistering interface 5-3:1.0
Nov 18 20:35:24 kefk kernel: Unable to handle kernel NULL pointer dereference
at virtual address 00000050
Nov 18 20:35:24 kefk kernel: printing eip:
Nov 18 20:35:24 kefk kernel: c0186e32
Nov 18 20:35:24 kefk kernel: *pde = 00000000
Nov 18 20:35:24 kefk kernel: Oops: 0000 [#1]
Nov 18 20:35:24 kefk kernel: PREEMPT SMP
Nov 18 20:35:24 kefk kernel: Modules linked in: nls_cp850 usb_storage md5 ipv6
rfcomm l2cap bluetooth snd_emu10k1 snd_rawmidi snd_seq_device snd_ac97_codec
snd_pcm snd_timer snd_page_alloc snd_util_mem snd_hwdep snd soundcore
ipt_REJECT iptable_filter ip_tables loop nls_utf8 ide_cd i2c_dev w83781d
i2c_sensor i2c_isa i2c_i801 isofs zlib_inflate e1000 parport_pc ppa parport
ehci_hcd usblp uhci_hcd genrtc
Nov 18 20:35:24 kefk kernel: CPU: 0
Nov 18 20:35:24 kefk kernel: EIP: 0060:[sysfs_hash_and_remove+174/241]
Not tainted VLI
Nov 18 20:35:24 kefk kernel: EIP: 0060:[<c0186e32>] Not tainted VLI
Nov 18 20:35:24 kefk kernel: EFLAGS: 00010246 (2.6.10-rc2-mm2)
Nov 18 20:35:24 kefk kernel: EIP is at sysfs_remove_dir+0x1d/0x10b
Nov 18 20:35:24 kefk kernel: eax: f6e79988 ebx: f6e79988 ecx: c18ff480
edx: c1000000
Nov 18 20:35:24 kefk kernel: esi: f78b8b00 edi: 00000000 ebp: f7bd5d24
esp: c1b7ddd8
Nov 18 20:35:24 kefk kernel: ds: 007b es: 007b ss: 0068
Nov 18 20:35:24 kefk kernel: Process khubd (pid: 139, threadinfo=c1b7d000
task=c199c020)
Nov 18 20:35:24 kefk kernel: Stack: 00000000 00000001 f6e79988 f78b8b00
00000001 f7bd5d24 c01f292f f6e79988
Nov 18 20:35:24 kefk kernel: c01f293f f246ae80 c0185530 f7948994
f78b8b00 c03bf4e4 f7bd5d24 c0298304
Nov 18 20:35:24 kefk kernel: f79489b8 f7948994 c024f0b1 f7948994
f7b7fc04 f7948994 c024f2b7 f7948994
Nov 18 20:35:24 kefk kernel: Call Trace:
Nov 18 20:35:24 kefk kernel: [bitmap_scnlistprintf+259/292]
kobject_del+0x14/0x1c
Nov 18 20:35:24 kefk kernel: [<c01f292f>] kobject_del+0x14/0x1c
Nov 18 20:35:24 kefk kernel: [bitmap_scnlistprintf+275/292]
kobject_unregister+0x8/0x10
Nov 18 20:35:24 kefk kernel: [<c01f293f>] kobject_unregister+0x8/0x10
Nov 18 20:35:24 kefk kernel: [get_kcore_size+54/69] del_gendisk+0x1d/0xd5
Nov 18 20:35:24 kefk kernel: [<c0185530>] del_gendisk+0x1d/0xd5
Nov 18 20:35:24 kefk kernel: [scsi_disk_release+57/82] sd_remove+0x17/0x52
Nov 18 20:35:24 kefk kernel: [<c0298304>] sd_remove+0x17/0x52
Nov 18 20:35:24 kefk kernel: [driver_probe_device+10/106]
device_release_driver+0x6d/0x6f
Nov 18 20:35:24 kefk kernel: [<c024f0b1>] device_release_driver+0x6d/0x6f
Nov 18 20:35:24 kefk kernel: [driver_detach+8/31] bus_remove_device+0x53/0x90
Nov 18 20:35:24 kefk kernel: [<c024f2b7>] bus_remove_device+0x53/0x90
Nov 18 20:35:24 kefk kernel: [device_initialize+43/70] device_del+0x54/0x91
Nov 18 20:35:24 kefk kernel: [<c024e34a>] device_del+0x54/0x91
Nov 18 20:35:24 kefk kernel: [scsi_sysfs_add_host+37/303]
scsi_remove_device+0x4e/0xab
Nov 18 20:35:24 kefk kernel: [<c027683c>] scsi_remove_device+0x4e/0xab
Nov 18 20:35:24 kefk kernel: [check_set+14/139] scsi_forget_host+0x2d/0x4f
Nov 18 20:35:24 kefk kernel: [<c0275be4>] scsi_forget_host+0x2d/0x4f
Nov 18 20:35:24 kefk kernel: [__scsi_iterate_devices+26/90]
scsi_remove_host+0x8/0x7c
Nov 18 20:35:24 kefk kernel: [<c026faf7>] scsi_remove_host+0x8/0x7c
Nov 18 20:35:24 kefk kernel: [pg0+946551473/1069159424]
storage_disconnect+0x7b/0x8d [usb_storage]
Nov 18 20:35:24 kefk kernel: [<f8b10ab1>] storage_disconnect+0x7b/0x8d
[usb_storage]
Nov 18 20:35:24 kefk kernel: [usb_register+114/159]
usb_unbind_interface+0x5e/0x60
Nov 18 20:35:24 kefk kernel: [<c02a4005>] usb_unbind_interface+0x5e/0x60
Nov 18 20:35:24 kefk kernel: [driver_probe_device+10/106]
device_release_driver+0x6d/0x6f
Nov 18 20:35:24 kefk kernel: [<c024f0b1>] device_release_driver+0x6d/0x6f
Nov 18 20:35:24 kefk kernel: [driver_detach+8/31] bus_remove_device+0x53/0x90
Nov 18 20:35:24 kefk kernel: [<c024f2b7>] bus_remove_device+0x53/0x90
Nov 18 20:35:24 kefk kernel: [device_initialize+43/70] device_del+0x54/0x91
Nov 18 20:35:24 kefk kernel: [<c024e34a>] device_del+0x54/0x91
Nov 18 20:35:24 kefk kernel: [usb_disable_device+190/327]
usb_disable_device+0xda/0x147
Nov 18 20:35:24 kefk kernel: [<c02abdcf>] usb_disable_device+0xda/0x147
Nov 18 20:35:24 kefk kernel: [usb_disconnect+288/392]
usb_disconnect+0xa8/0x188
Nov 18 20:35:24 kefk kernel: [<c02a6811>] usb_disconnect+0xa8/0x188
Nov 18 20:35:24 kefk kernel: [hub_port_connect_change+851/1143]
hub_port_connect_change+0x344/0x477
Nov 18 20:35:24 kefk kernel: [<c02a7cc6>] hub_port_connect_change+0x344/0x477
Nov 18 20:35:24 kefk kernel: [set_port_led+38/195]
clear_port_feature+0x48/0x4d
Nov 18 20:35:24 kefk kernel: [<c02a4fa8>] clear_port_feature+0x48/0x4d
Nov 18 20:35:24 kefk kernel: [hub_events+825/1270] hub_events+0x32a/0x4f6
Nov 18 20:35:24 kefk kernel: [<c02a8123>] hub_events+0x32a/0x4f6
Nov 18 20:35:24 kefk kernel: [hub_thread+68/270] hub_thread+0x35/0x10e
Nov 18 20:35:24 kefk kernel: [<c02a8324>] hub_thread+0x35/0x10e
Nov 18 20:35:24 kefk kernel: [do_timer_gettime+100/297]
autoremove_wake_function+0x0/0x43
Nov 18 20:35:24 kefk kernel: [<c012cfad>] autoremove_wake_function+0x0/0x43
Nov 18 20:35:24 kefk kernel: [copy_thread+542/592] ret_from_fork+0x6/0x14
Nov 18 20:35:24 kefk kernel: [<c0102506>] ret_from_fork+0x6/0x14
Nov 18 20:35:24 kefk kernel: [do_timer_gettime+100/297]
autoremove_wake_function+0x0/0x43
Nov 18 20:35:24 kefk kernel: [<c012cfad>] autoremove_wake_function+0x0/0x43
Nov 18 20:35:24 kefk kernel: [hub_thread+15/270] hub_thread+0x0/0x10e
Nov 18 20:35:24 kefk kernel: [<c02a82ef>] hub_thread+0x0/0x10e
Nov 18 20:35:24 kefk kernel: [huft_build+637/1249]
kernel_thread_helper+0x5/0xb
Nov 18 20:35:24 kefk kernel: [<c01008a5>] kernel_thread_helper+0x5/0xb
Nov 18 20:35:24 kefk kernel: Code: 5a 15 33 c0 e9 39 ff ff ff e9 0e ff ff ff
55 57 56 53 83 ec 08 8b 78 30 85 ff 74 0d 8b 07 85 c0 0f 84 e6 00 00 00 f0 ff
07 85 ff <8b> 4f 50 0f 84 ab 00 00 00 8b 57 10 f0 ff 4a 78 0f 88 03 07 00

> and now with UB

(I've removed first tries, that has gone exactly as did before, with some
errors and nothing more)

Nov 18 20:49:02 kefk kernel: hub 5-0:1.0: state 5 ports 8 chg ff00 evt 0008
Nov 18 20:49:02 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001803 POWER sig=j CSC CONNECT
Nov 18 20:49:02 kefk kernel: hub 5-0:1.0: port 3, status 0501, change 0001,
480 Mb/s
Nov 18 20:49:03 kefk kernel: hub 5-0:1.0: debounce: port 3: total 100ms stable
100ms status 0x501
Nov 18 20:49:03 kefk kernel: ehci_hcd 0000:00:1d.7: port 3 high speed
Nov 18 20:49:03 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001005 POWER sig=se0 PE CONNECT
Nov 18 20:49:03 kefk kernel: usb 5-3: new high speed USB device using ehci_hcd
and address 8
Nov 18 20:49:03 kefk kernel: ehci_hcd 0000:00:1d.7: port 3 high speed
Nov 18 20:49:03 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001005 POWER sig=se0 PE CONNECT
Nov 18 20:49:03 kefk kernel: usb 5-3: new device strings: Mfr=1, Product=2,
SerialNumber=3
Nov 18 20:49:03 kefk kernel: usb 5-3: default language 0x0409
Nov 18 20:49:03 kefk kernel: usb 5-3: Product: Mass storage
Nov 18 20:49:03 kefk kernel: usb 5-3: Manufacturer: USB
Nov 18 20:49:03 kefk kernel: usb 5-3: SerialNumber: 142E19413C2FCA34
Nov 18 20:49:03 kefk kernel: usb 5-3: hotplug
Nov 18 20:49:03 kefk kernel: usb 5-3: adding 5-3:1.0 (config #1, interface 0)
Nov 18 20:49:03 kefk kernel: usb 5-3:1.0: hotplug
Nov 18 20:49:03 kefk kernel: ub 5-3:1.0: usb_probe_interface
Nov 18 20:49:03 kefk kernel: ub 5-3:1.0: usb_probe_interface - got id
Nov 18 20:49:03 kefk kernel: uba: device 8 capacity nsec 0 bsize 512

> it should appear "uba1", not only "uba", or am I wrong?

(but this time I got no oopses)

[root@kefk root]# lspci -v
00:00.0 Host bridge: Intel Corp. 82875P Memory Controller Hub (rev 02)
Subsystem: ABIT Computer Corp.: Unknown device 1014
Flags: bus master, fast devsel, latency 0
Memory at e8000000 (32-bit, prefetchable) [size=128M]
Capabilities: [e4] #09 [2106]
Capabilities: [a0] AGP version 3.0

00:01.0 PCI bridge: Intel Corp. 82875P Processor to AGP Controller (rev 02)
(prog-if 00 [Normal decode])
Flags: bus master, 66Mhz, fast devsel, latency 64
Bus: primary=00, secondary=01, subordinate=01, sec-latency=32
Memory behind bridge: f8000000-f9ffffff
Prefetchable memory behind bridge: f0000000-f7ffffff

00:03.0 PCI bridge: Intel Corp. 82875P Processor to PCI to CSA Bridge (rev 02)
(prog-if 00 [Normal decode])
Flags: bus master, 66Mhz, fast devsel, latency 32
Bus: primary=00, secondary=02, subordinate=02, sec-latency=0
I/O behind bridge: 00009000-00009fff
Memory behind bridge: fa000000-fa0fffff

00:1d.0 USB Controller: Intel Corp. 82801EB/ER (ICH5/ICH5R) USB UHCI #1 (rev
02) (prog-if 00 [UHCI])
Subsystem: ABIT Computer Corp.: Unknown device 1014
Flags: bus master, medium devsel, latency 0, IRQ 185
I/O ports at bc00 [size=32]

00:1d.1 USB Controller: Intel Corp. 82801EB/ER (ICH5/ICH5R) USB UHCI #2 (rev
02) (prog-if 00 [UHCI])
Subsystem: ABIT Computer Corp.: Unknown device 1014
Flags: bus master, medium devsel, latency 0, IRQ 193
I/O ports at b000 [size=32]

00:1d.2 USB Controller: Intel Corp. 82801EB/ER (ICH5/ICH5R) USB UHCI #3 (rev
02) (prog-if 00 [UHCI])
Subsystem: ABIT Computer Corp.: Unknown device 1014
Flags: bus master, medium devsel, latency 0, IRQ 169
I/O ports at b400 [size=32]

00:1d.3 USB Controller: Intel Corp. 82801EB/ER (ICH5/ICH5R) USB UHCI #4 (rev
02) (prog-if 00 [UHCI])
Subsystem: ABIT Computer Corp.: Unknown device 1014
Flags: bus master, medium devsel, latency 0, IRQ 185
I/O ports at b800 [size=32]

00:1d.7 USB Controller: Intel Corp. 82801EB/ER (ICH5/ICH5R) USB2 EHCI
Controller (rev 02) (prog-if 20 [EHCI])
Subsystem: ABIT Computer Corp.: Unknown device 1014
Flags: bus master, medium devsel, latency 0, IRQ 201
Memory at fa200000 (32-bit, non-prefetchable) [size=1K]
Capabilities: [50] Power Management version 2
Capabilities: [58] #0a [20a0]

00:1e.0 PCI bridge: Intel Corp. 82801 PCI Bridge (rev c2) (prog-if 00 [Normal
decode])
Flags: bus master, fast devsel, latency 0
Bus: primary=00, secondary=03, subordinate=03, sec-latency=32
I/O behind bridge: 0000a000-0000afff
Memory behind bridge: fa100000-fa1fffff

00:1f.0 ISA bridge: Intel Corp. 82801EB/ER (ICH5/ICH5R) LPC Bridge (rev 02)
Flags: bus master, medium devsel, latency 0

00:1f.1 IDE interface: Intel Corp. 82801EB/ER (ICH5/ICH5R) Ultra ATA 100
Storage Controller (rev 02) (prog-if 8a [Master SecP PriP])
Subsystem: ABIT Computer Corp.: Unknown device 1014
Flags: bus master, medium devsel, latency 0, IRQ 169
I/O ports at <unassigned>
I/O ports at <unassigned>
I/O ports at <unassigned>
I/O ports at <unassigned>
I/O ports at f000 [size=16]
Memory at 40000000 (32-bit, non-prefetchable) [size=1K]

00:1f.2 IDE interface: Intel Corp. 82801EB (ICH5) Serial ATA 150 Storage
Controller (rev 02) (prog-if 8f [Master SecP SecO PriP PriO])
Subsystem: ABIT Computer Corp.: Unknown device 1014
Flags: bus master, 66Mhz, medium devsel, latency 0, IRQ 169
I/O ports at c000 [size=8]
I/O ports at c400 [size=4]
I/O ports at c800 [size=8]
I/O ports at cc00 [size=4]
I/O ports at d000 [size=16]

00:1f.3 SMBus: Intel Corp. 82801EB/ER (ICH5/ICH5R) SMBus Controller (rev 02)
Subsystem: ABIT Computer Corp.: Unknown device 1014
Flags: medium devsel, IRQ 9
I/O ports at 0500 [size=32]

01:00.0 VGA compatible controller: nVidia Corporation NV34 [GeForce FX 5200]
(rev a1) (prog-if 00 [VGA])
Subsystem: Unknown device 1682:1280
Flags: bus master, 66Mhz, medium devsel, latency 32, IRQ 10
Memory at f8000000 (32-bit, non-prefetchable) [size=16M]
Memory at f0000000 (32-bit, prefetchable) [size=128M]
Expansion ROM at <unassigned> [disabled] [size=128K]
Capabilities: [60] Power Management version 2
Capabilities: [44] AGP version 3.0

02:01.0 Ethernet controller: Intel Corp. 82547EI Gigabit Ethernet Controller
(LOM)
Subsystem: ABIT Computer Corp.: Unknown device 1014
Flags: bus master, 66Mhz, medium devsel, latency 0, IRQ 169
Memory at fa000000 (32-bit, non-prefetchable) [size=128K]
I/O ports at 9000 [size=32]
Capabilities: [dc] Power Management version 2

03:04.0 Multimedia audio controller: Creative Labs SB Audigy (rev 04)
Subsystem: Creative Labs SB Audigy 2 ZS (SB0350)
Flags: bus master, medium devsel, latency 32, IRQ 209
I/O ports at a000 [size=64]
Capabilities: [dc] Power Management version 2

03:04.1 Input device controller: Creative Labs SB Audigy MIDI/Game port (rev
04)
Subsystem: Creative Labs SB Audigy MIDI/Game Port
Flags: bus master, medium devsel, latency 32
I/O ports at a400 [size=8]
Capabilities: [dc] Power Management version 2

03:04.2 FireWire (IEEE 1394): Creative Labs SB Audigy FireWire Port (rev 04)
(prog-if 10 [OHCI])
Subsystem: Creative Labs SB Audigy FireWire Port
Flags: bus master, medium devsel, latency 32, IRQ 5
Memory at fa104000 (32-bit, non-prefetchable) [size=2K]
Memory at fa100000 (32-bit, non-prefetchable) [size=16K]
Capabilities: [44] Power Management version 2

03:06.0 SCSI storage controller: Adaptec AHA-7850 (rev 03)
Subsystem: Adaptec AHA-2904/Integrated AIC-7850
Flags: bus master, medium devsel, latency 32, IRQ 177
I/O ports at a800 [disabled] [size=256]
Memory at fa105000 (32-bit, non-prefetchable) [size=4K]
Capabilities: [dc] Power Management version 1


--
Fabio Coatti http://members.ferrara.linux.it/cova
Ferrara Linux Users Group http://ferrara.linux.it
GnuPG fp:9765 A5B6 6843 17BC A646 BE8C FA56 373A 5374 C703
Old SysOps never die... they simply forget their password.

Attachments:
(No filename) (30.59 kB)
 config.gz (8.18 kB)
 Download all attachments

2004-11-19 00:00:59

by Pete Zaitcev

[permalink] [raw]
Subject: Re: 2.6.10-rc2-mm2 usb storage still oopses

On Fri, 19 Nov 2004 00:42:40 +0100, Fabio Coatti <[email protected]> wrote:

> Nov 18 20:33:05 kefk kernel: sdb: assuming drive cache: write through
> Nov 18 20:33:05 kefk kernel: sdb: sdb1
> Nov 18 20:33:05 kefk kernel: sdb: sdb1
> Nov 18 20:33:05 kefk kernel: kobject_register failed for sdb1 (-17)

This looks as if SCSI falls victim of the general problem which ub addresses
with the following fragment:

--- linux-2.6.10-rc1/drivers/block/ub.c 2004-10-28 09:46:38.000000000 -0700
+++ linux-2.6.10-rc1-ub/drivers/block/ub.c 2004-11-06 23:59:20.000000000 -0800
@@ -267,6 +263,7 @@ struct ub_dev {
int changed; /* Media was changed */
int removable;
int readonly;
+ int first_open; /* Kludge. See ub_bd_open. */
char name[8];
struct usb_device *dev;
struct usb_interface *intf;
@@ -1428,6 +1420,26 @@ static int ub_bd_open(struct inode *inod
sc->openc++;
spin_unlock_irqrestore(&ub_lock, flags);

+ /*
+ * This is a workaround for a specific problem in our block layer.
+ * In 2.6.9, register_disk duplicates the code from rescan_partitions.
+ * However, if we do add_disk with a device which persistently reports
+ * a changed media, add_disk calls register_disk, which does do_open,
+ * which will call rescan_paritions for changed media. After that,
+ * register_disk attempts to do it all again and causes double kobject
+ * registration and a eventually an oops on module removal.
+ *
+ * The bottom line is, Al Viro says that we should not allow
+ * bdev->bd_invalidated to be set when doing add_disk no matter what.
+ */
+ if (sc->first_open) {
+ if (sc->changed) {
+ sc->first_open = 0;
+ rc = -ENOMEDIUM;
+ goto err_open;
+ }
+ }
+
if (sc->removable || sc->readonly)
check_disk_change(inode->i_bdev);

@@ -1467,6 +1479,8 @@ static int ub_bd_release(struct inode *i

spin_lock_irqsave(&ub_lock, flags);
--sc->openc;
+ if (sc->openc == 0)
+ sc->first_open = 0;
if (sc->openc == 0 && atomic_read(&sc->poison))
ub_cleanup(sc);
spin_unlock_irqrestore(&ub_lock, flags);
@@ -1919,6 +1932,8 @@ static int ub_probe(struct usb_interface
}

sc->removable = 1; /* XXX Query this from the device */
+ sc->changed = 1; /* ub_revalidate clears only */
+ sc->first_open = 1;

ub_revalidate(sc);
/* This is pretty much a long term P3 */

This feels kludgy, but my excuse is "James and Viro made me do it".
I have an IRC log to prove it laying somewhere...

I'm adding the linux-scsi to cc: in case any comments are forthcoming.

-- Pete

2004-11-19 02:48:47

by Maneesh Soni

[permalink] [raw]
Subject: Re: 2.6.10-rc2-mm2 usb storage still oopses

> Nov 18 20:35:24 kefk kernel: Unable to handle kernel NULL pointer dereference
> at virtual address 00000050
> Nov 18 20:35:24 kefk kernel: printing eip:
> Nov 18 20:35:24 kefk kernel: c0186e32
> Nov 18 20:35:24 kefk kernel: *pde = 00000000
> Nov 18 20:35:24 kefk kernel: Oops: 0000 [#1]
> Nov 18 20:35:24 kefk kernel: PREEMPT SMP
> Nov 18 20:35:24 kefk kernel: Modules linked in: nls_cp850 usb_storage md5 ipv6
> rfcomm l2cap bluetooth snd_emu10k1 snd_rawmidi snd_seq_device snd_ac97_codec
> snd_pcm snd_timer snd_page_alloc snd_util_mem snd_hwdep snd soundcore
> ipt_REJECT iptable_filter ip_tables loop nls_utf8 ide_cd i2c_dev w83781d
> i2c_sensor i2c_isa i2c_i801 isofs zlib_inflate e1000 parport_pc ppa parport
> ehci_hcd usblp uhci_hcd genrtc
> Nov 18 20:35:24 kefk kernel: CPU: 0
> Nov 18 20:35:24 kefk kernel: EIP: 0060:[sysfs_hash_and_remove+174/241]
> Not tainted VLI
> Nov 18 20:35:24 kefk kernel: EIP: 0060:[<c0186e32>] Not tainted VLI
> Nov 18 20:35:24 kefk kernel: EFLAGS: 00010246 (2.6.10-rc2-mm2)
> Nov 18 20:35:24 kefk kernel: EIP is at sysfs_remove_dir+0x1d/0x10b
> Nov 18 20:35:24 kefk kernel: eax: f6e79988 ebx: f6e79988 ecx: c18ff480
> edx: c1000000
> Nov 18 20:35:24 kefk kernel: esi: f78b8b00 edi: 00000000 ebp: f7bd5d24
> esp: c1b7ddd8
> Nov 18 20:35:24 kefk kernel: ds: 007b es: 007b ss: 0068

The following patch should avoid the sysfs_remove_dir() oops you are
seeing while device removal. It anyway fixes the obvious error and is
needed. But it will not make any change to the first error you are
seeing while connecting the device.

Andrew, Greg, please include this.

Thanks
Maneesh


o Following patch avoids the sysfs_remove_dir() oops when it is passed
a kobject with NULL dentry.

Signed-off-by: Maneesh Soni <[email protected]>
---

linux-2.6.10-rc2-bk3-maneesh/fs/sysfs/dir.c | 3 ++-
1 files changed, 2 insertions(+), 1 deletion(-)

diff -puN fs/sysfs/dir.c~fix-sysfs_remove_dir-oops fs/sysfs/dir.c
--- linux-2.6.10-rc2-bk3/fs/sysfs/dir.c~fix-sysfs_remove_dir-oops
2004-11-18 19:59:51.000000000 -0600
+++ linux-2.6.10-rc2-bk3-maneesh/fs/sysfs/dir.c 2004-11-18
20:01:11.000000000 -0600
@@ -268,7 +268,7 @@ void sysfs_remove_subdir(struct dentry *
void sysfs_remove_dir(struct kobject * kobj)
{
struct dentry * dentry = dget(kobj->dentry);
- struct sysfs_dirent * parent_sd = dentry->d_fsdata;
+ struct sysfs_dirent * parent_sd;
struct sysfs_dirent * sd, * tmp;

if (!dentry)
@@ -276,6 +276,7 @@ void sysfs_remove_dir(struct kobject * k

pr_debug("sysfs %s: removing dir\n",dentry->d_name.name);
down(&dentry->d_inode->i_sem);
+ parent_sd = dentry->d_fsdata;
list_for_each_entry_safe(sd, tmp, &parent_sd->s_children, s_sibling) {
if (!sd->s_element || !(sd->s_type & SYSFS_NOT_PINNED))
continue;
_



2004-11-19 16:50:39

by Greg KH

[permalink] [raw]
Subject: Re: 2.6.10-rc2-mm2 usb storage still oopses

On Thu, Nov 18, 2004 at 08:41:10PM -0600, Maneesh Soni wrote:
> > Nov 18 20:35:24 kefk kernel: Unable to handle kernel NULL pointer dereference
> > at virtual address 00000050
> > Nov 18 20:35:24 kefk kernel: printing eip:
> > Nov 18 20:35:24 kefk kernel: c0186e32
> > Nov 18 20:35:24 kefk kernel: *pde = 00000000
> > Nov 18 20:35:24 kefk kernel: Oops: 0000 [#1]
> > Nov 18 20:35:24 kefk kernel: PREEMPT SMP
> > Nov 18 20:35:24 kefk kernel: Modules linked in: nls_cp850 usb_storage md5 ipv6
> > rfcomm l2cap bluetooth snd_emu10k1 snd_rawmidi snd_seq_device snd_ac97_codec
> > snd_pcm snd_timer snd_page_alloc snd_util_mem snd_hwdep snd soundcore
> > ipt_REJECT iptable_filter ip_tables loop nls_utf8 ide_cd i2c_dev w83781d
> > i2c_sensor i2c_isa i2c_i801 isofs zlib_inflate e1000 parport_pc ppa parport
> > ehci_hcd usblp uhci_hcd genrtc
> > Nov 18 20:35:24 kefk kernel: CPU: 0
> > Nov 18 20:35:24 kefk kernel: EIP: 0060:[sysfs_hash_and_remove+174/241]
> > Not tainted VLI
> > Nov 18 20:35:24 kefk kernel: EIP: 0060:[<c0186e32>] Not tainted VLI
> > Nov 18 20:35:24 kefk kernel: EFLAGS: 00010246 (2.6.10-rc2-mm2)
> > Nov 18 20:35:24 kefk kernel: EIP is at sysfs_remove_dir+0x1d/0x10b
> > Nov 18 20:35:24 kefk kernel: eax: f6e79988 ebx: f6e79988 ecx: c18ff480
> > edx: c1000000
> > Nov 18 20:35:24 kefk kernel: esi: f78b8b00 edi: 00000000 ebp: f7bd5d24
> > esp: c1b7ddd8
> > Nov 18 20:35:24 kefk kernel: ds: 007b es: 007b ss: 0068
>
> The following patch should avoid the sysfs_remove_dir() oops you are
> seeing while device removal. It anyway fixes the obvious error and is
> needed. But it will not make any change to the first error you are
> seeing while connecting the device.
>
> Andrew, Greg, please include this.
>
> Thanks
> Maneesh
>
>
> o Following patch avoids the sysfs_remove_dir() oops when it is passed
> a kobject with NULL dentry.

Applied, thanks,

greg k-h

2004-11-30 00:35:16

by Andrew Morton

[permalink] [raw]
Subject: Re: 2.6.10-rc2-mm2 usb storage still oopses

Pete Zaitcev <[email protected]> wrote:
>
> On Fri, 19 Nov 2004 00:42:40 +0100, Fabio Coatti <[email protected]> wrote:
>
> > Nov 18 20:33:05 kefk kernel: sdb: assuming drive cache: write through
> > Nov 18 20:33:05 kefk kernel: sdb: sdb1
> > Nov 18 20:33:05 kefk kernel: sdb: sdb1
> > Nov 18 20:33:05 kefk kernel: kobject_register failed for sdb1 (-17)
>
> This looks as if SCSI falls victim of the general problem which ub addresses
> with the following fragment:

Guys, is this problem still present in Linus's tree? If so, is a fix for
2.6.10 looking feasible?

Thanks.

> --- linux-2.6.10-rc1/drivers/block/ub.c 2004-10-28 09:46:38.000000000 -0700
> +++ linux-2.6.10-rc1-ub/drivers/block/ub.c 2004-11-06 23:59:20.000000000 -0800
> @@ -267,6 +263,7 @@ struct ub_dev {
> int changed; /* Media was changed */
> int removable;
> int readonly;
> + int first_open; /* Kludge. See ub_bd_open. */
> char name[8];
> struct usb_device *dev;
> struct usb_interface *intf;
> @@ -1428,6 +1420,26 @@ static int ub_bd_open(struct inode *inod
> sc->openc++;
> spin_unlock_irqrestore(&ub_lock, flags);
>
> + /*
> + * This is a workaround for a specific problem in our block layer.
> + * In 2.6.9, register_disk duplicates the code from rescan_partitions.
> + * However, if we do add_disk with a device which persistently reports
> + * a changed media, add_disk calls register_disk, which does do_open,
> + * which will call rescan_paritions for changed media. After that,
> + * register_disk attempts to do it all again and causes double kobject
> + * registration and a eventually an oops on module removal.
> + *
> + * The bottom line is, Al Viro says that we should not allow
> + * bdev->bd_invalidated to be set when doing add_disk no matter what.
> + */
> + if (sc->first_open) {
> + if (sc->changed) {
> + sc->first_open = 0;
> + rc = -ENOMEDIUM;
> + goto err_open;
> + }
> + }
> +
> if (sc->removable || sc->readonly)
> check_disk_change(inode->i_bdev);
>
> @@ -1467,6 +1479,8 @@ static int ub_bd_release(struct inode *i
>
> spin_lock_irqsave(&ub_lock, flags);
> --sc->openc;
> + if (sc->openc == 0)
> + sc->first_open = 0;
> if (sc->openc == 0 && atomic_read(&sc->poison))
> ub_cleanup(sc);
> spin_unlock_irqrestore(&ub_lock, flags);
> @@ -1919,6 +1932,8 @@ static int ub_probe(struct usb_interface
> }
>
> sc->removable = 1; /* XXX Query this from the device */
> + sc->changed = 1; /* ub_revalidate clears only */
> + sc->first_open = 1;
>
> ub_revalidate(sc);
> /* This is pretty much a long term P3 */
>
> This feels kludgy, but my excuse is "James and Viro made me do it".
> I have an IRC log to prove it laying somewhere...
>
> I'm adding the linux-scsi to cc: in case any comments are forthcoming.
>
> -- Pete

2004-11-30 03:22:37

by James Bottomley

[permalink] [raw]
Subject: Re: 2.6.10-rc2-mm2 usb storage still oopses

On Mon, 2004-11-29 at 18:32, Andrew Morton wrote:
> Pete Zaitcev <[email protected]> wrote:
> >
> > On Fri, 19 Nov 2004 00:42:40 +0100, Fabio Coatti <[email protected]> wrote:
> >
> > > Nov 18 20:33:05 kefk kernel: sdb: assuming drive cache: write through
> > > Nov 18 20:33:05 kefk kernel: sdb: sdb1
> > > Nov 18 20:33:05 kefk kernel: sdb: sdb1
> > > Nov 18 20:33:05 kefk kernel: kobject_register failed for sdb1 (-17)
> >
> > This looks as if SCSI falls victim of the general problem which ub addresses
> > with the following fragment:
>
> Guys, is this problem still present in Linus's tree? If so, is a fix for
> 2.6.10 looking feasible?

Al Viro has a tentative one at

http://ftp.linux.org.uk/pub/people/viro/register_disk-hack

If someone could try it out and verify that it fixes the problem, we
could put it in.

James


2004-11-30 09:13:57

by Fabio Coatti

[permalink] [raw]
Subject: Re: 2.6.10-rc2-mm2 usb storage still oopses

Alle 04:22, marted? 30 novembre 2004, James Bottomley ha scritto:


> > >
> > > This looks as if SCSI falls victim of the general problem which ub
> > > addresses with the following fragment:
> >
> > Guys, is this problem still present in Linus's tree? If so, is a fix for
> > 2.6.10 looking feasible?
>
> Al Viro has a tentative one at
>
> http://ftp.linux.org.uk/pub/people/viro/register_disk-hack
>
> If someone could try it out and verify that it fixes the problem, we
> could put it in.


Now I'm at work; this evening I'll try and I'll report asap the results. on
wich kernel does it apply? last kernels that I've tried are 2.6.10-rcX-mmY
series, but I can try the most suitable version for debugging, just let me
know.



--
Fabio "Cova" Coatti http://members.ferrara.linux.it/cova
Ferrara Linux Users Group http://ferrara.linux.it
GnuPG fp:9765 A5B6 6843 17BC A646 BE8C FA56 373A 5374 C703
Old SysOps never die... they simply forget their password.

2004-11-30 19:30:52

by Fabio Coatti

[permalink] [raw]
Subject: Re: 2.6.10-rc2-mm2 usb storage still oopses

Alle 04:22, marted? 30 novembre 2004, James Bottomley ha scritto:

> >
> > Guys, is this problem still present in Linus's tree? If so, is a fix for
> > 2.6.10 looking feasible?
>
> Al Viro has a tentative one at
>
> http://ftp.linux.org.uk/pub/people/viro/register_disk-hack
>
> If someone could try it out and verify that it fixes the problem, we
> could put it in.

OK, here the result for tests, using 2.6.10-rc2-mm4.
I've to put a
options usbcore old_scheme_first=1
in modprobe.conf, otherwise the device is not detected.
With this option set, all works just fine (no ub module compiled or loaded, if
needed I can try also with this): no oopses, no call trace, it just works :)

The only small issue is that if i leave plugged the usb flash key and
power-cycle my box, at boot the device is not detected and it fails in the
same way it happens when usbcore old_scheme_first is not set (it's present in
modprobe.conf)

If I unplug/plug the device, all works just fine.

Great work !

Full logs:

Inserting the device with usbcore old_scheme_first=1:

Nov 30 19:54:41 kefk kernel: hub 5-0:1.0: state 5 ports 8 chg ff00 evt 0008
Nov 30 19:54:41 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001803 POWER sig=j CSC CONNECT
Nov 30 19:54:41 kefk kernel: hub 5-0:1.0: port 3, status 0501, change 0001,
480 Mb/s
Nov 30 19:54:41 kefk kernel: hub 5-0:1.0: debounce: port 3: total 100ms stable
100ms status 0x501
Nov 30 19:54:41 kefk kernel: ehci_hcd 0000:00:1d.7: port 3 high speed
Nov 30 19:54:41 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001005 POWER sig=se0 PE CONNECT
Nov 30 19:54:41 kefk kernel: usb 5-3: new high speed USB device using ehci_hcd
and address 3
Nov 30 19:54:41 kefk kernel: usb 5-3: new device strings: Mfr=1, Product=2,
SerialNumber=3
Nov 30 19:54:41 kefk kernel: usb 5-3: default language 0x0409
Nov 30 19:54:41 kefk kernel: usb 5-3: Product: Mass storage
Nov 30 19:54:41 kefk kernel: usb 5-3: Manufacturer: USB
Nov 30 19:54:41 kefk kernel: usb 5-3: SerialNumber: 142E19413C2FCA34
Nov 30 19:54:41 kefk kernel: usb 5-3: hotplug
Nov 30 19:54:41 kefk kernel: usb 5-3: adding 5-3:1.0 (config #1, interface 0)
Nov 30 19:54:41 kefk kernel: usb 5-3:1.0: hotplug
Nov 30 19:54:42 kefk kernel: Initializing USB Mass Storage driver...
Nov 30 19:54:42 kefk kernel: usb-storage 5-3:1.0: usb_probe_interface
Nov 30 19:54:42 kefk kernel: usb-storage 5-3:1.0: usb_probe_interface - got id
Nov 30 19:54:42 kefk kernel: scsi3 : SCSI emulation for USB Mass Storage
devices
Nov 30 19:54:42 kefk kernel: usbcore: registered new driver usb-storage
Nov 30 19:54:42 kefk kernel: USB Mass Storage support registered.
Nov 30 19:54:42 kefk kernel: usb-storage: device found at 3
Nov 30 19:54:42 kefk kernel: usb-storage: waiting for device to settle before
scanning
Nov 30 19:54:47 kefk kernel: Vendor: 512MB Model: USB2.0FlashDrive Rev:
2.00
Nov 30 19:54:47 kefk kernel: Type: Direct-Access ANSI
SCSI revision: 02
Nov 30 19:54:47 kefk kernel: sdb: Unit Not Ready, sense:
Nov 30 19:54:47 kefk kernel: : Current: sense key=0x6
Nov 30 19:54:47 kefk kernel: ASC=0x28 ASCQ=0x0
Nov 30 19:54:47 kefk kernel: sdb : READ CAPACITY failed.
Nov 30 19:54:47 kefk kernel: sdb : status=1, message=00, host=0, driver=08
Nov 30 19:54:47 kefk kernel: sd: Current: sense key=0x6
Nov 30 19:54:47 kefk kernel: ASC=0x28 ASCQ=0x0
Nov 30 19:54:47 kefk kernel: sdb: test WP failed, assume Write Enabled
Nov 30 19:54:47 kefk kernel: sdb: assuming drive cache: write through
Nov 30 19:54:47 kefk kernel: sdb: Unit Not Ready, sense:
Nov 30 19:54:47 kefk kernel: : Current: sense key=0x6
Nov 30 19:54:47 kefk kernel: ASC=0x28 ASCQ=0x0
Nov 30 19:54:47 kefk kernel: SCSI device sdb: 1024000 512-byte hdwr sectors
(524 MB)
Nov 30 19:54:47 kefk kernel: sdb: Write Protect is off
Nov 30 19:54:47 kefk kernel: sdb: Mode Sense: 03 00 00 00
Nov 30 19:54:47 kefk kernel: sdb: assuming drive cache: write through
Nov 30 19:54:47 kefk kernel: SCSI device sdb: 1024000 512-byte hdwr sectors
(524 MB)
Nov 30 19:54:47 kefk kernel: sdb: Write Protect is off
Nov 30 19:54:47 kefk kernel: sdb: Mode Sense: 03 00 00 00
Nov 30 19:54:47 kefk kernel: sdb: assuming drive cache: write through
Nov 30 19:54:47 kefk kernel: sdb: sdb1
Nov 30 19:54:47 kefk kernel: Attached scsi removable disk sdb at scsi3,
channel 0, id 0, lun 0
Nov 30 19:54:47 kefk kernel: Attached scsi generic sg4 at scsi3, channel 0, id
0, lun 0, type 0
Nov 30 19:54:47 kefk kernel: usb-storage: device scan complete
Nov 30 19:54:47 kefk scsi.agent[7714]: disk
at /devices/pci0000:00/0000:00:1d.7/usb5/5-3/5-3:1.0/host3/target3:0:0/3:0:0:0


removing it:
Nov 30 19:55:44 kefk kernel: hub 5-0:1.0: state 5 ports 8 chg ff00 evt 0008
Nov 30 19:55:44 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001002 POWER sig=se0 CSC
Nov 30 19:55:44 kefk kernel: hub 5-0:1.0: port 3, status 0100, change 0001, 12
Mb/s
Nov 30 19:55:44 kefk kernel: usb 5-3: USB disconnect, address 3
Nov 30 19:55:44 kefk kernel: usb 5-3: usb_disable_device nuking all URBs
Nov 30 19:55:44 kefk kernel: usb 5-3: unregistering interface 5-3:1.0
Nov 30 19:55:44 kefk kernel: usb 5-3:1.0: hotplug
Nov 30 19:55:44 kefk kernel: usb 5-3: unregistering device
Nov 30 19:55:44 kefk kernel: usb 5-3: hotplug
Nov 30 19:55:44 kefk kernel: hub 5-0:1.0: debounce: port 3: total 100ms stable
100ms status 0x100


inserting the device with old_scheme_first not set:

Nov 30 20:00:25 kefk kernel: hub 5-0:1.0: state 5 ports 8 chg ff00 evt 0008
Nov 30 20:00:25 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001803 POWER sig=j CSC CONNECT
Nov 30 20:00:25 kefk kernel: hub 5-0:1.0: port 3, status 0501, change 0001,
480 Mb/s
Nov 30 20:00:25 kefk kernel: hub 5-0:1.0: debounce: port 3: total 100ms stable
100ms status 0x501
Nov 30 20:00:25 kefk kernel: ehci_hcd 0000:00:1d.7: port 3 high speed
Nov 30 20:00:25 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001005 POWER sig=se0 PE CONNECT
Nov 30 20:00:25 kefk kernel: usb 5-3: new high speed USB device using ehci_hcd
and address 3
Nov 30 20:00:25 kefk kernel: ehci_hcd 0000:00:1d.7: devpath 3 ep0in 3strikes
Nov 30 20:00:25 kefk kernel: ehci_hcd 0000:00:1d.7: port 3 full speed -->
companion
Nov 30 20:00:25 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
003801 POWER OWNER sig=j CONNECT
Nov 30 20:00:25 kefk kernel: uhci_hcd 0000:00:1d.1: wakeup_hc
Nov 30 20:00:26 kefk kernel: hub 2-0:1.0: state 5 ports 2 chg fffc evt 0002
Nov 30 20:00:26 kefk kernel: uhci_hcd 0000:00:1d.1: port 1 portsc 0083,00
Nov 30 20:00:26 kefk kernel: hub 2-0:1.0: port 1, status 0101, change 0001, 12
Mb/s
Nov 30 20:00:26 kefk kernel: hub 2-0:1.0: debounce: port 1: total 100ms stable
100ms status 0x101
Nov 30 20:00:26 kefk kernel: usb 2-1: new full speed USB device using uhci_hcd
and address 2
Nov 30 20:00:26 kefk kernel: uhci_hcd 0000:00:1d.1: uhci_result_control:
failed with status 440000
Nov 30 20:00:26 kefk kernel: [f7977240] link (379771b2) element (37a86040)
Nov 30 20:00:26 kefk kernel: 0: [f7a86040] link (37a86080) e0 Stalled
CRC/Timeo Length=7 MaxLen=7 DT0 EndPt=0 Dev=0, PID=2d(SETUP) (buf=37144ba0)
Nov 30 20:00:26 kefk kernel: 1: [f7a86080] link (37a860c0) e3 SPD Active
Length=0 MaxLen=3f DT1 EndPt=0 Dev=0, PID=69(IN) (buf=355ae500)
Nov 30 20:00:26 kefk kernel: 2: [f7a860c0] link (00000001) e3 IOC Active
Length=0 MaxLen=7ff DT1 EndPt=0 Dev=0, PID=e1(OUT) (buf=00000000)
Nov 30 20:00:26 kefk kernel:
Nov 30 20:00:26 kefk kernel: usb 2-1: device descriptor read/64, error -71
Nov 30 20:00:26 kefk kernel: uhci_hcd 0000:00:1d.1: uhci_result_control:
failed with status 440000
Nov 30 20:00:26 kefk kernel: [f7977240] link (379771b2) element (37a86040)
Nov 30 20:00:26 kefk kernel: 0: [f7a86040] link (37a86080) e0 Stalled
CRC/Timeo Length=7 MaxLen=7 DT0 EndPt=0 Dev=0, PID=2d(SETUP) (buf=36486e60)
Nov 30 20:00:26 kefk kernel: 1: [f7a86080] link (37a860c0) e3 SPD Active
Length=0 MaxLen=3f DT1 EndPt=0 Dev=0, PID=69(IN) (buf=355aef00)
Nov 30 20:00:26 kefk kernel: 2: [f7a860c0] link (00000001) e3 IOC Active
Length=0 MaxLen=7ff DT1 EndPt=0 Dev=0, PID=e1(OUT) (buf=00000000)

Now, rebooting the box leaving the device inserted, with old_scheme_first=1 in
modprobe.conf

Nov 30 20:03:40 kefk kernel: usb 4-0:1.0: hotplug
Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: usb_probe_interface
Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: usb_probe_interface - got id
Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: USB hub found
Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: 2 ports detected
Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: standalone hub
Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: no power switching (usb 1.0)
Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: individual port over-current
protection
Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: power on to power good time: 2ms
Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: local power source is good
Nov 30 20:03:40 kefk kernel: hub 2-0:1.0: debounce: port 1: total 100ms stable
100ms status 0x101
Nov 30 20:03:40 kefk kernel: usb 2-1: new full speed USB device using uhci_hcd
and address 2
Nov 30 20:03:40 kefk kernel: uhci_hcd 0000:00:1d.1: uhci_result_control:
failed with status 440000
Nov 30 20:03:40 kefk kernel: [f7ab5240] link (37ab51b2) element (37ab4040)
Nov 30 20:03:40 kefk kernel: 0: [f7ab4040] link (37ab4080) e0 Stalled
CRC/Timeo Length=7 MaxLen=7 DT0 EndPt=0 Dev=0, PID=2d(SETUP) (buf=37998f20)
Nov 30 20:03:40 kefk kernel: 1: [f7ab4080] link (00000001) e3 IOC Active
Length=0 MaxLen=7ff DT1 EndPt=0 Dev=0, PID=69(IN) (buf=00000000)
Nov 30 20:03:40 kefk kernel:
Nov 30 20:03:40 kefk kernel: uhci_hcd 0000:00:1d.1: uhci_result_control:
failed with status 440000
Nov 30 20:03:40 kefk kernel: [f7ab5240] link (37ab51b2) element (37ab4040)
Nov 30 20:03:40 kefk kernel: 0: [f7ab4040] link (37ab4080) e0 Stalled
CRC/Timeo Length=7 MaxLen=7 DT0 EndPt=0 Dev=0, PID=2d(SETUP) (buf=378ef180)
Nov 30 20:03:40 kefk kernel: 1: [f7ab4080] link (00000001) e3 IOC Active
Length=0 MaxLen=7ff DT1 EndPt=0 Dev=0, PID=69(IN) (buf=00000000)
Nov 30 20:03:40 kefk kernel:
Nov 30 20:03:40 kefk kernel: usb 2-1: device not accepting address 2, error
-71
Nov 30 20:03:40 kefk kernel: usb 2-1: new full speed USB device using uhci_hcd
and address 3
Nov 30 20:03:40 kefk kernel: uhci_hcd 0000:00:1d.1: uhci_result_control:
failed with status 440000
Nov 30 20:03:40 kefk kernel: [f7ab5240] link (37ab51b2) element (37ab4040)
Nov 30 20:03:40 kefk kernel: 0: [f7ab4040] link (37ab4080) e0 Stalled
CRC/Timeo Length=7 MaxLen=7 DT0 EndPt=0 Dev=0, PID=2d(SETUP) (buf=378ef180)
Nov 30 20:03:40 kefk kernel: 1: [f7ab4080] link (00000001) e3 IOC Active
Length=0 MaxLen=7ff DT1 EndPt=0 Dev=0, PID=69(IN) (buf=00000000)

After this, if I remove and plug again the device, all works just fine.







--
Fabio Coatti http://members.ferrara.linux.it/cova
Ferrara Linux Users Group http://ferrara.linux.it
GnuPG fp:9765 A5B6 6843 17BC A646 BE8C FA56 373A 5374 C703
Old SysOps never die... they simply forget their password.

2004-11-30 21:00:05

by Alan Stern

[permalink] [raw]
Subject: Re: [linux-usb-devel] Re: 2.6.10-rc2-mm2 usb storage still oopses

On Tue, 30 Nov 2004, Fabio Coatti wrote:

> The only small issue is that if i leave plugged the usb flash key and
> power-cycle my box, at boot the device is not detected and it fails in the
> same way it happens when usbcore old_scheme_first is not set (it's present in
> modprobe.conf)
>
> If I unplug/plug the device, all works just fine.

> Now, rebooting the box leaving the device inserted, with old_scheme_first=1 in
> modprobe.conf
>
> Nov 30 20:03:40 kefk kernel: usb 4-0:1.0: hotplug
> Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: usb_probe_interface
> Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: usb_probe_interface - got id
> Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: USB hub found
> Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: 2 ports detected
> Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: standalone hub
> Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: no power switching (usb 1.0)
> Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: individual port over-current
> protection
> Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: power on to power good time: 2ms
> Nov 30 20:03:40 kefk kernel: hub 4-0:1.0: local power source is good
> Nov 30 20:03:40 kefk kernel: hub 2-0:1.0: debounce: port 1: total 100ms stable
> 100ms status 0x101
> Nov 30 20:03:40 kefk kernel: usb 2-1: new full speed USB device using uhci_hcd
> and address 2
> Nov 30 20:03:40 kefk kernel: uhci_hcd 0000:00:1d.1: uhci_result_control:
> failed with status 440000
> Nov 30 20:03:40 kefk kernel: [f7ab5240] link (37ab51b2) element (37ab4040)
> Nov 30 20:03:40 kefk kernel: 0: [f7ab4040] link (37ab4080) e0 Stalled
> CRC/Timeo Length=7 MaxLen=7 DT0 EndPt=0 Dev=0, PID=2d(SETUP) (buf=37998f20)
> Nov 30 20:03:40 kefk kernel: 1: [f7ab4080] link (00000001) e3 IOC Active
> Length=0 MaxLen=7ff DT1 EndPt=0 Dev=0, PID=69(IN) (buf=00000000)
> Nov 30 20:03:40 kefk kernel:
> Nov 30 20:03:40 kefk kernel: uhci_hcd 0000:00:1d.1: uhci_result_control:
> failed with status 440000
> Nov 30 20:03:40 kefk kernel: [f7ab5240] link (37ab51b2) element (37ab4040)
> Nov 30 20:03:40 kefk kernel: 0: [f7ab4040] link (37ab4080) e0 Stalled
> CRC/Timeo Length=7 MaxLen=7 DT0 EndPt=0 Dev=0, PID=2d(SETUP) (buf=378ef180)
> Nov 30 20:03:40 kefk kernel: 1: [f7ab4080] link (00000001) e3 IOC Active
> Length=0 MaxLen=7ff DT1 EndPt=0 Dev=0, PID=69(IN) (buf=00000000)
> Nov 30 20:03:40 kefk kernel:
> Nov 30 20:03:40 kefk kernel: usb 2-1: device not accepting address 2, error
> -71
> Nov 30 20:03:40 kefk kernel: usb 2-1: new full speed USB device using uhci_hcd
> and address 3
> Nov 30 20:03:40 kefk kernel: uhci_hcd 0000:00:1d.1: uhci_result_control:
> failed with status 440000
> Nov 30 20:03:40 kefk kernel: [f7ab5240] link (37ab51b2) element (37ab4040)
> Nov 30 20:03:40 kefk kernel: 0: [f7ab4040] link (37ab4080) e0 Stalled
> CRC/Timeo Length=7 MaxLen=7 DT0 EndPt=0 Dev=0, PID=2d(SETUP) (buf=378ef180)
> Nov 30 20:03:40 kefk kernel: 1: [f7ab4080] link (00000001) e3 IOC Active
> Length=0 MaxLen=7ff DT1 EndPt=0 Dev=0, PID=69(IN) (buf=00000000)
>
> After this, if I remove and plug again the device, all works just fine.

This log shows that the device was operating at full speed, not at high
speed. Probably your boot-up sequence involves loading the uhci-hcd
driver before ehci-hcd.

It may be that the device wants old_scheme_first to be set when it's
operating at high speed and not set when operating at full speed! You can
test this guess by unloading one driver or the other and then plugging in
the device.

Alan Stern

2004-12-01 01:14:49

by Fabio Coatti

[permalink] [raw]
Subject: Re: [linux-usb-devel] Re: 2.6.10-rc2-mm2 usb storage still oopses

Alle 21:58, marted? 30 novembre 2004, Alan Stern ha scritto:

> It may be that the device wants old_scheme_first to be set when it's
> operating at high speed and not set when operating at full speed! You can
> test this guess by unloading one driver or the other and then plugging in
> the device.

Well, I've tried and in fact without
old_scheme_first set ehci hands over the device to uhci, that fails to detect
it.
And in fact uhci is loaded at boot before ehci. I've modified this, but the
behaviour is not ok: it seems that the device is detected ok even if already
present at boot, but then I've a keyoboard/mouse lockup

Dec 1 01:40:26 kefk kernel: ehci_hcd 0000:00:1d.7: port 3 high speed
Dec 1 01:40:26 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001005 POWER sig=se0 PE CONNECT
Dec 1 01:40:26 kefk kernel: usb 1-3: new high speed USB device using ehci_hcd
and address 3
Dec 1 01:40:26 kefk kernel: usb 1-3: new device strings: Mfr=1, Product=2,
SerialNumber=3
Dec 1 01:40:26 kefk kernel: usb 1-3: default language 0x0409
Dec 1 01:40:26 kefk kernel: usb 1-3: Product: Mass storage
Dec 1 01:40:26 kefk kernel: usb 1-3: Manufacturer: USB
Dec 1 01:40:26 kefk kernel: usb 1-3: SerialNumber: 142E19413C2FCA34
Dec 1 01:40:26 kefk kernel: usb 1-3: hotplug
Dec 1 01:40:26 kefk kernel: PCI: Setting latency timer of device 0000:00:1d.2
to 64
Dec 1 01:40:26 kefk kernel: uhci_hcd 0000:00:1d.2: irq 169, io base 0xb400
Dec 1 01:40:26 kefk kernel: usb 1-3: adding 1-3:1.0 (config #1, interface 0)
Dec 1 01:40:26 kefk kernel: usb 1-3:1.0: hotplug


when cupds starts, that uses usb printer, the keyboard and mouse gets locked,
simply no key press or mouse move are detected. (or, at least, it seems that
cups driver loading causes the lockup, but I can try to repeat this).
the first log row after cups loading is this:
Dec 1 01:40:30 kefk kernel: ACPI: PCI interrupt 0000:03:04.0[A] -> GSI 20
(level, low) -> IRQ 209

But I don't think taht this can be so useful.
Please let me know is different details are needed.


This happens only when ehci is loaded before uhci and flash key is present at
boot.
If I keep unplugged the flash key the boot sequence goes on without problem,
then I can plug and use flash key.

I'm unable to see on the logs where something goes wrong, but if you can tell
me if more data are needed I can cut&paste the logs.



--
Fabio Coatti http://members.ferrara.linux.it/cova
Ferrara Linux Users Group http://ferrara.linux.it
GnuPG fp:9765 A5B6 6843 17BC A646 BE8C FA56 373A 5374 C703
Old SysOps never die... they simply forget their password.