Hi, When I do plug/unplug cycles with a particular memory stick, which has an embedded hub, I get easily khubd hanging into uninterruptible sleep. I have made about 100 plug/unplug cycles for each of the following devices/combinations (keyboard, externalhub+keyboard [plugging/unplugging hub cable], bulk-only memory stick, externalhub+bulk-only stick, externalhub alone) without khubd hang. With my now trained hand, it takes no more than 5 cycles with this particular stick to knock khubd down. The hang happens only if the unplug event occurs, while the storage driver is configuring the device.
What can cause khubd sleeping uninterruptibly? How do debug this? Below is a log about how it all happens. Hints are needed and appreciated. Olav --------------- log ------------------- The only lines in the log printed from isp116x-hcd are in the form: RH stat change: rhstat 0, rhport1 10101, rhport2 100 which show up when port status has changed (printed from the irq handler) and where bit 0 of the rhport1 shows connection state (set if device present). Note that while address 116 is assigned for the internal hub and 117 for the storage, only 117 is reported to be successfully disconnected later. // plug RH stat change: rhstat 0, rhport1 10101, rhport2 100 usb 1-1: new full speed USB device using address 116 usb 1-1: skipped 1 descriptor after endpoint usb 1-1: new device strings: Mfr=1, Product=3, SerialNumber=0 usb 1-1: default language 0x0409 usb 1-1: Product: USB Embedded Hub usb 1-1: Manufacturer: Generic DEV: registering device: ID = '1-1' usb 1-1: hotplug bus usb: add device 1-1 bound device '1-1' to driver 'usb' usb 1-1: adding 1-1:1.0 (config #1, interface 0) DEV: registering device: ID = '1-1:1.0' usb 1-1:1.0: hotplug bus usb: add device 1-1:1.0 hub 1-1:1.0: usb_probe_interface hub 1-1:1.0: usb_probe_interface - got id hub 1-1:1.0: USB hub found hub 1-1:1.0: 1 port detected hub 1-1:1.0: compound device; port removable status: F hub 1-1:1.0: individual port power switching hub 1-1:1.0: individual port over-current protection hub 1-1:1.0: power on to power good time: 100ms hub 1-1:1.0: local power source is lost (inactive) hub 1-1:1.0: enabling power on all ports bound device '1-1:1.0' to driver 'hub' hub 1-1:1.0: port 1, status 0101, change 0001, 12 Mb/s hub 1-1:1.0: debounce: port 1: total 100ms stable 100ms status 0x101 1-1.1: new full speed USB device using address 117 usb 1-1.1: new device strings: Mfr=1, Product=4, SerialNumber=0 usb 1-1.1: default language 0x0409 usb 1-1.1: Product: USB Mass Storage Device usb 1-1.1: Manufacturer: Generic DEV: registering device: ID = '1-1.1' usb 1-1.1: hotplug bus usb: add device 1-1.1 bound device '1-1.1' to driver 'usb' usb 1-1.1: adding 1-1.1:1.0 (config #1, interface 0) DEV: registering device: ID = '1-1.1:1.0' usb 1-1.1:1.0: hotplug bus usb: add device 1-1.1:1.0 usb-storage 1-1.1:1.0: usb_probe_interface usb-storage 1-1.1:1.0: usb_probe_interface - got id usb-storage: USB Mass Storage device detected usb-storage: -- associate_dev usb-storage: Vendor: 0x3538, Product: 0x0022, Revision: 0x0001 usb-storage: Interface Subclass: 0x05, Protocol: 0x50 usb-storage: Vendor: Generic, Product: USB Mass Storage Device usb-storage: Transport: Bulk usb-storage: Protocol: 8070i usb-storage: usb_stor_control_msg: rq=fe rqtype=a1 value=0000 index=00 len=1 usb-storage: GetMaxLUN command result is 1, data is 0 usb-storage: *** thread sleeping. scsi89 : SCSI emulation for USB Mass Storage devices DEV: registering device: ID = 'host89' CLASS: registering class device: ID = 'host89' class_hotplug - name = host89 usb-storage: queuecommand called usb-storage: *** thread awakened. usb-storage: Command INQUIRY (6 bytes) usb-storage: 12 00 00 00 24 00 usb-storage: Bulk Command S 0x43425355 T 0xa47 L 36 F 128 Trg 0 LUN 0 CL 12 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_buf: xfer 36 bytes usb-storage: Status code 0; transferred 36/36 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 0xa47 R 0 Stat 0x0 usb-storage: Fixing INQUIRY data to show SCSI rev 2 - was 0 usb-storage: scsi cmd done, result=0x0 usb-storage: *** thread sleeping. Vendor: Generic Model: USB Flash Disk Rev: 1.00 Type: Direct-Access ANSI SCSI revision: 02 DEV: registering device: ID = '89:0:0:0' bus scsi: add device 89:0:0:0 usb-storage: queuecommand called usb-storage: *** thread awakened. usb-storage: Command TEST_UNIT_READY (6 bytes) usb-storage: 00 00 00 00 00 00 usb-storage: Bulk Command S 0x43425355 T 0xa48 L 0 F 0 Trg 0 LUN 0 CL 12 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: Attempting to get CSW... usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes // unplug RH stat change: rhstat 0, rhport1 10100, rhport2 100 usb-storage: Status code -110; transferred 0/13 usb-storage: -- timeout or NAK usb-storage: Bulk status result = 4 usb-storage: -- transport indicates error, resetting usb-storage: usb_stor_Bulk_reset called usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0 usb-storage: Soft reset failed: -110 usb-storage: scsi cmd done, result=0x70000 usb-storage: *** thread sleeping. usb-storage: queuecommand called usb-storage: *** thread awakened. usb-storage: Command TEST_UNIT_READY (6 bytes) usb-storage: 00 00 00 00 00 00 usb-storage: Bulk Command S 0x43425355 T 0xa49 L 0 F 0 Trg 0 LUN 0 CL 12 usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes hub 1-1:1.0: transfer --> -110 usb-storage: Status code -110; transferred 0/31 usb-storage: -- timeout or NAK usb-storage: Bulk command transfer result=4 usb-storage: -- transport indicates error, resetting usb-storage: usb_stor_Bulk_reset called usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0 // The following lines repeat many times // while instead of TEST_UNIT_READY there are // also READ_CAPACITY or ALLOW_MEDIUM_REMOVAL usb-storage: Soft reset failed: -110 usb-storage: scsi cmd done, result=0x70000 usb-storage: *** thread sleeping. usb-storage: queuecommand called usb-storage: *** thread awakened. usb-storage: Command TEST_UNIT_READY (6 bytes) usb-storage: 00 00 00 00 00 00 usb-storage: Bulk Command S 0x43425355 T 0xa4a L 0 F 0 Trg 0 LUN 0 CL 12 usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes hub 1-1:1.0: transfer --> -110 usb-storage: Status code -110; transferred 0/31 usb-storage: -- timeout or NAK usb-storage: Bulk command transfer result=4 usb-storage: -- transport indicates error, resetting usb-storage: usb_stor_Bulk_reset called usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0 usb-storage: Soft reset failed: -110 // end of repeat hub 1-1:1.0: transfer --> -110 usb-storage: Soft reset failed: -110 usb-storage: scsi cmd done, result=0x70000 usb-storage: *** thread sleeping. Attached scsi removable disk sda at scsi89, channel 0, id 0, lun 0 bound device '89:0:0:0' to driver 'sd' CLASS: registering class device: ID = '89:0:0:0' class_hotplug - name = 89:0:0:0 CLASS: registering class device: ID = 'sg0' class_hotplug - name = sg0 Attached scsi generic sg0 at scsi89, channel 0, id 0, lun 0, type 0 usb-storage: queuecommand called usb-storage: *** thread awakened. usb-storage: Bad target number (1:0) usb-storage: scsi cmd done, result=0x40000 usb-storage: *** thread sleeping. usb-storage: queuecommand called usb-storage: *** thread awakened. usb-storage: Bad target number (2:0) usb-storage: scsi cmd done, result=0x40000 usb-storage: *** thread sleeping. usb-storage: queuecommand called usb-storage: *** thread awakened. usb-storage: Bad target number (3:0) usb-storage: scsi cmd done, result=0x40000 usb-storage: *** thread sleeping. usb-storage: queuecommand called usb-storage: *** thread awakened. usb-storage: Bad target number (4:0) usb-storage: scsi cmd done, result=0x40000 usb-storage: *** thread sleeping. usb-storage: queuecommand called usb-storage: *** thread awakened. usb-storage: Bad target number (5:0) usb-storage: scsi cmd done, result=0x40000 usb-storage: *** thread sleeping. usb-storage: queuecommand called usb-storage: *** thread awakened. usb-storage: Bad target number (6:0) usb-storage: scsi cmd done, result=0x40000 usb-storage: *** thread sleeping. usb-storage: queuecommand called usb-storage: *** thread awakened. usb-storage: Bad target number (7:0) usb-storage: scsi cmd done, result=0x40000 usb-storage: *** thread sleeping. USB Mass Storage device found at 117 bound device '1-1.1:1.0' to driver 'usb-storage' hub 1-1:1.0: resetting for error -110 hub 1-1:1.0: transfer --> -110 usb 1-1.1: USB disconnect, address 117 usb 1-1.1: usb_disable_device nuking all URBs usb 1-1.1: unregistering interface 1-1.1:1.0 bus usb: remove device 1-1.1:1.0 usb-storage: storage_disconnect() called usb-storage: usb_stor_stop_transport called CLASS: Unregistering class device. ID = '89:0:0:0' CLASS: Unregistering class device. ID = 'sg0' class_hotplug - name = sg0 device class 'sg0': release. class_hotplug - name = 89:0:0:0 device class '89:0:0:0': release. bus scsi: remove device 89:0:0:0 CLASS: Unregistering class device. ID = 'host89' class_hotplug - name = host89 device class 'host89': release. usb-storage: -- usb_stor_release_resources usb-storage: -- sending exit command to thread usb-storage: *** thread awakened. usb-storage: -- exit command received usb-storage: -- dissociate_dev usb 1-1.1:1.0: hotplug usb 1-1.1: unregistering device DEV: Unregistering device. ID = '1-1.1' bus usb: remove device 1-1.1 usb 1-1.1: hotplug usb 1-1: __usb_reset_device for hub! hub 1-1:1.0: can't reset; disconnecting // Here the process is over, khubd is // sleeping uninterruptibly and further // attempts to plug/unplug yield just // the following printouts // unplug RH stat change: rhstat 0, rhport1 10100, rhport2 100 // plug RH stat change: rhstat 0, rhport1 10101, rhport2 100 ------------------------------------------------------- This SF.Net email is sponsored by: IntelliVIEW -- Interactive Reporting Tool for open source databases. Create drag-&-drop reports. Save time by over 75%! Publish reports on the web. Export to DOC, XLS, RTF, etc. Download a FREE copy at http://www.intelliview.com/go/osdn_nl _______________________________________________ linux-usb-devel@lists.sourceforge.net To unsubscribe, use the last form field at: https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
