Bug 11260

Summary: Regression: USB memory stick triggers several USB resets before settling with bogus capacity
Product: Drivers Reporter: Alex Villacis Lasso (avillaci)
Component: USBAssignee: Greg Kroah-Hartman (greg)
Status: CLOSED CODE_FIX    
Severity: normal CC: stern
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 2.6.27-rc2 Subsystem:
Regression: Yes Bisected commit-id:
Bug Depends on:    
Bug Blocks: 11167    
Attachments: bzipped dmesg output with USB_DEBUG, USB_ANNOUNCE_NEW_DEVICES and USB_STORAGE_DEBUG when inserting USB stick
Stick inserted, manually modprobe usb-storage
usbmon trace with stick inserted, and manually modprobe usb-storage

Description Alex Villacis Lasso 2008-08-06 13:33:35 UTC
Latest working kernel version: 2.6.25 (possibly 2.6.26)
Earliest failing kernel version: 2.6.27-rc1
Distribution: Fedora 8
Hardware Environment:
Software Environment:

If some fields are empty or look unusual you may have an old version.
Compare to the current minimal requirements in Documentation/Changes.
 
Linux srv64.palosanto.com 2.6.27-rc2 #2 PREEMPT Wed Aug 6 14:48:09 ECT 2008 i686 i686 i386 GNU/Linux
 
Gnu C                  4.1.2
Gnu make               3.81
binutils               2.17.50.0.18
util-linux             2.13.1
mount                  2.13.1
module-init-tools      found
quota-tools            3.14.
Linux C Library        2.7
Dynamic linker (ldd)   2.7
Procps                 3.2.7
Kbd                    1.12
oprofile               0.9.3
Sh-utils               6.9
udev                   118
Modules Loaded         vfat fat usb_storage fuse rfcomm l2cap bluetooth dm_mirror dm_log dm_multipath dm_mod radeon drm ipv6 sr_mod cdrom snd_pcsp snd_seq_dummy snd_hda_intel snd_seq_oss snd_seq_midi_event snd_seq snd_seq_device 8139cp snd_pcm_oss snd_mixer_oss snd_pcm 8139too mii snd_timer snd_page_alloc snd_hwdep i2c_piix4 i2c_core pata_atiixp snd soundcore button sg pata_acpi ata_generic sata_sil libata sd_mod scsi_mod ext3 jbd mbcache uhci_hcd ohci_hcd ehci_hcd


Problem Description:

One particular USB flash-memory stick (identifes itself as "Corsair Voyager") that worked correctly up to 2.6.25, now triggers messages upon insertion in 2.6.27-rc1 and 2.6.27-rc2:

usb 1-2: new high speed USB device using ehci_hcd and address 2
usb 1-2: configuration #1 chosen from 1 choice
Initializing USB Mass Storage driver...
scsi6 : SCSI emulation for USB Mass Storage devices
usbcore: registered new interface driver usb-storage
USB Mass Storage support registered.
usb-storage: device found at 2
usb-storage: waiting for device to settle before scanning
usb-storage: device scan complete
scsi 6:0:0:0: Direct-Access     Corsair  Flash Voyager    1100 PQ: 0 ANSI: 0 CCS
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
sd 6:0:0:0: [sdb] READ CAPACITY(16) failed
sd 6:0:0:0: [sdb] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
sd 6:0:0:0: [sdb] Use 0xffffffff as device size
sd 6:0:0:0: [sdb] Sector size 0 reported, assuming 512.
sd 6:0:0:0: [sdb] 4294967296 512-byte hardware sectors (2199023 MB)
sd 6:0:0:0: [sdb] Write Protect is off
sd 6:0:0:0: [sdb] Mode Sense: 43 00 00 00
sd 6:0:0:0: [sdb] Assuming drive cache: write through
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
usb 1-2: reset high speed USB device using ehci_hcd and address 2
sd 6:0:0:0: [sdb] READ CAPACITY(16) failed
sd 6:0:0:0: [sdb] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
sd 6:0:0:0: [sdb] Use 0xffffffff as device size
sd 6:0:0:0: [sdb] Sector size 0 reported, assuming 512.
sd 6:0:0:0: [sdb] 4294967296 512-byte hardware sectors (2199023 MB)
sd 6:0:0:0: [sdb] Write Protect is off
sd 6:0:0:0: [sdb] Mode Sense: 43 00 00 00
sd 6:0:0:0: [sdb] Assuming drive cache: write through
sdb: sdb1
sd 6:0:0:0: [sdb] Attached SCSI removable disk
sd 6:0:0:0: Attached scsi generic sg2 type 0
SELinux: initialized (dev sdb1, type vfat), uses genfs_contexts 

After this, fdisk reports a bogus total capacity:

Disco /dev/sdb: 2199.0 GB, 2199023255552 bytes
16 heads, 61 sectors/track, 4400581 cylinders
Units = cilindros of 976 * 512 = 499712 bytes
Disk identifier: 0x00000000

Disposit. Inicio    Comienzo      Fin      Bloques  Id  Sistema
/dev/sdb1   *           1        1014      494801+   6  FAT16 

Stick seems to work  "correctly" after this - reads work correctly, have not tested writes. A Sansa Express MP3 player that exposes a USB drive does *not* trigger the bug.

Steps to reproduce:

Get a Corsair Voyager USB stick
Plug it in (in root hub).

Expected:
No errors upon insertion. Reports 507 Mb as total capacity.

Actual:
Several ehci resets. READ_CAPACITY fails and kernel reports a bogus total capacity.

[alex@srv64 usb]$ cat /proc/bus/usb/devices

T:  Bus=03 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=12  MxCh= 4
B:  Alloc=  0/900 us ( 0%), #Int=  0, #Iso=  0
D:  Ver= 1.10 Cls=09(hub  ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=1d6b ProdID=0001 Rev= 2.06
S:  Manufacturer=Linux 2.6.27-rc2 ohci_hcd
S:  Product=OHCI Host Controller
S:  SerialNumber=0000:00:13.1
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=  0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   2 Ivl=255ms

T:  Bus=02 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=12  MxCh= 4
B:  Alloc=  0/900 us ( 0%), #Int=  0, #Iso=  0
D:  Ver= 1.10 Cls=09(hub  ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=1d6b ProdID=0001 Rev= 2.06
S:  Manufacturer=Linux 2.6.27-rc2 ohci_hcd
S:  Product=OHCI Host Controller
S:  SerialNumber=0000:00:13.0
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=  0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   2 Ivl=255ms

T:  Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=480 MxCh= 8
B:  Alloc=  0/800 us ( 0%), #Int=  0, #Iso=  0
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=1d6b ProdID=0002 Rev= 2.06
S:  Manufacturer=Linux 2.6.27-rc2 ehci_hcd
S:  Product=EHCI Host Controller
S:  SerialNumber=0000:00:13.2
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=  0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   4 Ivl=256ms

T:  Bus=01 Lev=01 Prnt=01 Port=01 Cnt=01 Dev#=  4 Spd=480 MxCh= 0
D:  Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=090c ProdID=1000 Rev=11.00
S:  Manufacturer=Corsair
S:  Product=Flash Voyager
S:  SerialNumber=A100000000000604
C:* #Ifs= 1 Cfg#= 1 Atr=80 MxPwr=100mA
I:* If#= 0 Alt= 0 #EPs= 2 Cls=08(stor.) Sub=06 Prot=50 Driver=usb-storage
E:  Ad=81(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=02(O) Atr=02(Bulk) MxPS= 512 Ivl=31875us
Comment 1 Alex Villacis Lasso 2008-08-06 13:34:51 UTC
Created attachment 17109 [details]
bzipped dmesg output with USB_DEBUG, USB_ANNOUNCE_NEW_DEVICES and USB_STORAGE_DEBUG when inserting USB stick
Comment 2 Alex Villacis Lasso 2008-08-06 13:49:30 UTC
Created attachment 17110 [details]
Stick inserted, manually modprobe usb-storage

The bug can be triggered merely by rmmod usb-storage, followed by modprobe usb-storage, with the stick in place in the root hub. Resulting trace attached.
Comment 3 Rafael J. Wysocki 2008-08-06 13:56:29 UTC
It would be helpful to verify if 2.6.26 is affected.
Comment 4 Alex Villacis Lasso 2008-08-06 13:57:17 UTC
Created attachment 17111 [details]
usbmon trace with stick inserted, and manually modprobe usb-storage

This is a usbmon trace of the traffic sent when stick is already inserted, with manual loading of usb-storage. Kernel is 2.6.27-rc2
Comment 5 Alex Villacis Lasso 2008-08-06 16:51:35 UTC
Apparently this problem is already known and fixed (though not yet pulled into mainline):

Message http://marc.info/?l=linux-kernel&m=121804333614405&w=2 contains a fix, and http://marc.info/?l=linux-kernel&m=121804127910374&w=2 discusses what happened in the regression. 

Currently compiling kernel in order to test the patch.
Comment 6 Alex Villacis Lasso 2008-08-07 08:55:26 UTC
(In reply to comment #5)
> Apparently this problem is already known and fixed (though not yet pulled
> into
> mainline):
> 
> Message http://marc.info/?l=linux-kernel&m=121804333614405&w=2 contains a
> fix,
> and http://marc.info/?l=linux-kernel&m=121804127910374&w=2 discusses what
> happened in the regression. 
> 
> Currently compiling kernel in order to test the patch.
> 

I hereby confirm that the proposed fix actually works and fixes the errors in my case too. 

For the record, the fix is the following patch:

diff -ur /home/alex/checkouts/linux-2.6-git/include/scsi/scsi_device.h linux-2.6.27-rc2/include/scsi/scsi_device.h
--- /home/alex/checkouts/linux-2.6-git/include/scsi/scsi_device.h       2008-08-06 10:12:46.000000000 -0500
+++ linux-2.6.27-rc2/include/scsi/scsi_device.h 2008-08-06 18:28:05.000000000 -0500
@@ -6,6 +6,7 @@
 #include <linux/spinlock.h>
 #include <linux/workqueue.h>
 #include <linux/blkdev.h>
+#include <scsi/scsi.h>
 #include <asm/atomic.h>
 
 struct request_queue;
@@ -426,7 +427,7 @@
 
 static inline int scsi_device_protection(struct scsi_device *sdev)
 {
-       return sdev->inquiry[5] & (1<<0);
+       return sdev->scsi_level > SCSI_2 && sdev->inquiry[5] & (1<<0);
 }
 
 #define MODULE_ALIAS_SCSI_DEVICE(type) \
Comment 7 Rafael J. Wysocki 2008-08-07 15:34:53 UTC
Handled-By : Hugh Dickins <hugh@veritas.com>
Patch : http://marc.info/?l=linux-kernel&m=121804333614405&w=2
Comment 8 Rafael J. Wysocki 2008-08-11 10:33:25 UTC
On Monday, 11 of August 2008, Alex Villací­s Lasso wrote:
> Rafael J. Wysocki escribió:
> > This message has been generated automatically as a part of a report
> > of recent regressions.
> >
> > The following bug entry is on the current list of known regressions
> > from 2.6.26.  Please verify if it still should be listed and let me know
> > (either way).
> >
> >
> > Bug-Entry   : http://bugzilla.kernel.org/show_bug.cgi?id=11260
> > Subject             : Regression: USB memory stick triggers several USB
> resets before settling with bogus capacity
> > Submitter   : Alex Villacis Lasso <avillaci@ceibo.fiec.espol.edu.ec>
> > Date                : 2008-08-06 13:33 (4 days old)
> > Handled-By  : Hugh Dickins <hugh@veritas.com>
> > Patch               :
> http://marc.info/?l=linux-kernel&m=121804333614405&w=2
> >
> >
> >
> >   
> As of 12:01 GMT -5 with git tree at commit 
> 796aadeb1b2db9b5d463946766c5bbfd7717158c , the patch has not yet been 
> merged into mainline.
Comment 9 Rafael J. Wysocki 2008-08-17 05:15:03 UTC
On Sunday, 17 of August 2008, Hugh Dickins wrote:
> On Sat, 16 Aug 2008, Rafael J. Wysocki wrote:
> > 
> > Bug-Entry   : http://bugzilla.kernel.org/show_bug.cgi?id=11260
> > Subject             : Regression: USB memory stick triggers several USB
> resets before settling with bogus capacity
> > Submitter   : Alex Villacis Lasso <avillaci@ceibo.fiec.espol.edu.ec>
> > Date                : 2008-08-06 13:33 (11 days old)
> > Handled-By  : Hugh Dickins <hugh@veritas.com>
> > Patch               :
> http://marc.info/?l=linux-kernel&m=121804333614405&w=2
> 
> James has this fix queued in his scsi-rc-fixes for 2.6.27
> 
>
> http://git.kernel.org/?p=linux/kernel/git/jejb/scsi-rc-fixes-2.6.git;a=commit;h=d211f052fa58a053639bc51501cb64421157d362
> 
> but hasn't asked Linus to pull for a while: I'm hoping it'll get into -rc4.