Bug 5894 - usb-storage freezes during large file transfers
Summary: usb-storage freezes during large file transfers
Status: CLOSED CODE_FIX
Alias: None
Product: Drivers
Classification: Unclassified
Component: USB (show other bugs)
Hardware: i386 Linux
: P2 high
Assignee: Alan Stern
URL:
Keywords:
Depends on:
Blocks: USB
  Show dependency tree
 
Reported: 2006-01-14 21:26 UTC by Paul
Modified: 2007-07-15 06:56 UTC (History)
7 users (show)

See Also:
Kernel Version: 2.6.15
Subsystem:
Regression: ---
Bisected commit-id:

Attachments
usbmon output from freeze (626.19 KB, application/octet-stream)
2006-01-15 00:47 UTC, Paul 		Details
experimental patch (1.37 KB, patch)
2006-01-15 02:13 UTC, David Brownell 		Details | Diff
Reset even if there are multiple interfaces (641 bytes, patch)
2006-01-15 13:40 UTC, Alan Stern 		Details | Diff
Add an attachment (proposed patch, testcase, etc.)

Description Paul 2006-01-14 21:26:19 UTC 
Most recent kernel where this bug did not occur: dont know
Distribution: FC4
Hardware Environment: i686
Software Environment: FC4

Problem Description: 

I have a bunch of 300MB video files on a fairly new USB 2.0 Hard Disk, formatted
FAT-32 by Seagate's own software.  The HD is always plugged in.  PC is dual
boot.  In Windows XP, everything works just fine, and I can watch video from the
HDD without interruptions and copy files fine as well.

In 2.6.15, when I try to watch a video file, or copy one of the 300MB files to
another IDE disk drive, I get frequent problems.  To reproduce, I try to copy
three 300MB files from my USB-HD to my IDE-HD.  The problem will always occur
about once during one of those 3 transfers.

The transfer will stall for about 30-40 seconds, and then maybe resume (or if
being transferred via samba, samba just gives up.)  If watching in mplayer,
everything is fine until one of these freezes occur.  If in mplayer's fullscreen
mode, the keyboard & mouse stop responding, and I have to either wait about 40
seconds, or CTRL-ALT-BKSP to kill the X-server, or CTRL-ALT-F1 to swicth to
terminal.

Steps to reproduce:  mount a USB harddrive and try to copy about 1GB worth of
data from the drive.  The transfer will start and finish quickly, but there will
be a 40 second pause in the middle.

I turned on USB verbose logging, here's my messages [note, the askewedness of
the usb-storage log entries].  The freeze-up occured during a read at about Jan
14 23:53 :

Jan 14 23:45:24 titan kernel: klogd 1.4.1, log source = /proc/kmsg started.
Jan 14 23:45:24 titan kernel: CI Host Controller
Jan 14 23:45:24 titan kernel: ohci_hcd 0000:00:0d.0: new USB bus registered,
assigned bus number 2
Jan 14 23:45:24 titan kernel: ohci_hcd 0000:00:0d.0: irq 17, io mem 0xdb008000
Jan 14 23:45:24 titan kernel: usb usb2: Product: OHCI Host Controller
Jan 14 23:45:24 titan kernel: usb usb2: Manufacturer: Linux 2.6.15 ohci_hcd
Jan 14 23:45:24 titan kernel: usb usb2: SerialNumber: 0000:00:0d.0
Jan 14 23:45:24 titan kernel: hub 2-0:1.0: USB hub found
Jan 14 23:45:24 titan kernel: hub 2-0:1.0: 2 ports detected
Jan 14 23:45:24 titan kernel: ACPI: PCI Interrupt 0000:00:0d.1[C] -> GSI 19
(level, low) -> IRQ 19
Jan 14 23:45:24 titan kernel: ohci_hcd 0000:00:0d.1: OHCI Host Controller
Jan 14 23:45:24 titan kernel: ohci_hcd 0000:00:0d.1: new USB bus registered,
assigned bus number 3
Jan 14 23:45:24 titan kernel: ohci_hcd 0000:00:0d.1: irq 19, io mem 0xdb009000
Jan 14 23:45:24 titan kernel: usb usb3: Product: OHCI Host Controller
Jan 14 23:45:24 titan kernel: usb usb3: Manufacturer: Linux 2.6.15 ohci_hcd
Jan 14 23:45:24 titan kernel: usb usb3: SerialNumber: 0000:00:0d.1
Jan 14 23:45:24 titan kernel: hub 3-0:1.0: USB hub found
Jan 14 23:45:24 titan kernel: hub 3-0:1.0: 2 ports detected
Jan 14 23:45:24 titan kernel: usb 1-6: new high speed USB device using ehci_hcd
and address 2
Jan 14 23:45:24 titan kernel: ACPI: PCI Interrupt 0000:00:0d.2[D] -> GSI 16
(level, low) -> IRQ 16
Jan 14 23:45:24 titan kernel: ohci_hcd 0000:00:0d.2: OHCI Host Controller
Jan 14 23:45:24 titan kernel: ohci_hcd 0000:00:0d.2: new USB bus registered,
assigned bus number 4
Jan 14 23:45:24 titan kernel: ohci_hcd 0000:00:0d.2: irq 16, io mem 0xdb00a000
Jan 14 23:45:24 titan kernel: usb usb4: Product: OHCI Host Controller
Jan 14 23:45:24 titan kernel: usb usb4: Manufacturer: Linux 2.6.15 ohci_hcd
Jan 14 23:45:24 titan kernel: usb usb4: SerialNumber: 0000:00:0d.2
Jan 14 23:45:24 titan kernel: hub 4-0:1.0: USB hub found
Jan 14 23:45:24 titan kernel: hub 4-0:1.0: 2 ports detected
Jan 14 23:45:24 titan kernel: usb 1-6: Product: External HDD
Jan 14 23:45:24 titan kernel: usb 1-6: Manufacturer: Western Digital
Jan 14 23:45:24 titan kernel: usb 1-6: SerialNumber: 57442D5743414C3736313631333830
Jan 14 23:45:24 titan kernel: Initializing USB Mass Storage driver...
Jan 14 23:45:24 titan kernel: scsi0 : SCSI emulation for USB Mass Storage devices
Jan 14 23:45:24 titan kernel: usbcore: registered new driver usb-storage
Jan 14 23:45:24 titan kernel: USB Mass Storage support registered.

Jan 14 23:45:24 titan kernel: Freeing unused kernel memory: 144k freed
Jan 14 23:45:25 titan kernel:   Vendor: WD        Model: 2500JB External   Rev: 0602
Jan 14 23:45:25 titan kernel:   Type:   Direct-Access                      ANSI
SCSI revision: 00
Jan 14 23:45:25 titan kernel: SCSI device sda: 488397168 512-byte hdwr sectors
(250059 MB)
Jan 14 23:45:25 titan kernel: sda: assuming drive cache: write through
Jan 14 23:45:25 titan kernel: SCSI device sda: 488397168 512-byte hdwr sectors
(250059 MB)
Jan 14 23:45:25 titan kernel: sda: assuming drive cache: write through
Jan 14 23:45:25 titan kernel:  sda:<7>usb-storage: queuecommand called
Jan 14 23:45:25 titan kernel:  sda1
Jan 14 23:45:25 titan kernel: sd 0:0:0:0: Attached scsi disk sda

Jan 14 23:51:07 titan su(pam_unix)[3718]: session opened for user root by (uid=500)
Jan 14 23:52:29 titan kernel: nsfer complete
Jan 14 23:52:30 titan kernel: storage: Bulk Status S 0x53425355 T 0x1f13 R 0
Stat 0x0
Jan 14 23:52:34 titan kernel: plete
Jan 14 23:52:34 titan kernel: lete
Jan 14 23:53:02 titan kernel: <7rage: Bulk Status S 0x53425355 T 0x2b19 R 0 Stat 0x0
Jan 14 23:53:03 titan kernel: plete
Jan 14 23:53:03 titan kernel: e: Bulk Command S 0x43425355 T 0x2c7a L 65536 F
128 Trg 0 LUN 0 CL 10
Jan 14 23:53:04 titan kernel: : Bulk Status S 0x53425355 T 0x2ca3 R 0 Stat 0x0
Jan 14 23:53:04 titan kernel: plete
Jan 14 23:53:23 titan kernel: lk data transfer result 0x0
Jan 14 23:53:23 titan kernel: <7plete
Jan 14 23:53:25 titan kernel: <7ulk data transfer result 0x0
Jan 14 23:53:27 titan kernel: : Bulk Status S 0x53425355 T 0x37ba R 0 Stat 0x0
Jan 14 23:53:28 titan kernel: <7ulk data transfer result 0x0
Jan 14 23:53:29 titan kernel: <7plete
Jan 14 23:53:30 titan kernel: <: Bulk Status S 0x53425355 T 0x3a0b R 0 Stat 0x0
Jan 14 23:53:32 titan kernel: rage: Bulk Status S 0x53425355 T 0x3bbf R 0 Stat 0x0
Jan 14 23:53:32 titan kernel: <7torage: Bulk Status S 0x53425355 T 0x3c47 R 0
Stat 0x0
Jan 14 23:53:34 titan kernel: <7age: Bulk Status S 0x53425355 T 0x3dd7 R 0 Stat 0x0
Jan 14 23:53:36 titan kernel: <7orage: Bulk data transfer result 0x0
Jan 14 23:53:36 titan kernel: sfer complete
Jan 14 23:53:36 titan kernel: <7plete
Jan 14 23:53:38 titan kernel: <7 Bulk Status S 0x53425355 T 0x40e5 R 0 Stat 0x0

Here's my lspci -v:

[root@titan paul]# lspci -v
00:00.0 Host bridge: Silicon Integrated Systems [SiS] 645xx (rev 02)
        Subsystem: Silicon Integrated Systems [SiS] 645xx
        Flags: bus master, medium devsel, latency 32
        Memory at c0000000 (32-bit, non-prefetchable) [size=256M]
        Capabilities: [c0] AGP version 3.0

00:01.0 PCI bridge: Silicon Integrated Systems [SiS] Virtual PCI-to-PCI bridge
(AGP) (prog-if 00 [Normal decode])
        Flags: bus master, fast devsel, latency 64
        Bus: primary=00, secondary=01, subordinate=01, sec-latency=32
        Memory behind bridge: d8000000-d9ffffff
        Prefetchable memory behind bridge: d0000000-d7ffffff

00:02.0 ISA bridge: Silicon Integrated Systems [SiS] SiS963 [MuTIOL Media IO]
(rev 04)
        Flags: bus master, medium devsel, latency 0

00:02.1 SMBus: Silicon Integrated Systems [SiS] SiS961/2 SMBus Controller
        Flags: medium devsel
        I/O ports at 1400 [size=32]

00:02.5 IDE interface: Silicon Integrated Systems [SiS] 5513 [IDE] (prog-if 80
[Master])
        Subsystem: Silicon Integrated Systems [SiS] SiS5513 EIDE Controller (A,B
step)
        Flags: bus master, medium devsel, latency 128
        I/O ports at f000 [size=16]

00:02.7 Multimedia audio controller: Silicon Integrated Systems [SiS] Sound
Controller (rev a0)
        Subsystem: Giga-byte Technology: Unknown device a002
        Flags: bus master, medium devsel, latency 32, IRQ 17
        I/O ports at d800 [size=256]
        I/O ports at dc00 [size=128]
        Capabilities: [48] Power Management version 2

00:0a.0 Multimedia video controller: Brooktree Corporation Bt878 Video Capture
(rev 11)
        Subsystem: Hauppauge computer works Inc. WinTV Series
        Flags: bus master, medium devsel, latency 32, IRQ 17
        Memory at db005000 (32-bit, prefetchable) [size=4K]
        Capabilities: [44] Vital Product Data
        Capabilities: [4c] Power Management version 2

00:0a.1 Multimedia controller: Brooktree Corporation Bt878 Audio Capture (rev 11)
        Subsystem: Hauppauge computer works Inc. WinTV Series
        Flags: bus master, medium devsel, latency 32, IRQ 10
        Memory at db006000 (32-bit, prefetchable) [size=4K]
        Capabilities: [44] Vital Product Data
        Capabilities: [4c] Power Management version 2

00:0c.0 Ethernet controller: 3Com Corporation 3c905B 100BaseTX [Cyclone] (rev 30)
        Subsystem: 3Com Corporation 3C905B Fast Etherlink XL 10/100
        Flags: bus master, medium devsel, latency 32, IRQ 16
        I/O ports at e000 [size=128]
        Memory at db007000 (32-bit, non-prefetchable) [size=128]
        [virtual] Expansion ROM at 70000000 [disabled] [size=128K]
        Capabilities: [dc] Power Management version 1

00:0d.0 USB Controller: ALi Corporation USB 1.1 Controller (rev 03) (prog-if 10
[OHCI])
        Subsystem: ALi Corporation USB 1.1 Controller
        Flags: bus master, 66Mhz, medium devsel, latency 32, IRQ 17
        Memory at db008000 (32-bit, non-prefetchable) [size=4K]
        Capabilities: [60] Power Management version 2

00:0d.1 USB Controller: ALi Corporation USB 1.1 Controller (rev 03) (prog-if 10
[OHCI])
        Subsystem: ALi Corporation USB 1.1 Controller
        Flags: bus master, 66Mhz, medium devsel, latency 32, IRQ 19
        Memory at db009000 (32-bit, non-prefetchable) [size=4K]
        Capabilities: [60] Power Management version 2

00:0d.2 USB Controller: ALi Corporation USB 1.1 Controller (rev 03) (prog-if 10
[OHCI])
        Subsystem: ALi Corporation USB 1.1 Controller
        Flags: bus master, 66Mhz, medium devsel, latency 32, IRQ 16
        Memory at db00a000 (32-bit, non-prefetchable) [size=4K]
        Capabilities: [60] Power Management version 2

00:0d.3 USB Controller: ALi Corporation USB 2.0 Controller (rev 01) (prog-if 20
[EHCI])
        Subsystem: ALi Corporation USB 2.0 Controller
        Flags: bus master, 66Mhz, medium devsel, latency 32, IRQ 18
        Memory at db00b000 (32-bit, non-prefetchable) [size=256]
        Capabilities: [50] Power Management version 2
        Capabilities: [58] Debug port

01:00.0 VGA compatible controller: nVidia Corporation NV35 [GeForce FX 5900XT]
(rev a1) (prog-if 00 [VGA])
        Flags: bus master, 66Mhz, medium devsel, latency 248, IRQ 16
        Memory at d8000000 (32-bit, non-prefetchable) [size=16M]
        Memory at d0000000 (32-bit, prefetchable) [size=128M]
        [virtual] Expansion ROM at d9000000 [disabled] [size=128K]
        Capabilities: [60] Power Management version 2
        Capabilities: [44] AGP version 3.0

[root@titan paul]#
                             

Thanks.
Comment 1 Pete Zaitcev 2006-01-14 22:51:26 UTC 
A log like that is useless. We know that usb-storage's logging sucks, but there
may be a workaround. If you keep a "dmesg > /tmp/d.out" poised at a bash prompt
and hit enter the moment you detect a hang, it will get the tail of the buffer
intact.

Getting a usbmon trace may be useful, too (to rule out interaction with
some other process). See /usr/src/linux/Documentation/usb/usbmon.txt.

I have to warn you, storage logging may be only the first step to the
resolution. If the thing hangs because of VM problems, or because of EHCI
problems, it's going to be a long haul.

Does any older kernel work? If yes, which one?
Comment 2 Paul 2006-01-14 23:31:27 UTC 
Here is the result of running "dmesg > /tmp/d.out" about a second after I
noticed the freeze.

rage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a e8 55 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x5685c L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x5685c R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a e8 d5 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x5685d L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x5685d R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a e9 55 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x5685e L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x5685e R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a e9 d5 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x5685f L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x5685f R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a ea 55 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x56860 L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x56860 R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a ea d5 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x56861 L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x56861 R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a eb 55 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x56862 L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x56862 R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a eb d5 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x56863 L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x56863 R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a ec 55 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x56864 L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x56864 R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a ec d5 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x56865 L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x56865 R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a ed 55 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x56866 L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x56866 R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a ed d5 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x56867 L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x56867 R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a ee 55 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x56868 L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x56868 R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a ee d5 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x56869 L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x56869 R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a ef 55 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x5686a L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code 0; transferred 65536/65536
usb-storage: -- transfer complete
usb-storage: Bulk data transfer result 0x0
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code 0; transferred 13/13
usb-storage: -- transfer complete
usb-storage: Bulk status result = 0
usb-storage: Bulk Status S 0x53425355 T 0x5686a R 0 Stat 0x0
usb-storage: scsi cmd done, result=0x0
usb-storage: *** thread sleeping.
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command READ_10 (10 bytes)
usb-storage:  28 00 0a 5a ef d5 00 00 80 00
usb-storage: Bulk Command S 0x43425355 T 0x5686b L 65536 F 128 Trg 0 LUN 0 CL 10
usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
usb-storage: Status code 0; transferred 31/31
usb-storage: -- transfer complete
usb-storage: Bulk command transfer result=0
usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries
usb-storage: Status code -121; transferred 36867/65536
usb-storage: -- short read transfer
usb-storage: Bulk data transfer result 0x1
usb-storage: Attempting to get CSW...
usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
usb-storage: Status code -75; transferred 0/13
usb-storage: -- babble
usb-storage: Bulk status result = 3
usb-storage: -- transport indicates error, resetting
usb-storage: Refusing to reset a multi-interface device
usb-storage: usb_stor_Bulk_reset called
usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0
[root@titan tmp]#
Comment 3 Paul 2006-01-15 00:47:31 UTC 
Created attachment 7028 [details]
usbmon output from freeze

This is the usbmon output from the freeze.  I started usbmon about 5 seconds
before the freeze occured, the file transfer was stalled for about 40 seconds,
then it resumed, then I stopped usbmon about 5 seconds later.  Its a 2MB file
compressed, cus bugzilla wont let me upload a 2mb file....
Comment 4 Paul 2006-01-15 00:51:25 UTC 
OK, I ran the usbmon like you asked.  I started usbmon, copied a large file from
the USB hard drive, and sure enough, the freeze did occur.  I attached the
usbmon output as usbmon.txt.tar.gz. (The uncompressed file was 2MB [about 1
minute of usbmon capturing], so I had to compress [tar.gz] it in order to upload
it here.

No, I haven't tried any other kernels, as I just got the USB hard drive
recently, and before that, I never used USB for anything.  If there's a kernel
you'd like me to try, just let me know.

Thanks again!
Comment 5 David Brownell 2006-01-15 02:13:24 UTC 
Created attachment 7029 [details]
experimental patch

worth trying this patch ... might not help, but might.
Comment 6 Alan Stern 2006-01-15 08:46:38 UTC 
I suspect this is an ordinary sort of data transfer error.  Replacing USB cables
might help.

It's made more complicated by the fact that the device has multiple interfaces,
so usb-storage won't do its normal port reset.  What does "lsusb -v" show for
the drive?
Comment 7 Paul 2006-01-15 10:27:49 UTC 
I really dont think this is an ordinary data transfer problem.  It happens VERY
consistently in linux, and NEVER AT ALL in windows (exact same hardware, PC is
dual boot).  The drive and cable are less than 4 months old.

I'm gonna try the patch later tonight.  Here's the drive's lsusb -v:

Bus 001 Device 002: ID 1058:0404 Western Digital Technologies, Inc.
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass            0 (Defined at Interface level)
  bDeviceSubClass         0
  bDeviceProtocol         0
  bMaxPacketSize0        64
  idVendor           0x1058 Western Digital Technologies, Inc.
  idProduct          0x0404
  bcdDevice            6.02
  iManufacturer           1 Western Digital
  iProduct                2 External HDD
  iSerial                 3 57442D5743414C3736313631333830
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength           57
    bNumInterfaces          2
    bConfigurationValue     1
    iConfiguration          0
    bmAttributes         0xc0
      Self 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
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        1
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         3 Human Interface Devices
      bInterfaceSubClass      0 No Subclass
      bInterfaceProtocol      0 None
      iInterface              0
        HID Device Descriptor:
          bLength                 9
          bDescriptorType        33
          bcdHID               1.10
          bCountryCode            0 Not supported
          bNumDescriptors         1
          bDescriptorType        34 Report
          wDescriptorLength      34
          Report Descriptor: (length is 34)
            Item(Global): Usage Page, data= [ 0xa0 0xff ] 65440
                            (null)
            Item(Local ): Usage, data= [ 0xa5 ] 165
                            (null)
            Item(Main  ): Collection, data= [ 0x01 ] 1
                            Application
            Item(Local ): Usage, data= [ 0xa6 ] 166
                            (null)
            Item(Local ): Usage, data= [ 0xa7 ] 167
                            (null)
            Item(Global): Logical Minimum, data= [ 0x80 ] 128
            Item(Global): Logical Maximum, data= [ 0x7f ] 127
            Item(Global): Report Size, data= [ 0x08 ] 8
            Item(Global): Report Count, data= [ 0x02 ] 2
            Item(Main  ): Input, data= [ 0x02 ] 2
                            Data Variable Absolute No_Wrap Linear
                            Preferred_State No_Null_Position Non_Volatile Bitfield
            Item(Local ): Usage, data= [ 0xa9 ] 169
                            (null)
            Item(Global): Logical Minimum, data= [ 0x80 ] 128
            Item(Global): Logical Maximum, data= [ 0x7f ] 127
            Item(Global): Report Size, data= [ 0x08 ] 8
            Item(Global): Report Count, data= [ 0x02 ] 2
            Item(Main  ): Output, data= [ 0x02 ] 2
                            Data Variable Absolute No_Wrap Linear
                            Preferred_State No_Null_Position Non_Volatile Bitfield
            Item(Main  ): End Collection, data=none
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x83  EP 3 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0002  1x 2 bytes
        bInterval              10
Device Qualifier (for other device speed):
  bLength                10
  bDescriptorType         6
  bcdUSB               2.00
  bDeviceClass            0 (Defined at Interface level)
  bDeviceSubClass         0
  bDeviceProtocol         0
  bMaxPacketSize0        64
  bNumConfigurations      1
Comment 8 Pete Zaitcev 2006-01-15 11:35:33 UTC 
I am going to parse the usbmon output here. It adds nothing radically new to
Alan's asessement, only some curious details. It shows a data transfer error
(a bad cable or other, or a small bug in EHCI HCD), and failing to recover.
This is no different for ub, by the way, because ub uses the same reset
sequence as usb-storage.

 We submit a command, device responds, we submit data transfers (64KB):
f7542100 3328941948 S Bo:002:01 -115 31 = 55534243 c9640000 00000100 80000a28
000a8770 95000080 00000000 000000
f7542100 3328942090 C Bo:002:01 0 31 >
f1852a00 3328942107 S Bi:002:02 -115 8192 <
f1852e00 3328942109 S Bi:002:02 -115 8192 <
f1ee7400 3328942110 S Bi:002:02 -115 8192 <
f1852780 3328942110 S Bi:002:02 -115 8192 <
f1852280 3328942111 S Bi:002:02 -115 8192 <
f1c51200 3328942112 S Bi:002:02 -115 8192 <
f1c51f80 3328942113 S Bi:002:02 -115 8192 <
f1852f80 3328942114 S Bi:002:02 -115 8192 <

 Data transfers fail midway with a code 121 -EREMOTEIO:
f1852a00 3328943591 C Bi:002:02 0 8192 = 2bb6ed3a 6558923c 4978ad3f 9aa6a990
ded84311 c10c7f7c 91583281 1bd54299
f1852e00 3328943595 C Bi:002:02 0 8192 = f624946f 7ac16a34 44c927fc 1db0de7e
eae04748 c8b3ef80 7b494b5a f1728064
f1ee7400 3328943596 C Bi:002:02 0 8192 = b03fdfa3 b4697855 0872af96 7d674645
3275f0e6 ddcfdadf 32f7b482 f8d8107a
f1852780 3328943597 C Bi:002:02 0 8192 = 37d52070 0f65c53b adb66180 34ec17d0
3d8d0669 f0760c4c 5eaa9b97 749ffe83
f1852280 3328943598 C Bi:002:02 0 8192 = 4f24e29f 9952c61c 4d140387 97cc9f2e
f1a823f4 9c751096 3d7f2989 8326b70c
f1c51200 3328943599 C Bi:002:02 -121 4 = c672b92d
f1c51f80 3328943602 C Bi:002:02 -104 0
f1852f80 3328943603 C Bi:002:02 -104 0

 We read status, but get a bubble (presumably there's plenty of data
 pipelined yet):
f7542100 3328943619 S Bi:002:02 -115 13 <
f7542100 3328944091 C Bi:002:02 -75 0

 We do a quick bulk reset and clear halts (+6s wait)
f7542100 3328944111 S Co:002:00 s 21 ff 0000 0000 0000 0
f7542100 3328944466 C Co:002:00 0 0
f7542100 3334942799 S Co:002:00 s 02 01 0000 0082 0000 0
f7542100 3334943896 C Co:002:00 0 0
f7542100 3334943909 S Co:002:00 s 02 01 0000 0001 0000 0
f7542100 3334944393 C Co:002:00 0 0

 We retry the read and it fails with a simple timeout,
 which eats 30s:
f7542100 3334944523 S Bo:002:01 -115 31 = 55534243 ca640000 00000100 80000a28
000a8770 95000080 00000000 000000
f7542100 3334944768 C Bo:002:01 0 31 >
f1852a00 3334944786 S Bi:002:02 -115 8192 <
f1852e00 3334944788 S Bi:002:02 -115 8192 <
f1ee7400 3334944790 S Bi:002:02 -115 8192 <
f1852780 3334944791 S Bi:002:02 -115 8192 <
f1852280 3334944792 S Bi:002:02 -115 8192 <
f1c51200 3334944793 S Bi:002:02 -115 8192 <
f1c51f80 3334944794 S Bi:002:02 -115 8192 <
f1852f80 3334944795 S Bi:002:02 -115 8192 <
f1852a00 3334950793 C Bi:002:02 0 8192 = 55534243 ca640000 00000100 80000a28
000a8770 95000080 00000000 00000075
f1852e00 3334950795 C Bi:002:02 0 8192 = 68fdd165 94a9bc2a 44f328bb b91116a0
b98b3ce6 2d8cfb3d b65ba60a a480d5f7
f1ee7400 3364944910 C Bi:002:02 -104 5120 = d1b5ee14 26d57fec 9f587441 6c39d6fa
b1e12ef0 7d34cbdd e18f07be 3560fc11
f1852780 3364944919 C Bi:002:02 -104 0
f1852280 3364944920 C Bi:002:02 -104 0
f1c51200 3364944921 C Bi:002:02 -104 0
f1c51f80 3364944922 C Bi:002:02 -104 0
f1852f80 3364944923 C Bi:002:02 -104 0

 Bulk reset again, and a 6s wait:
f7542100 3364944948 S Co:002:00 s 21 ff 0000 0000 0000 0
f7542100 3364945281 C Co:002:00 0 0
f7542100 3370945048 S Co:002:00 s 02 01 0000 0082 0000 0
f7542100 3370946211 C Co:002:00 0 0
f7542100 3370946224 S Co:002:00 s 02 01 0000 0001 0000 0
f7542100 3370946583 C Co:002:00 0 0

Next command succeeds and we continue on our way, with 42s lost.
Comment 9 Pete Zaitcev 2006-01-15 12:05:35 UTC 
By the way, it's a good thing that the device timed out after the first reset,
because it transfered garbage.

Normal data looked like this:
 f1852a00 3328943591 C Bi:002:02 0 8192 = 2bb6ed3a 6558923c 4978ad3f 9aa6a990
ded84311 c10c7f7c 91583281 1bd54299
 .... looks like a compressed media stream.
But after the reset it looked like this:
 f1852a00 3334950793 C Bi:002:02 0 8192 = 55534243 ca640000 00000100 80000a28
000a8770 95000080 00000000 00000075
 .... which is the echo of the command which was just sent!

The first bulk reset did not reset the device and its firmware got all
confused.

I think we really need to work on lifting the limitation of not doing
port resets on multi-interface devices. It's a miracle that we did not
end with a data corruption here.
Comment 10 Alan Stern 2006-01-15 13:40:45 UTC 
Created attachment 7034 [details]
Reset even if there are multiple interfaces

"I really dont think this is an ordinary data transfer problem.  It happens
VERY
consistently in linux, and NEVER AT ALL in windows (exact same hardware, PC is
dual boot)."

You're missing the point.  It probably _is_ happening with Windows, and you
just aren't aware of it because Windows is able to recover and continue the
data transmission in a fraction of a second.  usb-storage would do the same
thing if your device didn't have a second interface.  Note that the age of a
device or a cable means nothing -- some vendors sell computers with bad
internal cables connecting the motherboard to the front USB ports on the case!

The attached patch will cause usb-storage to ignore the second interface and
perform the reset anyway.  I bet it will fix your problem.  (It might mess up
that other interface, though.)

By the way, what is the other interface used for?  Does the drive have some
buttons you can press, or a slider, or anything else of that sort?
Comment 11 Paul 2006-01-15 21:23:17 UTC 
Alan, you were indeed correct.  I tried your patch first, and it worked like a
charm!  I transferred a few gigs without one single noticeable pause, not even
any 6 second pauses. THANK YOU!

I'll take your advice on replacing the USB cable.  I'm definitely glad this
problem didnt lead to any data corruption.

The only thing I noticed now were these lines:

Jan 16 00:10:42 titan kernel: usb 1-6: reset high speed USB device using
ehci_hcd and address 2
Jan 16 00:11:15 titan last message repeated 2 times
Jan 16 00:12:43 titan kernel: usb 1-6: reset high speed USB device using
ehci_hcd and address 2

I assume this is OK, and is probably just indicitive of my need for a new USB
cable, and wont lead to any data corruption :)

In regards to the drive, its a Western Digital "Dual-Option Backup" drive. 
Which means that it has a useless button on the front that, had I ever installed
its software, would let me spawn a backup-process by pressing... It also has a
useless LED on the front that is supposed to tell me when I'm due for a
backup..... Useless marketing gimmicks...If the patch broke these things, I
couldn't possibly care less, because I've never used them.

Thanks a ton for all your help guys!
-Paul
Comment 12 Alan Stern 2006-01-16 07:52:39 UTC 
Good that the patch helped.  We need to change the kernel to avoid this sort of
problem coming up again in the future.  Would you be willing to try out other
patches in the future, to make sure they work properly?

Don't automatically assume that the cable is at fault.  I've got a USB disk
drive that doesn't work with one cable and does work with another.  However,
other USB devices work with both cables, and the drive and cable work together
when plugged into a different computer!  So all you can be certain of is that
the combination of USB-controller/cable/drive is a bad one.
Comment 13 Paul 2006-01-16 09:59:49 UTC 
I would absolutely be willing to help with any furthur patching/testing.  Just
let me know.
Comment 14 Greg Kroah-Hartman 2006-01-16 10:12:53 UTC 
Alan, you seem to want to take this one on :)
Comment 15 Greg Kroah-Hartman 2006-03-06 10:52:10 UTC 
Alan, any thoughts?
Comment 16 Alan Stern 2006-03-06 11:26:24 UTC 
Yes, sorry I've been out of touch on this.  If they're not at the center of my
attention, bug reports tend to just fade away... out of sight, out of mind.

To do this right will require a change to usbcore: sending notifications to
drivers when a device is about to be reset or has just been reset.  Not many
drivers will be affected very much; the only ones I'm certain of are usb-hid and
usb-storage.  I'll post something on linux-usb-devel when it's ready.
Comment 17 Alexandr Kara 2006-06-15 04:58:08 UTC 
I am probably having a similar problem.

In the kernel log (I don't have USB debugging turned on at the moment), these 3
lines repeat:

usb 3-5: reset high speed USB device using ehci_hcd and address 5
sd 2:0:0:0: SCSI error: return code = 0x70000
end_request: I/O error, dev sdc, sector 154221

The device works when plugged to a slow "full speed" (12 Mbit) hub.

I have an Asus A7N8X-E motherboard with an NForce 2 chipset which, as far as I
know, doesn't have a good reputation in Linux.
I am using the latest Fedora Core 5 kernel (2.6.16-1.2122_FC5).

The weird thing is that I have a flash-disk which works fine always, and one
which only works sometimes and in some USB ports/slots.
Another thing is that sometimes it works even if plugged to a front-panel USB
port (which might have bad cables) and after a power off/on, it doesn't work any
more.
The same devices work always well in my laptop (with an Intel chipset).

I posted a comment to bug 4057, but it is closed now.
Comment 18 Paul 2006-06-15 21:41:49 UTC 
You are experiencing a different problem.  I didnt get any SCSI errors or I/O
errors.  My whole problem stemmed from the fact that the usb driver REFUSED to
reset my device, but your device is in fact being reset, so I think your problem
is unrelated to the bug.
Comment 19 Frank Duignan 2007-01-22 02:48:43 UTC 
I had a similar problem with the Asus (VIA usb chip) motherboard.  When I
connected my mp3 player it would apparently randomly disconnect.  On foot of a
comment on the web I bought a pci usb card with an NEC chip (Belkin make the
card).  All appears to be well now.
Comment 20 Natalie Protasevich 2007-06-13 11:40:28 UTC 
Alan, I suspect you've done the fix that you intended in #16 since many problems with USB reset has gone away. Should we keep this bug open?

--Natalie
Comment 21 Alan Stern 2007-06-13 13:08:24 UTC 
Yes, the change has been made.  Closing the bug report.
Comment 22 Dominique Dumont 2007-06-13 13:11:50 UTC 
Ahem, I still have usb lockup on AMD 64 2.6.21. Should I file another bug report  or provide more information in this bug report ?
Comment 23 Alan Stern 2007-06-13 13:54:24 UTC 
Dominique, please start a new bug report and put the details there.
Comment 24 Dominique Dumont 2007-07-15 01:03:26 UTC 
Done in bug # 8692

http://bugzilla.kernel.org/show_bug.cgi?id=8692
Comment 25 Natalie Protasevich 2007-07-15 06:56:07 UTC 
To respond to #17:
Alexandr, if you feel your issue hasn't been addressed yet please test with latest kernel from kernel.org and if the problem still there file a new bug also.
Thanks.
Note You need to log in before you can comment on or make changes to this bug.