2008-06-23 21:44:22

by Rafael J. Wysocki

[permalink] [raw]
Subject: 2.6.27-rc7-git1: usb-storage breakage with non-functional disk

Hi,

This has just happened to me with -rc7-git1 while trying to use a not
sufficiently powered external disk (we should survive that IMO):

usb 6-3: new high speed USB device using ehci_hcd and address 9
usb 6-3: device descriptor read/64, error -110
usb 6-3: device descriptor read/64, error -110
usb 6-3: new high speed USB device using ehci_hcd and address 10
usb 6-3: device descriptor read/64, error -110
usb 6-3: device descriptor read/64, error -110
usb 6-3: new high speed USB device using ehci_hcd and address 11
usb 6-3: device not accepting address 11, error -110
usb 6-3: new high speed USB device using ehci_hcd and address 12
usb 6-3: device not accepting address 12, error -110
hub 6-0:1.0: unable to enumerate USB device on port 3
usb 2-1: new full speed USB device using ohci_hcd and address 2
usb 2-1: not running at top speed; connect to a high speed hub
usb 2-1: configuration #1 chosen from 1 choice
usb 2-1: New USB device found, idVendor=04cf, idProduct=8818
usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
usb 2-1: Product: USB Mass Storage Device
usb 2-1: Manufacturer: Myson Century, Inc.
usb 2-1: SerialNumber: 100
Initializing USB Mass Storage driver...
scsi12 : SCSI emulation for USB Mass Storage devices
usb-storage: device found at 2
usb-storage: waiting for device to settle before scanning
usbcore: registered new interface driver usb-storage
USB Mass Storage support registered.
scsi 12:0:0:0: Direct-Access IC25N060 ATMR04-0 MO3O PQ: 0 ANSI: 0 CCS
sd 12:0:0:0: [sdc] 117210240 512-byte hardware sectors (60012 MB)
sd 12:0:0:0: [sdc] Write Protect is off
sd 12:0:0:0: [sdc] Mode Sense: 00 14 00 00
sd 12:0:0:0: [sdc] Assuming drive cache: write through
sd 12:0:0:0: [sdc] 117210240 512-byte hardware sectors (60012 MB)
sd 12:0:0:0: [sdc] Write Protect is off
sd 12:0:0:0: [sdc] Mode Sense: 00 14 00 00
sd 12:0:0:0: [sdc] Assuming drive cache: write through
sdc:<6>usb 2-1: USB disconnect, address 2
sd 12:0:0:0: [sdc] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
end_request: I/O error, dev sdc, sector 0
Buffer I/O error on device sdc, logical block 0
sd 12:0:0:0: [sdc] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
end_request: I/O error, dev sdc, sector 0
Buffer I/O error on device sdc, logical block 0
unable to read partition table
sd 12:0:0:0: [sdc] Attached SCSI disk
sd 12:0:0:0: Attached scsi generic sg3 type 0
BUG: unable to handle kernel NULL pointer dereference at 0000000000000004
IP: [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
PGD 1260ff067 PUD 119076067 PMD 0
Oops: 0000 [1] SMP
CPU 3
Modules linked in: usb_storage parport_pc lp parport usblp nfsd lockd auth_rpcgss sunrpc exportfs iptable_filter ip_tables ip6table_filter ip6_tables x_tables ipv6 cpufreq_conservative cpufreq_ondemand cpufreq_userspace cpufreq_powersave powernow_k8 freq_table snd_pcm_oss snd_mixer_oss snd_seq snd_seq_device reiserfs dm_mod ohci1394 sr_mod cdrom floppy ieee1394 serio_raw rtc_cmos sky2 wmi snd_hda_intel rtc_core sg rtc_lib joydev snd_pcm snd_timer snd_page_alloc snd_hwdep snd evdev button soundcore raid456 async_xor async_memcpy async_tx xor raid0 usbhid ff_memless ehci_hcd ohci_hcd sd_mod edd raid1 ext3 jbd fan pata_marvell pata_atiixp thermal processor
Pid: 9319, comm: usb-stor-scan Not tainted 2.6.26-rc7 #196
RIP: 0010:[<ffffffffa038e6f1>] [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
RSP: 0018:ffff8100a20cdb60 EFLAGS: 00010202
RAX: 0000000000000000 RBX: ffff810087d828d0 RCX: 0000000000000003
RDX: ffff8101275f08e0 RSI: ffff810086cc49d0 RDI: ffff810124144b90
RBP: ffff8100a20cdb70 R08: 0000000000000001 R09: 0000000000000000
R10: ffffffff807fe7e0 R11: 0000000000000000 R12: ffff810087499000
R13: ffff810124953678 R14: ffff810087d82000 R15: 0000000000000000
FS: 00007f22f6561700(0000) GS:ffff810127c997c0(0000) knlGS:00000000eeb1db90
CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 0000000000000004 CR3: 0000000122089000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process usb-stor-scan (pid: 9319, threadinfo ffff8100a20cc000, task ffff810086cc4300)
Stack: ffff810087499000 ffff810124953650 ffff8100a20cdbb0 ffffffff803ea940
ffff8100a20cdbb0 ffff810087d82000 0000000000000000 0000000000000000
ffff810124953678 0000000000000000 ffff8100a20cdcf0 ffffffff803eac9a
Call Trace:
[<ffffffff803ea940>] scsi_alloc_sdev+0x1e0/0x250
[<ffffffff803eac9a>] scsi_probe_and_add_lun+0x12a/0xc20
[<ffffffff803ebd4f>] __scsi_scan_target+0x3bf/0x6c0
[<ffffffff8025db46>] ? mark_held_locks+0x56/0xa0
[<ffffffff804ebbe9>] ? mutex_lock_nested+0x1b9/0x290
[<ffffffff8025dcdf>] ? trace_hardirqs_on+0xbf/0x150
[<ffffffff803ec0da>] scsi_scan_channel+0x8a/0xa0
[<ffffffff803ec1e8>] scsi_scan_host_selected+0xf8/0x160
[<ffffffff803ec2ce>] do_scsi_scan_host+0x7e/0x80
[<ffffffff803ec850>] scsi_scan_host+0x190/0x1d0
[<ffffffffa0390f3d>] :usb_storage:usb_stor_scan_thread+0x6d/0x1c0
[<ffffffff8024f790>] ? autoremove_wake_function+0x0/0x40
[<ffffffffa0390ed0>] ? :usb_storage:usb_stor_scan_thread+0x0/0x1c0
[<ffffffff8024f33d>] kthread+0x4d/0x80
[<ffffffff8020c608>] child_rip+0xa/0x12
[<ffffffff8020bd1f>] ? restore_args+0x0/0x30
[<ffffffff8024f2f0>] ? kthread+0x0/0x80
[<ffffffff8020c5fe>] ? child_rip+0x0/0x12


Code: 1f c6 87 c3 00 00 00 24 48 8b 7f 08 48 81 c3 d0 08 00 00 8b 83 9c 00 00 00 48 8b 53 78 c1 e8 0f 83 e0 0f 48 8b 84 c2 e8 03 00 00 <0f> b7 70 04 ff ce e8 44 d9 fb df 80 bb c4 00 00 00 04 75 12 49
RIP [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
RSP <ffff8100a20cdb60>
CR2: 0000000000000004
---[ end trace 2077f860f94c5bf3 ]---
sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
end_request: I/O error, dev sdc, sector 0
Buffer I/O error on device sdc, logical block 0
Buffer I/O error on device sdc, logical block 1
Buffer I/O error on device sdc, logical block 2
Buffer I/O error on device sdc, logical block 3
sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
end_request: I/O error, dev sdc, sector 0
Buffer I/O error on device sdc, logical block 0
sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
end_request: I/O error, dev sdc, sector 117210112
Buffer I/O error on device sdc, logical block 14651264
sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
end_request: I/O error, dev sdc, sector 117210112
Buffer I/O error on device sdc, logical block 14651264
sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
end_request: I/O error, dev sdc, sector 117210112
Buffer I/O error on device sdc, logical block 14651264
sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
end_request: I/O error, dev sdc, sector 0
sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
end_request: I/O error, dev sdc, sector 0
sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
end_request: I/O error, dev sdc, sector 0
sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
end_request: I/O error, dev sdc, sector 117210232

It resulted in usb-storage being unusable and a system reboot.

Thanks,
Rafael


2008-06-23 21:49:25

by R. J. Wysocki

[permalink] [raw]
Subject: Re: 2.6.27-rc7-git1: usb-storage breakage with non-functional disk

[sorry for the broken USB list address in the original post.]

On Monday, 23 of June 2008, Rafael J. Wysocki wrote:
> Hi,
>
> This has just happened to me with -rc7-git1 while trying to use a not
> sufficiently powered external disk (we should survive that IMO):
>
> usb 6-3: new high speed USB device using ehci_hcd and address 9
> usb 6-3: device descriptor read/64, error -110
> usb 6-3: device descriptor read/64, error -110
> usb 6-3: new high speed USB device using ehci_hcd and address 10
> usb 6-3: device descriptor read/64, error -110
> usb 6-3: device descriptor read/64, error -110
> usb 6-3: new high speed USB device using ehci_hcd and address 11
> usb 6-3: device not accepting address 11, error -110
> usb 6-3: new high speed USB device using ehci_hcd and address 12
> usb 6-3: device not accepting address 12, error -110
> hub 6-0:1.0: unable to enumerate USB device on port 3
> usb 2-1: new full speed USB device using ohci_hcd and address 2
> usb 2-1: not running at top speed; connect to a high speed hub
> usb 2-1: configuration #1 chosen from 1 choice
> usb 2-1: New USB device found, idVendor=04cf, idProduct=8818
> usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
> usb 2-1: Product: USB Mass Storage Device
> usb 2-1: Manufacturer: Myson Century, Inc.
> usb 2-1: SerialNumber: 100
> Initializing USB Mass Storage driver...
> scsi12 : SCSI emulation for USB Mass Storage devices
> usb-storage: device found at 2
> usb-storage: waiting for device to settle before scanning
> usbcore: registered new interface driver usb-storage
> USB Mass Storage support registered.
> scsi 12:0:0:0: Direct-Access IC25N060 ATMR04-0 MO3O PQ: 0 ANSI: 0 CCS
> sd 12:0:0:0: [sdc] 117210240 512-byte hardware sectors (60012 MB)
> sd 12:0:0:0: [sdc] Write Protect is off
> sd 12:0:0:0: [sdc] Mode Sense: 00 14 00 00
> sd 12:0:0:0: [sdc] Assuming drive cache: write through
> sd 12:0:0:0: [sdc] 117210240 512-byte hardware sectors (60012 MB)
> sd 12:0:0:0: [sdc] Write Protect is off
> sd 12:0:0:0: [sdc] Mode Sense: 00 14 00 00
> sd 12:0:0:0: [sdc] Assuming drive cache: write through
> sdc:<6>usb 2-1: USB disconnect, address 2
> sd 12:0:0:0: [sdc] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
> end_request: I/O error, dev sdc, sector 0
> Buffer I/O error on device sdc, logical block 0
> sd 12:0:0:0: [sdc] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
> end_request: I/O error, dev sdc, sector 0
> Buffer I/O error on device sdc, logical block 0
> unable to read partition table
> sd 12:0:0:0: [sdc] Attached SCSI disk
> sd 12:0:0:0: Attached scsi generic sg3 type 0
> BUG: unable to handle kernel NULL pointer dereference at 0000000000000004
> IP: [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
> PGD 1260ff067 PUD 119076067 PMD 0
> Oops: 0000 [1] SMP
> CPU 3
> Modules linked in: usb_storage parport_pc lp parport usblp nfsd lockd auth_rpcgss sunrpc exportfs iptable_filter ip_tables ip6table_filter ip6_tables x_tables ipv6 cpufreq_conservative cpufreq_ondemand cpufreq_userspace cpufreq_powersave powernow_k8 freq_table snd_pcm_oss snd_mixer_oss snd_seq snd_seq_device reiserfs dm_mod ohci1394 sr_mod cdrom floppy ieee1394 serio_raw rtc_cmos sky2 wmi snd_hda_intel rtc_core sg rtc_lib joydev snd_pcm snd_timer snd_page_alloc snd_hwdep snd evdev button soundcore raid456 async_xor async_memcpy async_tx xor raid0 usbhid ff_memless ehci_hcd ohci_hcd sd_mod edd raid1 ext3 jbd fan pata_marvell pata_atiixp thermal processor
> Pid: 9319, comm: usb-stor-scan Not tainted 2.6.26-rc7 #196
> RIP: 0010:[<ffffffffa038e6f1>] [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
> RSP: 0018:ffff8100a20cdb60 EFLAGS: 00010202
> RAX: 0000000000000000 RBX: ffff810087d828d0 RCX: 0000000000000003
> RDX: ffff8101275f08e0 RSI: ffff810086cc49d0 RDI: ffff810124144b90
> RBP: ffff8100a20cdb70 R08: 0000000000000001 R09: 0000000000000000
> R10: ffffffff807fe7e0 R11: 0000000000000000 R12: ffff810087499000
> R13: ffff810124953678 R14: ffff810087d82000 R15: 0000000000000000
> FS: 00007f22f6561700(0000) GS:ffff810127c997c0(0000) knlGS:00000000eeb1db90
> CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
> CR2: 0000000000000004 CR3: 0000000122089000 CR4: 00000000000006e0
> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> Process usb-stor-scan (pid: 9319, threadinfo ffff8100a20cc000, task ffff810086cc4300)
> Stack: ffff810087499000 ffff810124953650 ffff8100a20cdbb0 ffffffff803ea940
> ffff8100a20cdbb0 ffff810087d82000 0000000000000000 0000000000000000
> ffff810124953678 0000000000000000 ffff8100a20cdcf0 ffffffff803eac9a
> Call Trace:
> [<ffffffff803ea940>] scsi_alloc_sdev+0x1e0/0x250
> [<ffffffff803eac9a>] scsi_probe_and_add_lun+0x12a/0xc20
> [<ffffffff803ebd4f>] __scsi_scan_target+0x3bf/0x6c0
> [<ffffffff8025db46>] ? mark_held_locks+0x56/0xa0
> [<ffffffff804ebbe9>] ? mutex_lock_nested+0x1b9/0x290
> [<ffffffff8025dcdf>] ? trace_hardirqs_on+0xbf/0x150
> [<ffffffff803ec0da>] scsi_scan_channel+0x8a/0xa0
> [<ffffffff803ec1e8>] scsi_scan_host_selected+0xf8/0x160
> [<ffffffff803ec2ce>] do_scsi_scan_host+0x7e/0x80
> [<ffffffff803ec850>] scsi_scan_host+0x190/0x1d0
> [<ffffffffa0390f3d>] :usb_storage:usb_stor_scan_thread+0x6d/0x1c0
> [<ffffffff8024f790>] ? autoremove_wake_function+0x0/0x40
> [<ffffffffa0390ed0>] ? :usb_storage:usb_stor_scan_thread+0x0/0x1c0
> [<ffffffff8024f33d>] kthread+0x4d/0x80
> [<ffffffff8020c608>] child_rip+0xa/0x12
> [<ffffffff8020bd1f>] ? restore_args+0x0/0x30
> [<ffffffff8024f2f0>] ? kthread+0x0/0x80
> [<ffffffff8020c5fe>] ? child_rip+0x0/0x12
>
>
> Code: 1f c6 87 c3 00 00 00 24 48 8b 7f 08 48 81 c3 d0 08 00 00 8b 83 9c 00 00 00 48 8b 53 78 c1 e8 0f 83 e0 0f 48 8b 84 c2 e8 03 00 00 <0f> b7 70 04 ff ce e8 44 d9 fb df 80 bb c4 00 00 00 04 75 12 49
> RIP [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
> RSP <ffff8100a20cdb60>
> CR2: 0000000000000004
> ---[ end trace 2077f860f94c5bf3 ]---
> sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> end_request: I/O error, dev sdc, sector 0
> Buffer I/O error on device sdc, logical block 0
> Buffer I/O error on device sdc, logical block 1
> Buffer I/O error on device sdc, logical block 2
> Buffer I/O error on device sdc, logical block 3
> sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> end_request: I/O error, dev sdc, sector 0
> Buffer I/O error on device sdc, logical block 0
> sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> end_request: I/O error, dev sdc, sector 117210112
> Buffer I/O error on device sdc, logical block 14651264
> sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> end_request: I/O error, dev sdc, sector 117210112
> Buffer I/O error on device sdc, logical block 14651264
> sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> end_request: I/O error, dev sdc, sector 117210112
> Buffer I/O error on device sdc, logical block 14651264
> sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> end_request: I/O error, dev sdc, sector 0
> sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> end_request: I/O error, dev sdc, sector 0
> sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> end_request: I/O error, dev sdc, sector 0
> sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> end_request: I/O error, dev sdc, sector 117210232
>
> It resulted in usb-storage being unusable and a system reboot.
>
> Thanks,
> Rafael
> --
> 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/
>
>



--
Rafael J. Wysocki, Ph.D.
Institute of Theoretical Physics
Faculty of Physics of Warsaw University
ul. Hoza 69, 00-681 Warsaw
[tel: +48 22 55 32 263]
[mob: +48 60 50 53 693]
----------------------------
One should not increase, beyond what is necessary,
the number of entities required to explain anything.
-- William of Ockham

2008-06-23 21:57:20

by Rafael J. Wysocki

[permalink] [raw]
Subject: Re: 2.6.27-rc7-git1: usb-storage breakage with non-functional disk

On Monday, 23 of June 2008, R. J. Wysocki wrote:
> [sorry for the broken USB list address in the original post.]

[and now my univeristy address instead of the usual one ...]

> On Monday, 23 of June 2008, Rafael J. Wysocki wrote:
> > Hi,
> >
> > This has just happened to me with -rc7-git1 while trying to use a not
> > sufficiently powered external disk (we should survive that IMO):
> >
> > usb 6-3: new high speed USB device using ehci_hcd and address 9
> > usb 6-3: device descriptor read/64, error -110
> > usb 6-3: device descriptor read/64, error -110
> > usb 6-3: new high speed USB device using ehci_hcd and address 10
> > usb 6-3: device descriptor read/64, error -110
> > usb 6-3: device descriptor read/64, error -110
> > usb 6-3: new high speed USB device using ehci_hcd and address 11
> > usb 6-3: device not accepting address 11, error -110
> > usb 6-3: new high speed USB device using ehci_hcd and address 12
> > usb 6-3: device not accepting address 12, error -110
> > hub 6-0:1.0: unable to enumerate USB device on port 3
> > usb 2-1: new full speed USB device using ohci_hcd and address 2
> > usb 2-1: not running at top speed; connect to a high speed hub
> > usb 2-1: configuration #1 chosen from 1 choice
> > usb 2-1: New USB device found, idVendor=04cf, idProduct=8818
> > usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
> > usb 2-1: Product: USB Mass Storage Device
> > usb 2-1: Manufacturer: Myson Century, Inc.
> > usb 2-1: SerialNumber: 100
> > Initializing USB Mass Storage driver...
> > scsi12 : SCSI emulation for USB Mass Storage devices
> > usb-storage: device found at 2
> > usb-storage: waiting for device to settle before scanning
> > usbcore: registered new interface driver usb-storage
> > USB Mass Storage support registered.
> > scsi 12:0:0:0: Direct-Access IC25N060 ATMR04-0 MO3O PQ: 0 ANSI: 0 CCS
> > sd 12:0:0:0: [sdc] 117210240 512-byte hardware sectors (60012 MB)
> > sd 12:0:0:0: [sdc] Write Protect is off
> > sd 12:0:0:0: [sdc] Mode Sense: 00 14 00 00
> > sd 12:0:0:0: [sdc] Assuming drive cache: write through
> > sd 12:0:0:0: [sdc] 117210240 512-byte hardware sectors (60012 MB)
> > sd 12:0:0:0: [sdc] Write Protect is off
> > sd 12:0:0:0: [sdc] Mode Sense: 00 14 00 00
> > sd 12:0:0:0: [sdc] Assuming drive cache: write through
> > sdc:<6>usb 2-1: USB disconnect, address 2
> > sd 12:0:0:0: [sdc] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
> > end_request: I/O error, dev sdc, sector 0
> > Buffer I/O error on device sdc, logical block 0
> > sd 12:0:0:0: [sdc] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
> > end_request: I/O error, dev sdc, sector 0
> > Buffer I/O error on device sdc, logical block 0
> > unable to read partition table
> > sd 12:0:0:0: [sdc] Attached SCSI disk
> > sd 12:0:0:0: Attached scsi generic sg3 type 0
> > BUG: unable to handle kernel NULL pointer dereference at 0000000000000004
> > IP: [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
> > PGD 1260ff067 PUD 119076067 PMD 0
> > Oops: 0000 [1] SMP
> > CPU 3
> > Modules linked in: usb_storage parport_pc lp parport usblp nfsd lockd auth_rpcgss sunrpc exportfs iptable_filter ip_tables ip6table_filter ip6_tables x_tables ipv6 cpufreq_conservative cpufreq_ondemand cpufreq_userspace cpufreq_powersave powernow_k8 freq_table snd_pcm_oss snd_mixer_oss snd_seq snd_seq_device reiserfs dm_mod ohci1394 sr_mod cdrom floppy ieee1394 serio_raw rtc_cmos sky2 wmi snd_hda_intel rtc_core sg rtc_lib joydev snd_pcm snd_timer snd_page_alloc snd_hwdep snd evdev button soundcore raid456 async_xor async_memcpy async_tx xor raid0 usbhid ff_memless ehci_hcd ohci_hcd sd_mod edd raid1 ext3 jbd fan pata_marvell pata_atiixp thermal processor
> > Pid: 9319, comm: usb-stor-scan Not tainted 2.6.26-rc7 #196
> > RIP: 0010:[<ffffffffa038e6f1>] [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
> > RSP: 0018:ffff8100a20cdb60 EFLAGS: 00010202
> > RAX: 0000000000000000 RBX: ffff810087d828d0 RCX: 0000000000000003
> > RDX: ffff8101275f08e0 RSI: ffff810086cc49d0 RDI: ffff810124144b90
> > RBP: ffff8100a20cdb70 R08: 0000000000000001 R09: 0000000000000000
> > R10: ffffffff807fe7e0 R11: 0000000000000000 R12: ffff810087499000
> > R13: ffff810124953678 R14: ffff810087d82000 R15: 0000000000000000
> > FS: 00007f22f6561700(0000) GS:ffff810127c997c0(0000) knlGS:00000000eeb1db90
> > CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
> > CR2: 0000000000000004 CR3: 0000000122089000 CR4: 00000000000006e0
> > DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> > Process usb-stor-scan (pid: 9319, threadinfo ffff8100a20cc000, task ffff810086cc4300)
> > Stack: ffff810087499000 ffff810124953650 ffff8100a20cdbb0 ffffffff803ea940
> > ffff8100a20cdbb0 ffff810087d82000 0000000000000000 0000000000000000
> > ffff810124953678 0000000000000000 ffff8100a20cdcf0 ffffffff803eac9a
> > Call Trace:
> > [<ffffffff803ea940>] scsi_alloc_sdev+0x1e0/0x250
> > [<ffffffff803eac9a>] scsi_probe_and_add_lun+0x12a/0xc20
> > [<ffffffff803ebd4f>] __scsi_scan_target+0x3bf/0x6c0
> > [<ffffffff8025db46>] ? mark_held_locks+0x56/0xa0
> > [<ffffffff804ebbe9>] ? mutex_lock_nested+0x1b9/0x290
> > [<ffffffff8025dcdf>] ? trace_hardirqs_on+0xbf/0x150
> > [<ffffffff803ec0da>] scsi_scan_channel+0x8a/0xa0
> > [<ffffffff803ec1e8>] scsi_scan_host_selected+0xf8/0x160
> > [<ffffffff803ec2ce>] do_scsi_scan_host+0x7e/0x80
> > [<ffffffff803ec850>] scsi_scan_host+0x190/0x1d0
> > [<ffffffffa0390f3d>] :usb_storage:usb_stor_scan_thread+0x6d/0x1c0
> > [<ffffffff8024f790>] ? autoremove_wake_function+0x0/0x40
> > [<ffffffffa0390ed0>] ? :usb_storage:usb_stor_scan_thread+0x0/0x1c0
> > [<ffffffff8024f33d>] kthread+0x4d/0x80
> > [<ffffffff8020c608>] child_rip+0xa/0x12
> > [<ffffffff8020bd1f>] ? restore_args+0x0/0x30
> > [<ffffffff8024f2f0>] ? kthread+0x0/0x80
> > [<ffffffff8020c5fe>] ? child_rip+0x0/0x12
> >
> >
> > Code: 1f c6 87 c3 00 00 00 24 48 8b 7f 08 48 81 c3 d0 08 00 00 8b 83 9c 00 00 00 48 8b 53 78 c1 e8 0f 83 e0 0f 48 8b 84 c2 e8 03 00 00 <0f> b7 70 04 ff ce e8 44 d9 fb df 80 bb c4 00 00 00 04 75 12 49
> > RIP [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
> > RSP <ffff8100a20cdb60>
> > CR2: 0000000000000004
> > ---[ end trace 2077f860f94c5bf3 ]---
> > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > end_request: I/O error, dev sdc, sector 0
> > Buffer I/O error on device sdc, logical block 0
> > Buffer I/O error on device sdc, logical block 1
> > Buffer I/O error on device sdc, logical block 2
> > Buffer I/O error on device sdc, logical block 3
> > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > end_request: I/O error, dev sdc, sector 0
> > Buffer I/O error on device sdc, logical block 0
> > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > end_request: I/O error, dev sdc, sector 117210112
> > Buffer I/O error on device sdc, logical block 14651264
> > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > end_request: I/O error, dev sdc, sector 117210112
> > Buffer I/O error on device sdc, logical block 14651264
> > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > end_request: I/O error, dev sdc, sector 117210112
> > Buffer I/O error on device sdc, logical block 14651264
> > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > end_request: I/O error, dev sdc, sector 0
> > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > end_request: I/O error, dev sdc, sector 0
> > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > end_request: I/O error, dev sdc, sector 0
> > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > end_request: I/O error, dev sdc, sector 117210232
> >
> > It resulted in usb-storage being unusable and a system reboot.
> >
> > Thanks,
> > Rafael

2008-06-23 23:42:53

by Matthew Dharm

[permalink] [raw]
Subject: Re: 2.6.27-rc7-git1: usb-storage breakage with non-functional disk

Huh. Does SCSI core not do a get_device() before actually scanning? It
looks to me like the disconnect path did it's scsi_host_put and the host
(and struct us_data) got freed immediately.

Matt

On Mon, Jun 23, 2008 at 11:58:32PM +0200, Rafael J. Wysocki wrote:
> On Monday, 23 of June 2008, R. J. Wysocki wrote:
> > [sorry for the broken USB list address in the original post.]
>
> [and now my univeristy address instead of the usual one ...]
>
> > On Monday, 23 of June 2008, Rafael J. Wysocki wrote:
> > > Hi,
> > >
> > > This has just happened to me with -rc7-git1 while trying to use a not
> > > sufficiently powered external disk (we should survive that IMO):
> > >
> > > usb 6-3: new high speed USB device using ehci_hcd and address 9
> > > usb 6-3: device descriptor read/64, error -110
> > > usb 6-3: device descriptor read/64, error -110
> > > usb 6-3: new high speed USB device using ehci_hcd and address 10
> > > usb 6-3: device descriptor read/64, error -110
> > > usb 6-3: device descriptor read/64, error -110
> > > usb 6-3: new high speed USB device using ehci_hcd and address 11
> > > usb 6-3: device not accepting address 11, error -110
> > > usb 6-3: new high speed USB device using ehci_hcd and address 12
> > > usb 6-3: device not accepting address 12, error -110
> > > hub 6-0:1.0: unable to enumerate USB device on port 3
> > > usb 2-1: new full speed USB device using ohci_hcd and address 2
> > > usb 2-1: not running at top speed; connect to a high speed hub
> > > usb 2-1: configuration #1 chosen from 1 choice
> > > usb 2-1: New USB device found, idVendor=04cf, idProduct=8818
> > > usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
> > > usb 2-1: Product: USB Mass Storage Device
> > > usb 2-1: Manufacturer: Myson Century, Inc.
> > > usb 2-1: SerialNumber: 100
> > > Initializing USB Mass Storage driver...
> > > scsi12 : SCSI emulation for USB Mass Storage devices
> > > usb-storage: device found at 2
> > > usb-storage: waiting for device to settle before scanning
> > > usbcore: registered new interface driver usb-storage
> > > USB Mass Storage support registered.
> > > scsi 12:0:0:0: Direct-Access IC25N060 ATMR04-0 MO3O PQ: 0 ANSI: 0 CCS
> > > sd 12:0:0:0: [sdc] 117210240 512-byte hardware sectors (60012 MB)
> > > sd 12:0:0:0: [sdc] Write Protect is off
> > > sd 12:0:0:0: [sdc] Mode Sense: 00 14 00 00
> > > sd 12:0:0:0: [sdc] Assuming drive cache: write through
> > > sd 12:0:0:0: [sdc] 117210240 512-byte hardware sectors (60012 MB)
> > > sd 12:0:0:0: [sdc] Write Protect is off
> > > sd 12:0:0:0: [sdc] Mode Sense: 00 14 00 00
> > > sd 12:0:0:0: [sdc] Assuming drive cache: write through
> > > sdc:<6>usb 2-1: USB disconnect, address 2
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 0
> > > Buffer I/O error on device sdc, logical block 0
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 0
> > > Buffer I/O error on device sdc, logical block 0
> > > unable to read partition table
> > > sd 12:0:0:0: [sdc] Attached SCSI disk
> > > sd 12:0:0:0: Attached scsi generic sg3 type 0
> > > BUG: unable to handle kernel NULL pointer dereference at 0000000000000004
> > > IP: [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
> > > PGD 1260ff067 PUD 119076067 PMD 0
> > > Oops: 0000 [1] SMP
> > > CPU 3
> > > Modules linked in: usb_storage parport_pc lp parport usblp nfsd lockd auth_rpcgss sunrpc exportfs iptable_filter ip_tables ip6table_filter ip6_tables x_tables ipv6 cpufreq_conservative cpufreq_ondemand cpufreq_userspace cpufreq_powersave powernow_k8 freq_table snd_pcm_oss snd_mixer_oss snd_seq snd_seq_device reiserfs dm_mod ohci1394 sr_mod cdrom floppy ieee1394 serio_raw rtc_cmos sky2 wmi snd_hda_intel rtc_core sg rtc_lib joydev snd_pcm snd_timer snd_page_alloc snd_hwdep snd evdev button soundcore raid456 async_xor async_memcpy async_tx xor raid0 usbhid ff_memless ehci_hcd ohci_hcd sd_mod edd raid1 ext3 jbd fan pata_marvell pata_atiixp thermal processor
> > > Pid: 9319, comm: usb-stor-scan Not tainted 2.6.26-rc7 #196
> > > RIP: 0010:[<ffffffffa038e6f1>] [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
> > > RSP: 0018:ffff8100a20cdb60 EFLAGS: 00010202
> > > RAX: 0000000000000000 RBX: ffff810087d828d0 RCX: 0000000000000003
> > > RDX: ffff8101275f08e0 RSI: ffff810086cc49d0 RDI: ffff810124144b90
> > > RBP: ffff8100a20cdb70 R08: 0000000000000001 R09: 0000000000000000
> > > R10: ffffffff807fe7e0 R11: 0000000000000000 R12: ffff810087499000
> > > R13: ffff810124953678 R14: ffff810087d82000 R15: 0000000000000000
> > > FS: 00007f22f6561700(0000) GS:ffff810127c997c0(0000) knlGS:00000000eeb1db90
> > > CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
> > > CR2: 0000000000000004 CR3: 0000000122089000 CR4: 00000000000006e0
> > > DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > > DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> > > Process usb-stor-scan (pid: 9319, threadinfo ffff8100a20cc000, task ffff810086cc4300)
> > > Stack: ffff810087499000 ffff810124953650 ffff8100a20cdbb0 ffffffff803ea940
> > > ffff8100a20cdbb0 ffff810087d82000 0000000000000000 0000000000000000
> > > ffff810124953678 0000000000000000 ffff8100a20cdcf0 ffffffff803eac9a
> > > Call Trace:
> > > [<ffffffff803ea940>] scsi_alloc_sdev+0x1e0/0x250
> > > [<ffffffff803eac9a>] scsi_probe_and_add_lun+0x12a/0xc20
> > > [<ffffffff803ebd4f>] __scsi_scan_target+0x3bf/0x6c0
> > > [<ffffffff8025db46>] ? mark_held_locks+0x56/0xa0
> > > [<ffffffff804ebbe9>] ? mutex_lock_nested+0x1b9/0x290
> > > [<ffffffff8025dcdf>] ? trace_hardirqs_on+0xbf/0x150
> > > [<ffffffff803ec0da>] scsi_scan_channel+0x8a/0xa0
> > > [<ffffffff803ec1e8>] scsi_scan_host_selected+0xf8/0x160
> > > [<ffffffff803ec2ce>] do_scsi_scan_host+0x7e/0x80
> > > [<ffffffff803ec850>] scsi_scan_host+0x190/0x1d0
> > > [<ffffffffa0390f3d>] :usb_storage:usb_stor_scan_thread+0x6d/0x1c0
> > > [<ffffffff8024f790>] ? autoremove_wake_function+0x0/0x40
> > > [<ffffffffa0390ed0>] ? :usb_storage:usb_stor_scan_thread+0x0/0x1c0
> > > [<ffffffff8024f33d>] kthread+0x4d/0x80
> > > [<ffffffff8020c608>] child_rip+0xa/0x12
> > > [<ffffffff8020bd1f>] ? restore_args+0x0/0x30
> > > [<ffffffff8024f2f0>] ? kthread+0x0/0x80
> > > [<ffffffff8020c5fe>] ? child_rip+0x0/0x12
> > >
> > >
> > > Code: 1f c6 87 c3 00 00 00 24 48 8b 7f 08 48 81 c3 d0 08 00 00 8b 83 9c 00 00 00 48 8b 53 78 c1 e8 0f 83 e0 0f 48 8b 84 c2 e8 03 00 00 <0f> b7 70 04 ff ce e8 44 d9 fb df 80 bb c4 00 00 00 04 75 12 49
> > > RIP [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
> > > RSP <ffff8100a20cdb60>
> > > CR2: 0000000000000004
> > > ---[ end trace 2077f860f94c5bf3 ]---
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 0
> > > Buffer I/O error on device sdc, logical block 0
> > > Buffer I/O error on device sdc, logical block 1
> > > Buffer I/O error on device sdc, logical block 2
> > > Buffer I/O error on device sdc, logical block 3
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 0
> > > Buffer I/O error on device sdc, logical block 0
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 117210112
> > > Buffer I/O error on device sdc, logical block 14651264
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 117210112
> > > Buffer I/O error on device sdc, logical block 14651264
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 117210112
> > > Buffer I/O error on device sdc, logical block 14651264
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 0
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 0
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 0
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 117210232
> > >
> > > It resulted in usb-storage being unusable and a system reboot.
> > >
> > > Thanks,
> > > Rafael
> --
> To unsubscribe from this list: send the line "unsubscribe linux-usb" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html

--
Matthew Dharm Home: [email protected]
Maintainer, Linux USB Mass Storage Driver

S: Another stupid question?
G: There's no such thing as a stupid question, only stupid people.
-- Stef and Greg
User Friendly, 7/15/1998


Attachments:
(No filename) (8.89 kB)
(No filename) (189.00 B)
Download all attachments

2008-06-24 14:41:22

by Alan Stern

[permalink] [raw]
Subject: Re: 2.6.27-rc7-git1: usb-storage breakage with non-functional disk

On Mon, 23 Jun 2008, Rafael J. Wysocki wrote:

> On Monday, 23 of June 2008, R. J. Wysocki wrote:
> > [sorry for the broken USB list address in the original post.]
>
> [and now my univeristy address instead of the usual one ...]
>
> > On Monday, 23 of June 2008, Rafael J. Wysocki wrote:
> > > Hi,
> > >
> > > This has just happened to me with -rc7-git1 while trying to use a not
> > > sufficiently powered external disk (we should survive that IMO):
> > >
...
> > > scsi 12:0:0:0: Direct-Access IC25N060 ATMR04-0 MO3O PQ: 0 ANSI: 0 CCS
> > > sd 12:0:0:0: [sdc] 117210240 512-byte hardware sectors (60012 MB)
> > > sd 12:0:0:0: [sdc] Write Protect is off
> > > sd 12:0:0:0: [sdc] Mode Sense: 00 14 00 00
> > > sd 12:0:0:0: [sdc] Assuming drive cache: write through
> > > sd 12:0:0:0: [sdc] 117210240 512-byte hardware sectors (60012 MB)
> > > sd 12:0:0:0: [sdc] Write Protect is off
> > > sd 12:0:0:0: [sdc] Mode Sense: 00 14 00 00
> > > sd 12:0:0:0: [sdc] Assuming drive cache: write through
> > > sdc:<6>usb 2-1: USB disconnect, address 2
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 0
> > > Buffer I/O error on device sdc, logical block 0
> > > sd 12:0:0:0: [sdc] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
> > > end_request: I/O error, dev sdc, sector 0
> > > Buffer I/O error on device sdc, logical block 0
> > > unable to read partition table
> > > sd 12:0:0:0: [sdc] Attached SCSI disk
> > > sd 12:0:0:0: Attached scsi generic sg3 type 0
> > > BUG: unable to handle kernel NULL pointer dereference at 0000000000000004
> > > IP: [<ffffffffa038e6f1>] :usb_storage:slave_alloc+0x41/0x80
...
> > > It resulted in usb-storage being unusable and a system reboot.

This is a nasty problem. What happened is that the endpoint pointer
arrays ep_in and ep_out in struct usb_device get cleared before the
device drivers' disconnect methods are called. Since usb-storage
dereferences one of the pointers in those arrays, you ended up with an
invalid memory access.

In principle the arrays should not be cleared until after the drivers
have been unbound. However for now it is simpler to remove the
dereference in usb-storage. Especially since the reason for adding it
in the first place turned out to be wrong.

Is this oops fairly reproducible? If it is, then you should be able to
test whether this patch fixes it.

Alan Stern



Index: usb-2.6/drivers/usb/storage/scsiglue.c
===================================================================
--- usb-2.6.orig/drivers/usb/storage/scsiglue.c
+++ usb-2.6/drivers/usb/storage/scsiglue.c
@@ -71,7 +71,6 @@ static const char* host_info(struct Scsi
static int slave_alloc (struct scsi_device *sdev)
{
struct us_data *us = host_to_us(sdev->host);
- struct usb_host_endpoint *bulk_in_ep;

/*
* Set the INQUIRY transfer length to 36. We don't use any of
@@ -80,16 +79,22 @@ static int slave_alloc (struct scsi_devi
*/
sdev->inquiry_len = 36;

- /* Scatter-gather buffers (all but the last) must have a length
- * divisible by the bulk maxpacket size. Otherwise a data packet
- * would end up being short, causing a premature end to the data
- * transfer. We'll use the maxpacket value of the bulk-IN pipe
- * to set the SCSI device queue's DMA alignment mask.
+ /* USB has unusual DMA-alignment requirements: Although the
+ * starting address of each scatter-gather element doesn't matter,
+ * the length of each element except the last must be divisible
+ * by the Bulk maxpacket value. There's currently no way to
+ * express this by block-layer constraints, so we'll cop out
+ * and simply require addresses to be aligned at 512-byte
+ * boundaries. This is okay since most block I/O involves
+ * hardware sectors that are multiples of 512 bytes in length,
+ * and since host controllers up through USB 2.0 have maxpacket
+ * values no larger than 512.
+ *
+ * But it doesn't suffice for Wireless USB, where Bulk maxpacket
+ * values can be as large as 2048. To make that work properly
+ * will require changes to the block layer.
*/
- bulk_in_ep = us->pusb_dev->ep_in[usb_pipeendpoint(us->recv_bulk_pipe)];
- blk_queue_update_dma_alignment(sdev->request_queue,
- le16_to_cpu(bulk_in_ep->desc.wMaxPacketSize) - 1);
- /* wMaxPacketSize must be a power of 2 */
+ blk_queue_update_dma_alignment(sdev->request_queue, (512 - 1));

/*
* The UFI spec treates the Peripheral Qualifier bits in an

2008-07-08 13:23:05

by Indan Zupancic

[permalink] [raw]
Subject: Re: 2.6.27-rc7-git1: usb-storage breakage with non-functional disk

Hello,

On Tue, June 24, 2008 16:41, Alan Stern wrote:
> This is a nasty problem. What happened is that the endpoint pointer
> arrays ep_in and ep_out in struct usb_device get cleared before the
> device drivers' disconnect methods are called. Since usb-storage
> dereferences one of the pointers in those arrays, you ended up with an
> invalid memory access.
>
> In principle the arrays should not be cleared until after the drivers
> have been unbound. However for now it is simpler to remove the
> dereference in usb-storage. Especially since the reason for adding it
> in the first place turned out to be wrong.
>
> Is this oops fairly reproducible? If it is, then you should be able to
> test whether this patch fixes it.
>
> Alan Stern
>
>
>
> Index: usb-2.6/drivers/usb/storage/scsiglue.c
> ===================================================================
> --- usb-2.6.orig/drivers/usb/storage/scsiglue.c
> +++ usb-2.6/drivers/usb/storage/scsiglue.c
> @@ -71,7 +71,6 @@ static const char* host_info(struct Scsi
> static int slave_alloc (struct scsi_device *sdev)
> {
> struct us_data *us = host_to_us(sdev->host);
> - struct usb_host_endpoint *bulk_in_ep;
>
> /*
> * Set the INQUIRY transfer length to 36. We don't use any of
> @@ -80,16 +79,22 @@ static int slave_alloc (struct scsi_devi
> */
> sdev->inquiry_len = 36;
>
> - /* Scatter-gather buffers (all but the last) must have a length
> - * divisible by the bulk maxpacket size. Otherwise a data packet
> - * would end up being short, causing a premature end to the data
> - * transfer. We'll use the maxpacket value of the bulk-IN pipe
> - * to set the SCSI device queue's DMA alignment mask.
> + /* USB has unusual DMA-alignment requirements: Although the
> + * starting address of each scatter-gather element doesn't matter,
> + * the length of each element except the last must be divisible
> + * by the Bulk maxpacket value. There's currently no way to
> + * express this by block-layer constraints, so we'll cop out
> + * and simply require addresses to be aligned at 512-byte
> + * boundaries. This is okay since most block I/O involves
> + * hardware sectors that are multiples of 512 bytes in length,
> + * and since host controllers up through USB 2.0 have maxpacket
> + * values no larger than 512.
> + *
> + * But it doesn't suffice for Wireless USB, where Bulk maxpacket
> + * values can be as large as 2048. To make that work properly
> + * will require changes to the block layer.
> */
> - bulk_in_ep = us->pusb_dev->ep_in[usb_pipeendpoint(us->recv_bulk_pipe)];
> - blk_queue_update_dma_alignment(sdev->request_queue,
> - le16_to_cpu(bulk_in_ep->desc.wMaxPacketSize) - 1);
> - /* wMaxPacketSize must be a power of 2 */
> + blk_queue_update_dma_alignment(sdev->request_queue, (512 - 1));
>
> /*
> * The UFI spec treates the Peripheral Qualifier bits in an
>

I hit almost the same BUG, so tried out this patch, and can confirm that
it fixes the BUG. Other devices still work too. As it's 2.6.26-rc9 it might
be time to send this patch upstream, before it's too late.

Any idea why my cardreader doesn't work in the first place though?

The error is basically:

usb 1-5: new high speed USB device using ehci_hcd and address 22
usb 1-5: device not accepting address 22, error -71
usb 1-5: new high speed USB device using ehci_hcd and address 23
usb 1-5: configuration #1 chosen from 1 choice
scsi17 : SCSI emulation for USB Mass Storage devices
usb-storage: device found at 23
usb-storage: waiting for device to settle before scanning
usb 1-5: reset high speed USB device using ehci_hcd and address 23
usb 1-5: reset high speed USB device using ehci_hcd and address 23
usb 1-5: reset high speed USB device using ehci_hcd and address 23
scsi 17:0:0:0: Direct-Access Generic USB SD Reader 1.00 PQ: 0 ANSI: 0
usb 1-5: reset high speed USB device using ehci_hcd and address 23
usb 1-5: device not accepting address 23, error -71
usb 1-5: reset high speed USB device using ehci_hcd and address 23
usb 1-5: reset high speed USB device using ehci_hcd and address 23
usb 1-5: reset high speed USB device using ehci_hcd and address 23
usb 1-5: reset high speed USB device using ehci_hcd and address 23
usb 1-5: can't restore configuration #1 (error=-71)
usb 1-5: USB disconnect, address 23
sd 17:0:0:0: [sdb] READ CAPACITY failed
sd 17:0:0:0: [sdb] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
sd 17:0:0:0: [sdb] Sense not available.
sd 17:0:0:0: [sdb] Write Protect is off
sd 17:0:0:0: [sdb] Mode Sense: 00 00 00 00
sd 17:0:0:0: [sdb] Assuming drive cache: write through
sd 17:0:0:0: [sdb] Attached SCSI removable disk
sd 17:0:0:0: Attached scsi generic sg2 type 0
usb-storage: device scan complete
usb 1-5: new high speed USB device using ehci_hcd and address 24
usb 1-5: string descriptor 0 read error: -71
usb 1-5: configuration #1 chosen from 1 choice
usb 1-5: can't set config #1, error -71

It's a new Trust Mini Cardreader, model CR-1350p.

$ lsusb -s 24 -v

Bus 001 Device 024: ID 058f:6332 Alcor Micro Corp.
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 2.00
bDeviceClass 0 (Defined at Interface level)
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 64
idVendor 0x058f Alcor Micro Corp.
idProduct 0x6332
bcdDevice 1.02
iManufacturer 1
iProduct 2
iSerial 3
bNumConfigurations 1
Configuration Descriptor:
bLength 9
bDescriptorType 2
wTotalLength 32
bNumInterfaces 1
bConfigurationValue 1
iConfiguration 0
bmAttributes 0x80
(Bus Powered)
MaxPower 100mA
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 0
bNumEndpoints 2
bInterfaceClass 8 Mass Storage
bInterfaceSubClass 6 SCSI
bInterfaceProtocol 80 Bulk (Zip)
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x01 EP 1 OUT
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0200 1x 512 bytes
bInterval 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x82 EP 2 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0200 1x 512 bytes
bInterval 0

It doesn't matter in which port I put the thing (front, back),
and I've tried older kernels too (2.6.12), but I get the same
error there. This is with an Intel 945G chipset.
(I've no Windows to test if it works there.)

Is it just a crappy device which I should bring back, or is
there more going on?

Greetings,

Indan

2008-07-08 13:53:54

by Indan Zupancic

[permalink] [raw]
Subject: Re: 2.6.27-rc7-git1: usb-storage breakage with non-functional disk

On Tue, July 8, 2008 15:00, Indan Zupancic wrote:
> Any idea why my cardreader doesn't work in the first place though?

In case it's useful, an usbmon dump can be found at http://pastebin.org/49630
This is the log of plugging in the thing and unplugging it again after it failed.
Corresponding dmesg output with USB and usb-storage debugging enabled at
http://pastebin.org/49631. This is on 2.6.26-rc9 with Alan's patch applied.

Regards,

Indan

2008-07-08 14:01:52

by Alan Stern

[permalink] [raw]
Subject: Re: 2.6.27-rc7-git1: usb-storage breakage with non-functional disk

On Tue, 8 Jul 2008, Indan Zupancic wrote:

> Any idea why my cardreader doesn't work in the first place though?
>
> The error is basically:
>
> usb 1-5: new high speed USB device using ehci_hcd and address 22
> usb 1-5: device not accepting address 22, error -71
> usb 1-5: new high speed USB device using ehci_hcd and address 23
> usb 1-5: configuration #1 chosen from 1 choice
> scsi17 : SCSI emulation for USB Mass Storage devices
> usb-storage: device found at 23
> usb-storage: waiting for device to settle before scanning
> usb 1-5: reset high speed USB device using ehci_hcd and address 23
> usb 1-5: reset high speed USB device using ehci_hcd and address 23
> usb 1-5: reset high speed USB device using ehci_hcd and address 23
> scsi 17:0:0:0: Direct-Access Generic USB SD Reader 1.00 PQ: 0 ANSI: 0
> usb 1-5: reset high speed USB device using ehci_hcd and address 23
> usb 1-5: device not accepting address 23, error -71
> usb 1-5: reset high speed USB device using ehci_hcd and address 23
> usb 1-5: reset high speed USB device using ehci_hcd and address 23
> usb 1-5: reset high speed USB device using ehci_hcd and address 23
> usb 1-5: reset high speed USB device using ehci_hcd and address 23
> usb 1-5: can't restore configuration #1 (error=-71)
> usb 1-5: USB disconnect, address 23
> sd 17:0:0:0: [sdb] READ CAPACITY failed
> sd 17:0:0:0: [sdb] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK,SUGGEST_OK
> sd 17:0:0:0: [sdb] Sense not available.
> sd 17:0:0:0: [sdb] Write Protect is off
> sd 17:0:0:0: [sdb] Mode Sense: 00 00 00 00
> sd 17:0:0:0: [sdb] Assuming drive cache: write through
> sd 17:0:0:0: [sdb] Attached SCSI removable disk
> sd 17:0:0:0: Attached scsi generic sg2 type 0
> usb-storage: device scan complete
> usb 1-5: new high speed USB device using ehci_hcd and address 24
> usb 1-5: string descriptor 0 read error: -71
> usb 1-5: configuration #1 chosen from 1 choice
> usb 1-5: can't set config #1, error -71
>
> It's a new Trust Mini Cardreader, model CR-1350p.

> It doesn't matter in which port I put the thing (front, back),
> and I've tried older kernels too (2.6.12), but I get the same
> error there. This is with an Intel 945G chipset.
> (I've no Windows to test if it works there.)
>
> Is it just a crappy device which I should bring back, or is
> there more going on?

It could be a bad device or it could be a bad USB cable. Have you
tried using the card reader with a different computer?

A usb-storage verbose debugging log might reveal something useful.

Alan Stern

2008-07-08 14:11:36

by Alan Stern

[permalink] [raw]
Subject: Re: 2.6.27-rc7-git1: usb-storage breakage with non-functional disk

On Tue, 8 Jul 2008, Indan Zupancic wrote:

> On Tue, July 8, 2008 15:00, Indan Zupancic wrote:
> > Any idea why my cardreader doesn't work in the first place though?
>
> In case it's useful, an usbmon dump can be found at http://pastebin.org/49630
> This is the log of plugging in the thing and unplugging it again after it failed.
> Corresponding dmesg output with USB and usb-storage debugging enabled at
> http://pastebin.org/49631. This is on 2.6.26-rc9 with Alan's patch applied.

The logs reveal only that this doesn't seem to be a software- or
firmware-related problem. And it probably isn't a problem in the cable
either, which leaves only the reader or its USB interface.

It might work better at full speed than at high speed (although you
probably don't want to use it in a degraded mode).

Alan Stern

2008-07-08 14:28:50

by Indan Zupancic

[permalink] [raw]
Subject: Re: 2.6.27-rc7-git1: usb-storage breakage with non-functional disk

On Tue, July 8, 2008 16:11, Alan Stern wrote:
> On Tue, 8 Jul 2008, Indan Zupancic wrote:
>
>> On Tue, July 8, 2008 15:00, Indan Zupancic wrote:
>> > Any idea why my cardreader doesn't work in the first place though?
>>
>> In case it's useful, an usbmon dump can be found at
>> http://pastebin.org/49630
>> This is the log of plugging in the thing and unplugging it again after it
>> failed.
>> Corresponding dmesg output with USB and usb-storage debugging enabled at
>> http://pastebin.org/49631. This is on 2.6.26-rc9 with Alan's patch applied.
>
> The logs reveal only that this doesn't seem to be a software- or
> firmware-related problem. And it probably isn't a problem in the cable
> either, which leaves only the reader or its USB interface.

It's connected directly without cable, so good call on the no cable problem.
It looks like a big usb stick with slots for memory cards.

It's not something silly like the device saying it only needs 100mA
while in reality it needs 200mA? Or are those numbers only used to
calculate how many devices may be connected?

> It might work better at full speed than at high speed (although you
> probably don't want to use it in a degraded mode).

I have ehci built-in, how can I force full speed? Hm, in the BIOS maybe.

I'll try it with my neighbours' pc later today, if I've the chance.

Thanks,

Indan

2008-07-08 14:39:18

by Alan Stern

[permalink] [raw]
Subject: Re: 2.6.27-rc7-git1: usb-storage breakage with non-functional disk

On Tue, 8 Jul 2008, Indan Zupancic wrote:

> It's not something silly like the device saying it only needs 100mA
> while in reality it needs 200mA? Or are those numbers only used to
> calculate how many devices may be connected?

If it's plugged directly into the computer then it should receive all
the power it needs. Unless there's an option to give it more power
(like a second USB connector with only the power lines attached)?

> > It might work better at full speed than at high speed (although you
> > probably don't want to use it in a degraded mode).
>
> I have ehci built-in, how can I force full speed? Hm, in the BIOS maybe.

echo 5 >/sys/class/usb_host/usb_host1/companion

Alan Stern

2008-07-08 15:13:55

by Indan Zupancic

[permalink] [raw]
Subject: Re: 2.6.27-rc7-git1: usb-storage breakage with non-functional disk

On Tue, July 8, 2008 16:11, Alan Stern wrote:
> On Tue, 8 Jul 2008, Indan Zupancic wrote:
>
>> On Tue, July 8, 2008 15:00, Indan Zupancic wrote:
>> > Any idea why my cardreader doesn't work in the first place though?
>>
>> In case it's useful, an usbmon dump can be found at
>> http://pastebin.org/49630
>> This is the log of plugging in the thing and unplugging it again after it
>> failed.
>> Corresponding dmesg output with USB and usb-storage debugging enabled at
>> http://pastebin.org/49631. This is on 2.6.26-rc9 with Alan's patch applied.
>
> The logs reveal only that this doesn't seem to be a software- or
> firmware-related problem. And it probably isn't a problem in the cable
> either, which leaves only the reader or its USB interface.
>
> It might work better at full speed than at high speed (although you
> probably don't want to use it in a degraded mode).

It works if I disable USB 2.0 support in the BIOS, does that tell us
anything new? The thing is sold as a USB 2.0 device, does this just
confirm that it's a cheap device which is just lousy quality, or can
it be considered broken?

...

I tried it with my neighbour's computer and there it didn't work either,
so it's just broken hardware it seems.

Oh well, tested one patch today, so it wasn't totally useless.

Thanks for the help,

Indan