Begin forwarded message:
Date: Fri, 2 Sep 2005 02:21:26 -0700 From: [EMAIL PROTECTED] To: [EMAIL PROTECTED] Subject: [Bugme-new] [Bug 5173] New: USB subsystems hangs when stressing the bulk-only storage device http://bugzilla.kernel.org/show_bug.cgi?id=5173 Summary: USB subsystems hangs when stressing the bulk-only storage device Kernel Version: 2.6.13 Status: NEW Severity: normal Owner: [EMAIL PROTECTED] Submitter: [EMAIL PROTECTED] Most recent kernel where this bug did not occur: None Distribution: Mandriva Linux release 2006.0 (Cooker) for i586 Hardware Environment: i686 Intel(R) Pentium(R) 4 CPU 3.00GHz Software Environment: Kernel tested: 2.6.13-rc7, 2.6.13 Problem Description: I write a test program to tests flash cards through card readers. All the flash cards are identical. The card readers are the same, too. This program relies on usb-storage to build the block devices for the flash card/card readers. Then read and write tests with O_SYNC open option are performed. If only one pair is tested, it seems okay. However, typically several pairs are tested simultaneously. Inside my program, each transfer unit of read() or write() is 64K bytes. The data is generated randomly. And the address is also randomly generated but guaranteed to be valid. After some long tests (about several hundreds MB for each pair), one pair may hang. That is, the I/O operation (read() or write()) never returns. Command lsusb will never return, either. Even if I unplugged all the card readers, the USB subsystem still hangs. And the block devices /dev/sdX are still present. By the ps command, it can be observed that all storage and scsi drivers are still present and one of them is blocked. The following is the ps result of tests for 4 pairs: [EMAIL PROTECTED] syslog]# ps -eo pid,tid,class,rtprio,ni,pri,psr,pcpu,stat,wchan:30,comm | grep scsi 8635 8635 TS - 0 19 0 0.0 S text.lock.scsi_error scsi_eh_35 8649 8649 TS - 0 19 0 0.0 S text.lock.scsi_error scsi_eh_36 8685 8685 TS - 0 24 0 0.0 S text.lock.scsi_error scsi_eh_37 8713 8713 TS - 0 24 0 0.0 D command_abort scsi_eh_38 [EMAIL PROTECTED] syslog]# ps -eo pid,tid,class,rtprio,ni,pri,psr,pcpu,stat,wchan:30,comm | grep usb 8636 8636 TS - 0 24 0 0.0 S text.lock.usb usb-storage 8650 8650 TS - 0 24 0 0.0 S text.lock.usb usb-storage 8687 8687 TS - 0 24 0 0.0 S text.lock.usb usb-storage 9202 9202 TS - 0 22 0 0.0 D+ text.lock.usb lsusb The following is the ver_linux result: Gnu C 4.0.1 Gnu make 3.80 binutils 2.16.91.0.2 util-linux 2.12q mount 2.12q module-init-tools 3.2-pre8 e2fsprogs 1.38 reiserfsprogs line reiser4progs line nfs-utils 1.0.7 Linux C Library 2.3.5 Dynamic linker (ldd) 2.3.5 Procps 3.2.5 Net-tools 1.60 Console-tools 0.2.3 Sh-utils 5.2.1 udev 068 Modules Loaded sd_mod usb_storage nfsd exportfs ipv6 nfs lockd nfs_acl sunrpc snd_pcm_oss snd_mixer_oss snd_intel8x0 snd_ac97_codec snd_pcm snd_timer snd soundcore snd_page_alloc sk98lin af_packet ide_cd loop vfat fat nls_cp950 ntfs intel_agp agpgart hw_random ata_piix libata scsi_mod ehci_hcd uhci_hcd usbcore ext3 jbd The following is the last few messages of /var/log/kernel/info: (The devices are 5-1.1, 5-1.2, 5-1.3, and 5-1.4. Only 5-1.4 failed to complete the testing) Sep 2 16:17:10 fsyang kernel: usb-storage: Command WRITE_10 (10 bytes) Sep 2 16:17:10 fsyang kernel: usb-storage: 2a 00 00 0f 11 00 00 00 80 00 Sep 2 16:17:10 fsyang kernel: usb-storage: Bulk Command S 0x43425355 T 0x2150 L 65536 F 0 Trg 0 LUN 0 CL 10 Sep 2 16:17:10 fsyang kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes Sep 2 16:17:10 fsyang kernel: usb-storage: Status code 0; transferred 31/31 Sep 2 16:17:10 fsyang kernel: usb-storage: -- transfer complete Sep 2 16:17:10 fsyang kernel: usb-storage: Bulk command transfer result=0 Sep 2 16:17:10 fsyang kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 16 entries Sep 2 16:17:10 fsyang kernel: usb-storage: Status code 0; transferred 65536/65536 Sep 2 16:17:10 fsyang kernel: usb-storage: -- transfer complete Sep 2 16:17:10 fsyang kernel: usb-storage: Bulk data transfer result 0x0 Sep 2 16:17:10 fsyang kernel: usb-storage: Attempting to get CSW... Sep 2 16:17:10 fsyang kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes Sep 2 16:17:10 fsyang kernel: usb-storage: Status code 0; transferred 13/13 Sep 2 16:17:10 fsyang kernel: usb-storage: -- transfer complete Sep 2 16:17:10 fsyang kernel: usb-storage: Bulk status result = 0 Sep 2 16:17:10 fsyang kernel: usb-storage: Bulk Status S 0x53425355 T 0x2150 R 0 Stat 0x0 Sep 2 16:17:10 fsyang kernel: usb-storage: scsi cmd done, result=0x0 Sep 2 16:17:10 fsyang kernel: usb-storage: *** thread sleeping. Sep 2 16:17:10 fsyang kernel: usb-storage: queuecommand called Sep 2 16:17:10 fsyang kernel: usb-storage: *** thread awakened. Sep 2 16:17:10 fsyang kernel: usb-storage: Command WRITE_10 (10 bytes) Sep 2 16:17:10 fsyang kernel: usb-storage: 2a 00 00 0f 11 80 00 00 80 00 Sep 2 16:17:10 fsyang kernel: usb-storage: Bulk Command S 0x43425355 T 0x2151 L 65536 F 0 Trg 0 LUN 0 CL 10 Sep 2 16:17:10 fsyang kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes Sep 2 16:17:10 fsyang kernel: usb-storage: Status code 0; transferred 31/31 Sep 2 16:17:10 fsyang kernel: usb-storage: -- transfer complete Sep 2 16:17:10 fsyang kernel: usb-storage: Bulk command transfer result=0 Sep 2 16:17:10 fsyang kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 65536 bytes, 15 entries Sep 2 16:17:10 fsyang kernel: usb-storage: Status code -71; transferred 56832/65536 Sep 2 16:17:10 fsyang kernel: usb-storage: -- unknown error Sep 2 16:17:10 fsyang kernel: usb-storage: Bulk data transfer result 0x4 Sep 2 16:17:10 fsyang kernel: usb-storage: -- transport indicates error, resetting Sep 2 16:17:13 fsyang kernel: usb-storage: usb_reset_device returns -19 Sep 2 16:17:13 fsyang kernel: usb-storage: usb_stor_Bulk_reset called Sep 2 16:17:13 fsyang kernel: usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0 Sep 2 16:17:13 fsyang kernel: usb-storage: Soft reset failed: -19 Sep 2 16:17:13 fsyang kernel: usb-storage: scsi cmd done, result=0x70000 Sep 2 16:17:13 fsyang kernel: usb-storage: *** thread sleeping. Sep 2 16:17:13 fsyang kernel: usb-storage: queuecommand called Sep 2 16:17:13 fsyang kernel: usb-storage: *** thread awakened. Sep 2 16:17:13 fsyang kernel: usb-storage: Command WRITE_10 (10 bytes) Sep 2 16:17:13 fsyang kernel: usb-storage: 2a 00 00 0f 11 80 00 00 80 00 Sep 2 16:17:13 fsyang kernel: usb-storage: Bulk Command S 0x43425355 T 0x2152 L 65536 F 0 Trg 0 LUN 0 CL 10 Sep 2 16:17:13 fsyang kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes Sep 2 16:17:13 fsyang kernel: usb-storage: Status code -19; transferred 0/31 Sep 2 16:17:13 fsyang kernel: usb-storage: -- unknown error Sep 2 16:17:13 fsyang kernel: usb-storage: Bulk command transfer result=4 Sep 2 16:17:13 fsyang kernel: usb-storage: -- transport indicates error, resetting Sep 2 16:17:13 fsyang kernel: usb-storage: unable to lock device for reset: -19 Sep 2 16:17:13 fsyang kernel: usb-storage: usb_stor_Bulk_reset called Sep 2 16:17:13 fsyang kernel: usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0 Sep 2 16:17:13 fsyang kernel: usb-storage: Soft reset failed: -19 Sep 2 16:17:13 fsyang kernel: usb-storage: scsi cmd done, result=0x70000 Sep 2 16:17:13 fsyang kernel: usb-storage: *** thread sleeping. Sep 2 16:17:13 fsyang kernel: usb-storage: queuecommand called Sep 2 16:17:13 fsyang kernel: usb-storage: *** thread awakened. Sep 2 16:17:13 fsyang kernel: usb-storage: Command WRITE_10 (10 bytes) Sep 2 16:17:13 fsyang kernel: usb-storage: 2a 00 00 0f 11 80 00 00 80 00 Sep 2 16:17:13 fsyang kernel: usb-storage: Bulk Command S 0x43425355 T 0x2153 L 65536 F 0 Trg 0 LUN 0 CL 10 Sep 2 16:17:13 fsyang kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes Sep 2 16:17:13 fsyang kernel: usb-storage: Status code -19; transferred 0/31 Sep 2 16:17:13 fsyang kernel: usb-storage: -- unknown error Sep 2 16:17:13 fsyang kernel: usb-storage: Bulk command transfer result=4 Sep 2 16:17:13 fsyang kernel: usb-storage: -- transport indicates error, resetting Sep 2 16:17:13 fsyang kernel: usb-storage: unable to lock device for reset: -19 Sep 2 16:17:13 fsyang kernel: usb-storage: usb_stor_Bulk_reset called Sep 2 16:17:13 fsyang kernel: usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0 Sep 2 16:17:13 fsyang kernel: usb-storage: Soft reset failed: -19 Sep 2 16:17:13 fsyang kernel: usb-storage: scsi cmd done, result=0x70000 Sep 2 16:17:13 fsyang kernel: usb-storage: *** thread sleeping. Sep 2 16:17:13 fsyang kernel: usb-storage: queuecommand called Sep 2 16:17:13 fsyang kernel: usb-storage: *** thread awakened. Sep 2 16:17:13 fsyang kernel: usb-storage: Command WRITE_10 (10 bytes) Sep 2 16:17:13 fsyang kernel: usb-storage: 2a 00 00 0f 11 80 00 00 80 00 Sep 2 16:17:13 fsyang kernel: usb-storage: Bulk Command S 0x43425355 T 0x2154 L 65536 F 0 Trg 0 LUN 0 CL 10 Sep 2 16:17:13 fsyang kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes Sep 2 16:17:13 fsyang kernel: usb-storage: Status code -19; transferred 0/31 Sep 2 16:17:13 fsyang kernel: usb-storage: -- unknown error Sep 2 16:17:13 fsyang kernel: usb-storage: Bulk command transfer result=4 Sep 2 16:17:13 fsyang kernel: usb-storage: -- transport indicates error, resetting Sep 2 16:17:13 fsyang kernel: usb-storage: unable to lock device for reset: -19 Sep 2 16:17:13 fsyang kernel: usb-storage: usb_stor_Bulk_reset called Sep 2 16:17:13 fsyang kernel: usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0 Sep 2 16:17:13 fsyang kernel: usb-storage: Soft reset failed: -19 Sep 2 16:17:13 fsyang kernel: usb-storage: scsi cmd done, result=0x70000 Sep 2 16:17:13 fsyang kernel: usb-storage: *** thread sleeping. Sep 2 16:17:13 fsyang kernel: usb-storage: queuecommand called Sep 2 16:17:13 fsyang kernel: usb 5-1.4: USB disconnect, address 50 Sep 2 16:17:13 fsyang kernel: usb-storage: storage_disconnect() called Sep 2 16:17:13 fsyang kernel: usb-storage: usb_stor_stop_transport called Sep 2 16:17:13 fsyang kernel: usb-storage: *** thread awakened. Sep 2 16:17:13 fsyang kernel: usb-storage: -- exiting Sep 2 16:17:18 fsyang kernel: usb-storage: command_abort called Sep 2 16:17:18 fsyang kernel: usb-storage: usb_stor_stop_transport called This log isn't affected by unplugging all the USB card readers. So I think the USB subsystem is dead... By the way, the possibility of failure depends on the host (PC) and hub used. So I think the hardware brand isn't the most important factor. The card reader seems not robust enough to recover from errors. Most of the devices under Kernel 2.6.12.5 will always fail (with messages "No such device or adderss", etc.) when several are tested simultaneously. By monitoring the USB bus, we know the device failed to respond correctly when errors happens. For example, it failed to ACK the bulk reset command or endlessly NAK the bulk in command. As a result, Kernel 2.6.12.5 will put it offline. Kernel 2.6.13 is better. However, isn't good enough. Sometimes still failed to recover from errors and I need to close the block device and reopen it for further testings. And this won't always solve the errors. For example, I re-opened the block device for 10 times and write() still failed. Then I gave up! ------- You are receiving this mail because: ------- You are on the CC list for the bug, or are watching someone who is. ------------------------------------------------------- SF.Net email is Sponsored by the Better Software Conference & EXPO September 19-22, 2005 * San Francisco, CA * Development Lifecycle Practices Agile & Plan-Driven Development * Managing Projects & Teams * Testing & QA Security * Process Improvement & Measurement * http://www.sqe.com/bsce5sf _______________________________________________ linux-usb-devel@lists.sourceforge.net To unsubscribe, use the last form field at: https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
