Bug 138012

Summary: "lsusb -v" umounts USB storage device
Product: [openSUSE] SUSE LINUX 10.0 Reporter: Ulrich Windl <Ulrich.Windl>
Component: KernelAssignee: Olaf Hering <ohering>
Status: RESOLVED WONTFIX QA Contact: E-mail List <qa-bugs>
Severity: Normal    
Priority: P5 - None    
Version: Final   
Target Milestone: ---   
Hardware: Other   
OS: Other   
Whiteboard:
Found By: Other Services Priority:
Business Priority: Blocker: ---
Marketing QA Status: --- IT Deployment: ---
Attachments: Extract of /var/log/messages showing USB disconnects when there were physically none
Output of hwinfo (as requested)

Description Ulrich Windl 2005-12-12 10:06:48 UTC
I found that "lsusb -v" unmounts my USB storage device (kernel sees a USB disconnect where there was none)! I guess this is not intended.
Comment 1 Ulrich Windl 2005-12-12 10:08:11 UTC
Created attachment 60266 [details]
Extract of /var/log/messages showing USB disconnects when there were physically none
Comment 2 Olaf Hering 2005-12-12 13:48:14 UTC
please attach the full hwinfo output. thats a kernel bug, or a flaky device which doesnt handle some of the info requests.
Comment 3 Ulrich Windl 2005-12-12 14:53:08 UTC
Created attachment 60285 [details]
Output of hwinfo (as requested)
Comment 4 Olaf Hering 2005-12-13 14:09:29 UTC
Is there a hard requirement for 'acpi=force'? Does it work any better without it?
Comment 5 Olaf Hering 2005-12-13 14:14:57 UTC
Also, the hwinfo output is unfortunately incomplete, there are many parts missing after 
  <6>Adding 522072k swap on /dev/hda1.  Priority:42 extents:1
  <6>device-mapper: 4.4.0-ioctl (2005-01-12) initialised: dm-devel@redhat.com

Can you reproduce and attach the full dmesg output?
Comment 6 Ulrich Windl 2005-12-14 07:12:00 UTC
Comment #4: No, before the recent kernel update there was no requirement for "acpi=force". I guess it doesn't make a difference.
Comment #2: It could be related to the device, or it could be specific to USB 2.0.
Comment #3: I can't imagine why hwinfo should be incomplete. I redirected the output to af file (size 203211), and that file was attached. The file I have contains the block
...
  <6>Adding 522072k swap on /dev/hda1.  Priority:42 extents:1
  <6>device-mapper: 4.4.0-ioctl (2005-01-12) initialised: dm-devel@redhat.com
  <5>sdb: Write Protect is off
  <7>sdb: Mode Sense: 00 00 00 00
  <3>sdb: assuming drive cache: write through
...
Comment 7 Olaf Hering 2005-12-14 09:45:33 UTC
where is the info about the usb hostcontroller init, where is the info about sdb appearing? 
also try without acpi=force.
Comment 8 Ulrich Windl 2005-12-14 11:26:40 UTC
Comment #7: You are asking the wrong person. I guess the USB controller init messages are in /var/log/boot.msg or /var/log/messages. Did you see attachment #60266 [details] ?
Dec 12 10:35:15 pc8032 kernel: usbcore: registered new driver usbfs
Dec 12 10:35:15 pc8032 kernel: usbcore: registered new driver hub
Dec 12 10:35:15 pc8032 kernel: ACPI: PCI Interrupt 0000:00:12.2[C] -> Link [LNKD] -> GSI 11 (level, low) -> IRQ 11
Dec 12 10:35:15 pc8032 kernel: ehci_hcd 0000:00:12.2: EHCI Host Controller
Dec 12 10:35:15 pc8032 kernel: ehci_hcd 0000:00:12.2: new USB bus registered, assigned bus number 1
Dec 12 10:35:15 pc8032 kernel: ehci_hcd 0000:00:12.2: irq 11, io mem 0xf4101400Dec 12 10:35:15 pc8032 kernel: ehci_hcd 0000:00:12.2: USB 2.0 initialized, EHCI 1.00, driver 10 Dec 2004
Dec 12 10:35:15 pc8032 kernel: hub 1-0:1.0: USB hub found
Dec 12 10:35:15 pc8032 kernel: hub 1-0:1.0: 4 ports detected
Dec 12 10:35:15 pc8032 kernel: piix4_smbus 0000:00:04.3: Found 0000:00:04.3 device
Dec 12 10:35:15 pc8032 kernel: USB Universal Host Controller Interface driver v2.3
Dec 12 10:35:15 pc8032 kernel: ACPI: PCI Interrupt 0000:00:04.2[D] -> Link [LNKD] -> GSI 11 (level, low) -> IRQ 11
Dec 12 10:35:15 pc8032 kernel: uhci_hcd 0000:00:04.2: UHCI Host Controller
Dec 12 10:35:15 pc8032 kernel: uhci_hcd 0000:00:04.2: new USB bus registered, assigned bus number 2
Dec 12 10:35:15 pc8032 kernel: uhci_hcd 0000:00:04.2: irq 11, io base 0x00001000
Dec 12 10:35:15 pc8032 kernel: hub 2-0:1.0: USB hub found
Dec 12 10:35:15 pc8032 kernel: hub 2-0:1.0: 2 ports detected
Dec 12 10:35:15 pc8032 kernel: ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 5Dec 12 10:35:15 pc8032 kernel: PCI: setting IRQ 5 as level-triggered
Dec 12 10:35:15 pc8032 kernel: ACPI: PCI Interrupt 0000:00:12.0[A] -> Link [LNKB] -> GSI 5 (level, low) -> IRQ 5
Dec 12 10:35:15 pc8032 kernel: uhci_hcd 0000:00:12.0: UHCI Host Controller
Dec 12 10:35:15 pc8032 kernel: uhci_hcd 0000:00:12.0: new USB bus registered, assigned bus number 3
Dec 12 10:35:15 pc8032 kernel: uhci_hcd 0000:00:12.0: irq 5, io base 0x00001020Dec 12 10:35:15 pc8032 kernel: hub 3-0:1.0: USB hub found
Dec 12 10:35:15 pc8032 kernel: hub 3-0:1.0: 2 ports detected
Dec 12 10:35:15 pc8032 kernel: ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 10
Dec 12 10:35:15 pc8032 kernel: PCI: setting IRQ 10 as level-triggered
Dec 12 10:35:15 pc8032 kernel: ACPI: PCI Interrupt 0000:00:12.1[B] -> Link [LNKC] -> GSI 10 (level, low) -> IRQ 10
Dec 12 10:35:15 pc8032 kernel: uhci_hcd 0000:00:12.1: UHCI Host Controller
Dec 12 10:35:15 pc8032 kernel: uhci_hcd 0000:00:12.1: new USB bus registered, assigned bus number 4
Dec 12 10:35:15 pc8032 kernel: uhci_hcd 0000:00:12.1: irq 10, io base 0x00001060
Dec 12 10:35:15 pc8032 kernel: hub 4-0:1.0: USB hub found
Dec 12 10:35:15 pc8032 kernel: hub 4-0:1.0: 2 ports detected
Dec 12 10:35:15 pc8032 kernel: ohci_hcd: 2005 April 22 USB 1.1 'Open' Host Controller (OHCI) Driver (PCI)
Dec 12 10:35:15 pc8032 kernel: usbcore: registered new driver hiddev
Dec 12 10:35:15 pc8032 kernel: usbcore: registered new driver usbhid
Dec 12 10:35:15 pc8032 kernel: drivers/usb/input/hid-core.c: v2.01:USB HID core driver
...
Dec 12 10:46:40 pc8032 kernel: usb 1-4: new high speed USB device using ehci_hcd and address 2
Dec 12 10:46:40 pc8032 kernel: SCSI subsystem initialized
Dec 12 10:46:40 pc8032 kernel: Initializing USB Mass Storage driver...
Dec 12 10:46:40 pc8032 kernel: scsi0 : SCSI emulation for USB Mass Storage devices
Dec 12 10:46:40 pc8032 kernel: usb-storage: device found at 2
Dec 12 10:46:40 pc8032 kernel: usb-storage: waiting for device to settle before scanning
Dec 12 10:46:40 pc8032 kernel: usbcore: registered new driver usb-storage
Dec 12 10:46:40 pc8032 kernel: USB Mass Storage support registered.
Dec 12 10:46:45 pc8032 kernel:   Vendor:           Model: USB DISK Pro      Rev: 1.01
Dec 12 10:46:45 pc8032 kernel:   Type:   Direct-Access                      ANSI SCSI revision: 00
Dec 12 10:46:45 pc8032 kernel:   Vendor:           Model: USB DISK Pro      Rev: 1.01
Dec 12 10:46:45 pc8032 kernel:   Type:   Direct-Access                      ANSI SCSI revision: 00
Dec 12 10:46:45 pc8032 kernel: usb-storage: device scan complete
Dec 12 10:46:46 pc8032 kernel: SCSI device sda: 484352 512-byte hdwr sectors (248 MB)
Dec 12 10:46:46 pc8032 kernel: sda: Write Protect is off
Dec 12 10:46:46 pc8032 kernel: sda: Mode Sense: 23 00 00 00
Dec 12 10:46:46 pc8032 kernel: sda: assuming drive cache: write through
Dec 12 10:46:46 pc8032 kernel: SCSI device sda: 484352 512-byte hdwr sectors (248 MB)
Dec 12 10:46:46 pc8032 kernel: sda: Write Protect is off
Dec 12 10:46:46 pc8032 kernel: sda: Mode Sense: 23 00 00 00
Dec 12 10:46:46 pc8032 kernel: sda: assuming drive cache: write through
Dec 12 10:46:46 pc8032 kernel:  sda: sda1
Dec 12 10:46:46 pc8032 kernel: Attached scsi removable disk sda at scsi0, channel 0, id 0, lun 0
Dec 12 10:46:46 pc8032 kernel: SCSI device sdb: 2880 512-byte hdwr sectors (1 MB)
Dec 12 10:46:46 pc8032 kernel: sdb: Write Protect is off
Dec 12 10:46:46 pc8032 kernel: sdb: Mode Sense: 23 00 00 00
Dec 12 10:46:47 pc8032 kernel: sdb: assuming drive cache: write through
Dec 12 10:46:47 pc8032 kernel: SCSI device sdb: 2880 512-byte hdwr sectors (1 MB)
Dec 12 10:46:47 pc8032 kernel: sdb: Write Protect is off
Dec 12 10:46:47 pc8032 kernel: sdb: Mode Sense: 23 00 00 00
Dec 12 10:46:47 pc8032 kernel: sdb: assuming drive cache: write through
Dec 12 10:46:47 pc8032 kernel:  sdb: unknown partition table
Dec 12 10:46:47 pc8032 kernel: Attached scsi removable disk sdb at scsi0, channel 0, id 0, lun 1
Dec 12 10:46:47 pc8032 kernel: Attached scsi generic sg0 at scsi0, channel 0, id 0, lun 0,  type 0
Dec 12 10:46:47 pc8032 kernel: Attached scsi generic sg1 at scsi0, channel 0, id 0, lun 1,  type 0
Dec 12 10:46:48 pc8032 hal-subfs-mount[5618]: SYMLINKS:: disk/by-id/usb-_USB_DISK_Pro_07471A063018 disk/by-path/usb-07471A063018:0:0:1
Dec 12 10:46:48 pc8032 hal-subfs-mount[5618]: MOUNT_POINT:: /media/usbdisk
Dec 12 10:46:48 pc8032 hal-subfs-mount[5618]: MOUNTPOINT:: /media/usbdisk
Dec 12 10:46:48 pc8032 hal-subfs-mount[5618]: Collected mount options and Called(0) /bin/mount -t subfs -o fs=floppyfss,sync,procuid,nosuid,nodev,exec,utf8=true /dev/sdb "/media/usbdisk"
Dec 12 10:46:49 pc8032 udevd[2054]: get_netlink_msg: no ACTION in payload found, skip event 'mount'
Dec 12 10:46:49 pc8032 hal-subfs-mount[5637]: SYMLINKS:: disk/by-id/usb-_USB_DISK_Pro_07471A063018 disk/by-path/usb-07471A063018:0:0:0
Dec 12 10:46:49 pc8032 hal-subfs-mount[5637]: MOUNT_POINT:: /media/USBDISKPRO
Dec 12 10:46:49 pc8032 hal-subfs-mount[5637]: MOUNTPOINT:: /media/USBDISKPRO
Dec 12 10:46:49 pc8032 hal-subfs-mount[5637]: Collected mount options and Called(0) /bin/mount -t subfs -o fs=floppyfss,sync,procuid,nosuid,nodev,exec,utf8=true /dev/sda1 "/media/USBDISKPRO"
Dec 12 10:46:49 pc8032 udevd[2054]: get_netlink_msg: no ACTION in payload found, skip event 'mount'
Dec 12 10:46:52 pc8032 udevd[2054]: get_netlink_msg: no ACTION in payload found, skip event 'umount'
Dec 12 10:46:52 pc8032 udevd[2054]: get_netlink_msg: no ACTION in payload found, skip event 'umount'
Dec 12 10:47:26 pc8032 kernel: usb 1-4: USB disconnect, address 2
Dec 12 10:47:26 pc8032 kernel: scsi0 (0:0): rejecting I/O to dead device
Dec 12 10:47:26 pc8032 last message repeated 3 times
Dec 12 10:47:26 pc8032 kernel: sda : READ CAPACITY failed.
Dec 12 10:47:26 pc8032 kernel: sda : status=0, message=00, host=0, driver=04
Dec 12 10:47:26 pc8032 kernel: sda : sense not available.
Dec 12 10:47:26 pc8032 kernel: scsi0 (0:0): rejecting I/O to dead device
Dec 12 10:47:26 pc8032 kernel: sda: Write Protect is off
Dec 12 10:47:26 pc8032 kernel: sda: Mode Sense: 00 00 00 00
Dec 12 10:47:26 pc8032 kernel: sda: assuming drive cache: write through
Dec 12 10:47:26 pc8032 kernel: scsi0 (0:0): rejecting I/O to dead device
Dec 12 10:47:26 pc8032 last message repeated 3 times
Dec 12 10:47:26 pc8032 kernel: sda : READ CAPACITY failed.
Dec 12 10:47:26 pc8032 kernel: sda : status=0, message=00, host=0, driver=04
Dec 12 10:47:26 pc8032 kernel: sda : sense not available.
Dec 12 10:47:26 pc8032 kernel: scsi0 (0:0): rejecting I/O to dead device
Dec 12 10:47:26 pc8032 kernel: sda: Write Protect is off
Dec 12 10:47:26 pc8032 kernel: sda: Mode Sense: 00 00 00 00
Dec 12 10:47:26 pc8032 kernel: sda: assuming drive cache: write through
Dec 12 10:47:26 pc8032 kernel:  sda:<3>scsi0 (0:0): rejecting I/O to dead device
Dec 12 10:47:26 pc8032 kernel: Buffer I/O error on device sda, logical block 0
Dec 12 10:47:26 pc8032 kernel: scsi0 (0:0): rejecting I/O to dead device
Dec 12 10:47:26 pc8032 kernel: Buffer I/O error on device sda, logical block 0
Dec 12 10:47:26 pc8032 kernel: scsi0 (0:0): rejecting I/O to dead device
Dec 12 10:47:26 pc8032 kernel: Buffer I/O error on device sda, logical block 0
Dec 12 10:47:26 pc8032 kernel:  unable to read partition table
Dec 12 10:47:26 pc8032 hal-subfs-mount[5749]: By hald-subfs-mount created dir /media/USBDISKPRO got removed.
Dec 12 10:47:26 pc8032 hal-subfs-mount[5769]: By hald-subfs-mount created dir /media/usbdisk got removed.
Comment 9 Olaf Hering 2005-12-15 22:49:55 UTC
how is the testing without 'acpi=force' going? Does it change anything?
Comment 10 Ulrich Windl 2005-12-16 07:22:20 UTC
What makes you think using ACPI could have something to do with USB detecting a device disconnect when there is none? Regarding the testing: I mainly (try to) use Linux for getting work done, not for rebooting. Despite of your question on whether the effect is hardware dependent, I might add the further questions whether it may be timing dependent ot dependent on using USB 2.0. The combinations of tests that could be done is significant, so it might good to have some theory to cut down the tests to do to what seems to produce any new insights. Now that you have the kernel messages.
Comment 11 Olaf Hering 2005-12-16 09:10:47 UTC
Uli, we are not a hardware company nor do we have the hardware specs for the hardware you use.
I suggest you bug the involved hardware vendors. After all, its their job to keep the stuff running. Not ours.

Good luck.
Comment 12 Ulrich Windl 2005-12-16 09:53:47 UTC
OK, I can tell you that the problem only happens with one of m,y three USB 2.0 memory sticks. Unfortunately the one with the problem (TakeMS, www.takems.com) is the one our company give out to the employees, while the "good" one are my own.
At the last attempt the kernel messges were:
kernel: usb 4-2: reset low speed USB device using uhci_hcd and address 6
kernel: usb 4-2: device descriptor read/64, error -110

Maybe the kernel tried to re-establish the connection after that, but it failed (see also bug #139317 (completely different device)):
Dec 16 10:36:36 pc8032 kernel: usb 4-2: new low speed USB device using uhci_hcd and address 8
Dec 16 10:36:40 pc8032 kernel: usb 4-2: device descriptor read/64, error -110
Dec 16 10:36:55 pc8032 kernel: usb 4-2: device descriptor read/64, error -110
Dec 16 10:36:55 pc8032 kernel: usb 4-2: new low speed USB device using uhci_hcd and address 9
Dec 16 10:37:06 pc8032 kernel: usb 4-2: device not accepting address 9, error -110
Dec 16 10:37:06 pc8032 kernel: usb 4-2: new full speed USB device using uhci_hcd and address 10
Dec 16 10:37:16 pc8032 kernel: usb 4-2: device not accepting address 10, error -110

The problem with the stick also appears on a different (USB 1) port.

As "lsusb" can be called by normal users, this issue might be considered as a denial of service attack as well. If you decide not to care, it's your decision.
Comment 13 Ulrich Windl 2005-12-19 07:30:05 UTC
Regarding comment #4, comment #7, and comment #9 on "acpi=force": No, using "acpi=off" dis not change anything (as I had expected). Now you know it, too.