Dear Sarah and Andiry,
I finally got to recompile the kernel with CONFIG_USB_STORAGE_DEBUG enabled.
My apologies if this email seems longish.
Andiry Xu wrote:
> On 03/29/2012 07:11 AM, Sarah Sharp wrote:
>> On Tue, Mar 27, 2012 at 07:29:23PM +0200, Martin Mokrejs wrote:
>>> Hi,
>>> I already mentioned on this list I am having some issues with my new 2.7TiB hard drive
>>> which I bought at about a month ago. I crashed ext3 fs two days ago on it when I filled
>>> up the disk with the data. Yesterday I learned Seagate released a new firmware for it.
>>> I flashed it from CC46 (I think) to CC4C. I created an ext4 filesystem now, just in case.
>>> I started copying fo teh data and two hours later I see on the console:
>>>
>>> vostro kernel: journal commit I/O error
>>>
>>> Aside from the fact I do not understand why is it coming from "JBD2" it seems it caused
>>> the drive to be unmounted. Is that a part of ext4 driver?
>>>
>>> Anyway, it looks the whole story started here:
>>>
>>> Mar 27 18:10:23 vostro kernel: xhci_hcd 0000:0b:00.0: WARN: transfer error on endpoint
>>
>> Which kernel version are you running? These useless warning messages
>> were removed in 3.3, ISTR. They're harmless.
>>
>
> This one is a critical error (USB transaction error) and is not removed.
>From top of my head 3.2.11, 3.2.12 but used earlier 3.2.5, 3.2.6, 3.2.9 as well. I always saw
this message as far as I remember.
>
>>> Mar 27 18:10:23 vostro kernel: usb 4-1: reset SuperSpeed USB device number 12 using xhci_hcd
>>> Mar 27 18:10:23 vostro kernel: xhci_hcd 0000:0b:00.0: WARN: short transfer on control ep
>>> Mar 27 18:10:23 vostro kernel: xhci_hcd 0000:0b:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff8800073ff540
>>> Mar 27 18:10:23 vostro kernel: xhci_hcd 0000:0b:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff8800073ff580
>>> Mar 27 18:10:23 vostro kernel: usb 4-1: Successful Endpoint Configure command
>>> Mar 27 18:10:54 vostro kernel: usb 4-1: reset SuperSpeed USB device number 12 using xhci_hcd
>>
>> The usb-storage driver decided to reset the device, for whatever reason.
>> You can enable CONFIG_USB_STORAGE_DEBUG to find out which command caused
>> it to be reset.
>>
>>> Mar 27 18:10:54 vostro kernel: xhci_hcd 0000:0b:00.0: WARN: short transfer on control ep
>>> Mar 27 18:10:54 vostro kernel: xhci_hcd 0000:0b:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff8800073ff540
>>> Mar 27 18:10:54 vostro kernel: xhci_hcd 0000:0b:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff8800073ff580
>>> Mar 27 18:10:54 vostro kernel: usb 4-1: Successful Endpoint Configure command
>>> Mar 27 18:11:04 vostro kernel: usb 4-1: reset SuperSpeed USB device number 12 using xhci_hcd
>>
>> And then it gets reset again, 10 seconds later.
>>
>>> Mar 27 18:11:04 vostro kernel: xhci_hcd 0000:0b:00.0: WARN: short transfer on control ep
>>> Mar 27 18:11:04 vostro kernel: xhci_hcd 0000:0b:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff8800073ff540
>>> Mar 27 18:11:04 vostro kernel: xhci_hcd 0000:0b:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff8800073ff580
>>> Mar 27 18:11:04 vostro kernel: usb 4-1: Successful Endpoint Configure command
>>> Mar 27 18:11:04 vostro kernel: hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0002
>>> Mar 27 18:11:04 vostro kernel: hub 4-0:1.0: warm reset port 1
>>
>> I wonder why you needed to have a warm reset for the port?
>>
>
> I think it's because the link state is SS_INACTIVE after reset.
>
> Thanks,
> Andiry
>
>>> Mar 27 18:11:04 vostro kernel: hub 4-0:1.0: port 1 not warm reset yet, waiting 50ms
>>> Mar 27 18:11:04 vostro kernel: hub 4-0:1.0: port 1 not warm reset yet, waiting 200ms
>>> Mar 27 18:11:04 vostro kernel: hub 4-0:1.0: port 1 not warm reset yet, waiting 200ms
>>
>> Mmm, the warm port reset timed out, which isn't very good. Perhaps your
>> TI host is quirky in that respect?
>>
>>> Mar 27 18:11:05 vostro kernel: hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0002
>>> Mar 27 18:11:06 vostro kernel: hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0002
>>> Mar 27 18:11:06 vostro kernel: hub 4-0:1.0: port 1, status 02a0, change 0001, 5.0 Gb/s
>>> Mar 27 18:11:06 vostro kernel: usb 4-1: USB disconnect, device number 12
>>
>> And then the device disconnected. Sounds like flaky hardware. Maybe if
>> you figure out what SCSI command is failing for the device, we can apply
>> a storage device quirk, and we could avoid having to reset the device.
>>
>>> Mar 27 18:11:06 vostro kernel: usb 4-1: unregistering device
>>> Mar 27 18:11:06 vostro kernel: usb 4-1: unregistering interface 4-1:1.0
>>> Mar 27 18:11:09 vostro kernel: sd 17:0:0:0: Device offlined - not ready after error recovery
>>> Mar 27 18:11:09 vostro kernel: ice sdc1, logical block 204754273
>>> Mar 27 18:11:09 vostro kernel: Buffer I/O error on device sdc1, logical block 204754274
>>> Mar 27 18:11:09 vostro kernel: Buffer I/O error on device sdc1, logical block 204754275
>>> Mar 27 18:11:09 vostro kernel: EXT4-fs warning (device sdc1): ext4_end_bio:244: I/O error writing to inode 51118127 (offset 30695424 size 126976 starting block 204754532)
>>> Mar 27 18:11:09 vostro kernel: Buffer I/O error on device sdc1, logical block 204754276
>>> Mar 27 18:11:09 vostro kernel: Buffer I/O error on device sdc1, logical block 204754277
>>>
>>>
>>> Would anybody please comment whether the logs from xHCI side look sane?
>>
>> It helps if you Cc me (I'm listed in MAINTAINERS as the xHCI driver
>> maintainer). Otherwise the linux-usb mail ends up in another folder and
>> can get ignored for days if I get busy. :)
>>
>>> I have attached the
>>> complete log. From that it looks that mkfs.ext4 caushed the 3.2.12 kernel to complain
>>> with "mount: page allocation failure: order:5, mode:0xd0" but that is another story.
>>> Now I wonder how can I prove the disk is at fault and not the USWB3.0-to-SATAII
>>> bridge or linux kernel. The disk is rather hot (compared to another drive of exactly same
>>> model number) I bought 2 days ago (and which had the newer firmware, and therefore I
>>> went to upgrade the older-one with a tool from seagate website).
>>
>> Can you connect the disk to a desktop box and run the same sort of
>> workload? Connecting it via a USB 2.0 to SATA connector might not be
>> helpful, because if the drive is sensitive to the speed at which it's
>> accessed, then the error might not show up because USB 2.0 is going to
>> be much slower than USB 3.0.
>>
>>> 0b:00.0 USB controller: Texas Instruments Device 8241 (rev 02) (prog-if 30 [XHCI])
>>> Subsystem: Dell Device 04b3
>>> Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
>>> Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
>>> Latency: 0, Cache Line Size: 64 bytes
>>> Interrupt: pin A routed to IRQ 16
>>> Region 0: Memory at f7d00000 (64-bit, non-prefetchable) [size=64K]
>>> Region 2: Memory at f7d10000 (64-bit, non-prefetchable) [size=8K]
>>> Capabilities: [40] Power Management version 3
>>> Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=100mA PME(D0+,D1+,D2+,D3hot+,D3cold+)
>>> Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME-
>>> Capabilities: [48] MSI: Enable- Count=1/8 Maskable- 64bit+
>>> Address: 0000000000000000 Data: 0000
>>> Capabilities: [70] Express (v2) Endpoint, MSI 00
>>> DevCap: MaxPayload 1024 bytes, PhantFunc 0, Latency L0s unlimited, L1 unlimited
>>> ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset-
>>> DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
>>> RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
>>> MaxPayload 128 bytes, MaxReadReq 512 bytes
>>> DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq+ AuxPwr+ TransPend-
>>> LnkCap: Port #0, Speed 5GT/s, Width x1, ASPM L0s L1, Latency L0 <512ns, L1 <64us
>>> ClockPM+ Surprise- LLActRep- BwNot-
>>> LnkCtl: ASPM L1 Enabled; RCB 64 bytes Disabled- Retrain- CommClk+
>>> ExtSynch- ClockPM+ AutWidDis- BWInt- AutBWInt-
>>> LnkSta: Speed 5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
>>> DevCap2: Completion Timeout: Not Supported, TimeoutDis+
>>> DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-
>>> LnkCtl2: Target Link Speed: 5GT/s, EnterCompliance- SpeedDis-, Selectable De-emphasis: -6dB
>>> Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
>>> Compliance De-emphasis: -6dB
>>> LnkSta2: Current De-emphasis Level: -6dB, EqualizationComplete-, EqualizationPhase1-
>>> EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
>>> Capabilities: [c0] MSI-X: Enable+ Count=8 Masked-
>>> Vector table: BAR=2 offset=00000000
>>> PBA: BAR=2 offset=00001000
>>> Capabilities: [100 v2] Advanced Error Reporting
>>> UESta: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
>>> UEMsk: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
>>> UESvrt: DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
>>> CESta: RxErr- BadTLP- BadDLLP+ Rollover- Timeout- NonFatalErr+
>>> CEMsk: RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr+
>>> AERCap: First Error Pointer: 00, GenCap+ CGenEn- ChkCap+ ChkEn-
>>> Capabilities: [150 v1] Device Serial Number 08-00-28-00-00-20-00-00
>>> Kernel driver in use: xhci_hcd
>>
>> Oh, I see. It's a TI host. Yeah, I haven't done much testing on that
>> particular host controller, so I don't know if it works well.
These issues I can reproduce while READING from USB3.0 port next to MIC/OUT of my
soundcard and writing through the USB3.0 socket next to ethernet socket.
So far I haven't had an error with purely reading from the MIC/OUT socket
combined with writes onto internal SATA disk.
Look for some pictures of this Dell Vostro 3550 laptop on the internet.
Mar 31 05:23:46 vostro kernel: usb-storage: *** thread sleeping.
Mar 31 05:23:46 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 05:23:46 vostro kernel: usb-storage: *** thread awakened.
Mar 31 05:23:46 vostro kernel: usb-storage: Command WRITE_10 (10 bytes)
Mar 31 05:23:46 vostro kernel: usb-storage: 2a 00 36 e9 84 f0 00 00 f0 00
Mar 31 05:23:46 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x502c51 L 122880 F 0 Trg 0 LUN 0 CL 10
Mar 31 05:23:46 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 05:23:46 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 05:23:46 vostro kernel: usb-storage: -- transfer complete
Mar 31 05:23:46 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 05:23:46 vostro kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 122880 bytes, 30 entries
Mar 31 05:23:46 vostro kernel: usb-storage: Status code 0; transferred 122880/122880
Mar 31 05:23:46 vostro kernel: usb-storage: -- transfer complete
Mar 31 05:23:46 vostro kernel: usb-storage: Bulk data transfer result 0x0
Mar 31 05:23:46 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 05:23:46 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 05:23:46 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 05:23:46 vostro kernel: usb-storage: -- transfer complete
Mar 31 05:23:46 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 05:23:46 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x502c51 R 0 Stat 0x0
Mar 31 05:23:46 vostro kernel: usb-storage: scsi cmd done, result=0x0
Mar 31 05:23:46 vostro kernel: usb-storage: *** thread sleeping.
Mar 31 05:23:46 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 05:23:46 vostro kernel: usb-storage: *** thread awakened.
Mar 31 05:23:46 vostro kernel: usb-storage: Command WRITE_10 (10 bytes)
Mar 31 05:23:46 vostro kernel: usb-storage: 2a 00 36 e9 85 e0 00 00 f0 00
Mar 31 05:23:46 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x502c52 L 122880 F 0 Trg 0 LUN 0 CL 10
Mar 31 05:23:46 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 05:23:46 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 05:23:46 vostro kernel: usb-storage: -- transfer complete
Mar 31 05:23:46 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 05:23:46 vostro kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 122880 bytes, 30 entries
Mar 31 05:23:46 vostro kernel: usb-storage: Status code -71; transferred 73728/122880
Mar 31 05:23:46 vostro kernel: usb-storage: -- unknown error
Mar 31 05:23:46 vostro kernel: usb-storage: Bulk data transfer result 0x4
Mar 31 05:23:46 vostro kernel: usb-storage: -- transport indicates error, resetting
Mar 31 05:23:46 vostro kernel: usb-storage: usb_stor_pre_reset
Mar 31 05:23:46 vostro kernel: usb 4-1: Successful Endpoint Configure command
Mar 31 05:23:46 vostro kernel: usb-storage: usb_stor_post_reset
Mar 31 05:23:46 vostro kernel: usb-storage: usb_reset_device returns 0
Mar 31 05:23:46 vostro kernel: usb-storage: scsi cmd done, result=0x70000
Mar 31 05:23:46 vostro kernel: usb-storage: *** thread sleeping.
Mar 31 05:23:46 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 05:23:46 vostro kernel: usb-storage: *** thread awakened.
Mar 31 05:23:46 vostro kernel: usb-storage: Command WRITE_10 (10 bytes)
Mar 31 05:23:46 vostro kernel: usb-storage: 2a 00 36 e9 85 e0 00 00 f0 00
Mar 31 05:23:46 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x502c53 L 122880 F 0 Trg 0 LUN 0 CL 10
Mar 31 05:23:46 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 05:23:46 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 05:23:46 vostro kernel: usb-storage: -- transfer complete
Mar 31 05:23:46 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 05:23:46 vostro kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 122880 bytes, 30 entries
Mar 31 05:24:17 vostro kernel: usb-storage: command_abort called
Mar 31 05:24:17 vostro kernel: usb-storage: usb_stor_stop_transport called
Mar 31 05:24:17 vostro kernel: usb-storage: -- cancelling sg request
Mar 31 05:24:17 vostro kernel: usb-storage: Status code -104; transferred 7168/122880
Mar 31 05:24:17 vostro kernel: usb-storage: -- transfer cancelled
Mar 31 05:24:17 vostro kernel: usb-storage: Bulk data transfer result 0x4
Mar 31 05:24:17 vostro kernel: usb-storage: -- command was aborted
Mar 31 05:24:17 vostro kernel: usb-storage: usb_stor_pre_reset
Mar 31 05:24:17 vostro kernel: usb 4-1: Successful Endpoint Configure command
Mar 31 05:24:17 vostro kernel: usb-storage: usb_stor_post_reset
Mar 31 05:24:17 vostro kernel: usb-storage: usb_reset_device returns 0
Mar 31 05:24:17 vostro kernel: usb-storage: scsi command aborted
Mar 31 05:24:17 vostro kernel: usb-storage: *** thread sleeping.
Mar 31 05:24:17 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 05:24:17 vostro kernel: usb-storage: *** thread awakened.
Mar 31 05:24:17 vostro kernel: usb-storage: Command TEST_UNIT_READY (6 bytes)
Mar 31 05:24:17 vostro kernel: usb-storage: 00 00 00 00 00 00
Mar 31 05:24:17 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x502c54 L 0 F 0 Trg 0 LUN 0 CL 6
Mar 31 05:24:17 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 05:24:17 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 05:24:17 vostro kernel: usb-storage: -- transfer complete
Mar 31 05:24:17 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 05:24:17 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 05:24:17 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 05:24:27 vostro kernel: usb-storage: command_abort called
Mar 31 05:24:27 vostro kernel: usb-storage: usb_stor_stop_transport called
Mar 31 05:24:27 vostro kernel: usb-storage: -- cancelling URB
Mar 31 05:24:27 vostro kernel: usb-storage: Status code -104; transferred 0/13
Mar 31 05:24:27 vostro kernel: usb-storage: -- transfer cancelled
Mar 31 05:24:27 vostro kernel: usb-storage: Bulk status result = 4
Mar 31 05:24:27 vostro kernel: usb-storage: -- command was aborted
Mar 31 05:24:27 vostro kernel: usb-storage: usb_stor_pre_reset
Mar 31 05:24:27 vostro kernel: usb 4-1: Successful Endpoint Configure command
Mar 31 05:24:27 vostro kernel: usb-storage: usb_stor_post_reset
Mar 31 05:24:27 vostro kernel: usb-storage: usb_reset_device returns 0
Mar 31 05:24:27 vostro kernel: usb-storage: scsi command aborted
Mar 31 05:24:27 vostro kernel: usb-storage: *** thread sleeping.
Mar 31 05:24:27 vostro kernel: usb-storage: device_reset called
Mar 31 05:24:27 vostro kernel: usb-storage: usb_stor_Bulk_reset called
Mar 31 05:24:27 vostro kernel: usb-storage: usb_stor_control_msg: rq=ff rqtype=21 value=0000 index=00 len=0
Mar 31 05:24:27 vostro kernel: hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0002
Mar 31 05:24:27 vostro kernel: hub 4-0:1.0: warm reset port 1
Mar 31 05:24:27 vostro kernel: hub 4-0:1.0: port 1 not warm reset yet, waiting 50ms
Mar 31 05:24:27 vostro kernel: hub 4-0:1.0: port 1 not warm reset yet, waiting 200ms
Mar 31 05:24:28 vostro kernel: hub 4-0:1.0: port 1 not warm reset yet, waiting 200ms
Mar 31 05:24:28 vostro kernel: hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0002
Mar 31 05:24:29 vostro kernel: hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0002
Mar 31 05:24:29 vostro kernel: hub 4-0:1.0: port 1, status 02a0, change 0001, 5.0 Gb/s
Mar 31 05:24:29 vostro kernel: usb 4-1: unregistering device
Mar 31 05:24:29 vostro kernel: usb 4-1: unregistering interface 4-1:1.0
Mar 31 05:24:29 vostro kernel: usb-storage: storage_disconnect() called
Mar 31 05:24:32 vostro kernel: usb-storage: Timeout -- cancelling URB
Mar 31 05:24:32 vostro kernel: usb-storage: Soft reset failed: -2
Mar 31 05:24:32 vostro kernel: usb-storage: bus_reset called
Mar 31 05:24:32 vostro kernel: usb-storage: unable to lock device for reset: -19
Mar 31 05:24:32 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 05:24:32 vostro kernel: usb-storage: Fail command during disconnect
Mar 31 05:24:32 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 05:24:32 vostro kernel: usb-storage: Fail command during disconnect
Mar 31 05:24:33 vostro kernel: usb-storage: -- usb_stor_release_resources
Mar 31 05:24:33 vostro kernel: usb-storage: -- sending exit command to thread
Mar 31 05:24:33 vostro kernel: usb-storage: *** thread awakened.
Mar 31 05:24:33 vostro kernel: usb-storage: -- exiting
Mar 31 05:24:33 vostro kernel: usb-storage: -- dissociate_dev
Mar 31 05:24:33 vostro kernel: usb 4-1: usb_disable_device nuking all URBs
Mar 31 05:24:33 vostro kernel: usb 4-1: Successful Endpoint Configure command
Mar 31 05:24:34 vostro kernel: hub 4-0:1.0: debounce: port 1: total 100ms stable 100ms status 0x2a0
Mar 31 05:24:36 vostro kernel: hub 4-0:1.0: hub_suspend
Mar 31 05:24:36 vostro kernel: usb usb4: bus auto-suspend, wakeup 1
here I have NOT deleted any single line from the /var/log/debug file.
At about 05:23:46 the testing "cp -rp /local/sata/blah /mnt/usb30_on_TI_chipset_next_to_eth_socket" crashed.
At about 08:57 I came to the computer.
Mar 31 08:57:25 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread awakened.
Mar 31 08:57:25 vostro kernel: usb-storage: Command TEST_UNIT_READY (6 bytes)
Mar 31 08:57:25 vostro kernel: usb-storage: 00 00 00 00 00 00
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x16 L 0 F 0 Trg 0 LUN 0 CL 6
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x16 R 0 Stat 0x1
Mar 31 08:57:25 vostro kernel: usb-storage: -- transport indicates command failure
Mar 31 08:57:25 vostro kernel: usb-storage: Issuing auto-REQUEST_SENSE
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x17 L 18 F 128 Trg 0 LUN 0 CL 6
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 18 bytes, 1 entries
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 18/18
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk data transfer result 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x17 R 0 Stat 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: -- Result from auto-sense is 0
Mar 31 08:57:25 vostro kernel: usb-storage: -- code: 0x70, key: 0x2, ASC: 0x3a, ASCQ: 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Not Ready: Medium not present
Mar 31 08:57:25 vostro kernel: usb-storage: scsi cmd done, result=0x2
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread sleeping.
Mar 31 08:57:25 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread awakened.
Mar 31 08:57:25 vostro kernel: usb-storage: Command ALLOW_MEDIUM_REMOVAL (6 bytes)
Mar 31 08:57:25 vostro kernel: usb-storage: 1e 00 00 00 01 00
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x18 L 0 F 0 Trg 0 LUN 0 CL 6
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x18 R 0 Stat 0x1
Mar 31 08:57:25 vostro kernel: usb-storage: -- transport indicates command failure
Mar 31 08:57:25 vostro kernel: usb-storage: Issuing auto-REQUEST_SENSE
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x19 L 18 F 128 Trg 0 LUN 0 CL 6
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 18 bytes, 1 entries
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 18/18
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk data transfer result 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x19 R 0 Stat 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: -- Result from auto-sense is 0
Mar 31 08:57:25 vostro kernel: usb-storage: -- code: 0x70, key: 0x5, ASC: 0x24, ASCQ: 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Illegal Request: Invalid field in cdb
Mar 31 08:57:25 vostro kernel: usb-storage: scsi cmd done, result=0x2
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread sleeping.
Mar 31 08:57:25 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread awakened.
Mar 31 08:57:25 vostro kernel: usb-storage: Command (unknown command) (16 bytes)
Mar 31 08:57:25 vostro kernel: usb-storage: 85 06 20 00 05 00 fe 00 00 00 00 00 00 40 ef 00
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x1a L 0 F 0 Trg 0 LUN 0 CL 16
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x1a R 0 Stat 0x1
Mar 31 08:57:25 vostro kernel: usb-storage: -- transport indicates command failure
Mar 31 08:57:25 vostro kernel: usb-storage: Issuing auto-REQUEST_SENSE
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x1b L 18 F 128 Trg 0 LUN 0 CL 6
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 18 bytes, 1 entries
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 18/18
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk data transfer result 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x1b R 0 Stat 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: -- Result from auto-sense is 0
Mar 31 08:57:25 vostro kernel: usb-storage: -- code: 0x70, key: 0x5, ASC: 0x24, ASCQ: 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Illegal Request: Invalid field in cdb
Mar 31 08:57:25 vostro kernel: usb-storage: scsi cmd done, result=0x2
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread sleeping.
Mar 31 08:57:25 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread awakened.
Mar 31 08:57:25 vostro kernel: usb-storage: Command (unknown command) (16 bytes)
Mar 31 08:57:25 vostro kernel: usb-storage: 85 06 20 00 c2 00 00 00 00 00 00 00 00 40 ef 00
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x1c L 0 F 0 Trg 0 LUN 0 CL 16
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x1c R 0 Stat 0x1
Mar 31 08:57:25 vostro kernel: usb-storage: -- transport indicates command failure
Mar 31 08:57:25 vostro kernel: usb-storage: Issuing auto-REQUEST_SENSE
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x1d L 18 F 128 Trg 0 LUN 0 CL 6
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 18 bytes, 1 entries
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 18/18
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk data transfer result 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x1d R 0 Stat 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: -- Result from auto-sense is 0
Mar 31 08:57:25 vostro kernel: usb-storage: -- code: 0x70, key: 0x5, ASC: 0x24, ASCQ: 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Illegal Request: Invalid field in cdb
Mar 31 08:57:25 vostro kernel: usb-storage: scsi cmd done, result=0x2
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread sleeping.
Mar 31 08:57:25 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread awakened.
Mar 31 08:57:25 vostro kernel: usb-storage: Command (unknown command) (16 bytes)
Mar 31 08:57:25 vostro kernel: usb-storage: 85 06 20 00 02 00 00 00 00 00 00 00 00 40 ef 00
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x1e L 0 F 0 Trg 0 LUN 0 CL 16
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x1e R 0 Stat 0x1
Mar 31 08:57:25 vostro kernel: usb-storage: -- transport indicates command failure
Mar 31 08:57:25 vostro kernel: usb-storage: Issuing auto-REQUEST_SENSE
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x1f L 18 F 128 Trg 0 LUN 0 CL 6
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 18 bytes, 1 entries
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 18/18
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk data transfer result 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x1f R 0 Stat 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: -- Result from auto-sense is 0
Mar 31 08:57:25 vostro kernel: usb-storage: -- code: 0x70, key: 0x5, ASC: 0x24, ASCQ: 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Illegal Request: Invalid field in cdb
Mar 31 08:57:25 vostro kernel: usb-storage: scsi cmd done, result=0x2
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread sleeping.
Mar 31 08:57:25 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread awakened.
Mar 31 08:57:25 vostro kernel: usb-storage: Command (unknown command) (16 bytes)
Mar 31 08:57:25 vostro kernel: usb-storage: 85 06 20 00 00 00 00 00 00 00 00 00 00 40 e3 00
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x20 L 0 F 0 Trg 0 LUN 0 CL 16
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x20 R 0 Stat 0x1
Mar 31 08:57:25 vostro kernel: usb-storage: -- transport indicates command failure
Mar 31 08:57:25 vostro kernel: usb-storage: Issuing auto-REQUEST_SENSE
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x21 L 18 F 128 Trg 0 LUN 0 CL 6
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 18 bytes, 1 entries
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 18/18
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk data transfer result 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x21 R 0 Stat 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: -- Result from auto-sense is 0
Mar 31 08:57:25 vostro kernel: usb-storage: -- code: 0x70, key: 0x5, ASC: 0x24, ASCQ: 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Illegal Request: Invalid field in cdb
Mar 31 08:57:25 vostro kernel: usb-storage: scsi cmd done, result=0x2
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread sleeping.
Mar 31 08:57:25 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread awakened.
Mar 31 08:57:25 vostro kernel: usb-storage: Command (unknown command) (16 bytes)
Mar 31 08:57:25 vostro kernel: usb-storage: 85 08 0e 00 00 00 01 00 00 00 00 00 00 40 ec 00
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x22 L 512 F 128 Trg 0 LUN 0 CL 16
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 512 bytes, 1 entries
Mar 31 08:57:25 vostro kernel: usb-storage: Status code -32; transferred 0/512
Mar 31 08:57:25 vostro kernel: usb-storage: clearing endpoint halt for pipe 0xc0010580
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=82 len=0
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_clear_halt: result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk data transfer result 0x2
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x22 R 0 Stat 0x1
Mar 31 08:57:25 vostro kernel: usb-storage: -- transport indicates command failure
Mar 31 08:57:25 vostro kernel: usb-storage: -- unexpectedly short transfer
Mar 31 08:57:25 vostro kernel: usb-storage: Issuing auto-REQUEST_SENSE
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x23 L 18 F 128 Trg 0 LUN 0 CL 6
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 18 bytes, 1 entries
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 18/18
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk data transfer result 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x23 R 0 Stat 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: -- Result from auto-sense is 0
Mar 31 08:57:25 vostro kernel: usb-storage: -- code: 0x70, key: 0x5, ASC: 0x24, ASCQ: 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Illegal Request: Invalid field in cdb
Mar 31 08:57:25 vostro kernel: usb-storage: scsi cmd done, result=0x2
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread sleeping.
Mar 31 08:57:25 vostro kernel: usb-storage: queuecommand_lck called
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread awakened.
Mar 31 08:57:25 vostro kernel: usb-storage: Command TEST_UNIT_READY (6 bytes)
Mar 31 08:57:25 vostro kernel: usb-storage: 00 00 00 00 00 00
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x24 L 0 F 0 Trg 0 LUN 0 CL 6
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x24 R 0 Stat 0x1
Mar 31 08:57:25 vostro kernel: usb-storage: -- transport indicates command failure
Mar 31 08:57:25 vostro kernel: usb-storage: Issuing auto-REQUEST_SENSE
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Command S 0x43425355 T 0x25 L 18 F 128 Trg 0 LUN 0 CL 6
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 31/31
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk command transfer result=0
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 18 bytes, 1 entries
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 18/18
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk data transfer result 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Attempting to get CSW...
Mar 31 08:57:25 vostro kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Mar 31 08:57:25 vostro kernel: usb-storage: Status code 0; transferred 13/13
Mar 31 08:57:25 vostro kernel: usb-storage: -- transfer complete
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk status result = 0
Mar 31 08:57:25 vostro kernel: usb-storage: Bulk Status S 0x53425355 T 0x25 R 0 Stat 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: -- Result from auto-sense is 0
Mar 31 08:57:25 vostro kernel: usb-storage: -- code: 0x70, key: 0x2, ASC: 0x3a, ASCQ: 0x0
Mar 31 08:57:25 vostro kernel: usb-storage: Not Ready: Medium not present
Mar 31 08:57:25 vostro kernel: usb-storage: scsi cmd done, result=0x2
Mar 31 08:57:25 vostro kernel: usb-storage: *** thread sleeping.
The debug messages from USB_STORAGE behave weird. First of all, it seems
some hex numbers are written without any formwatting into my virtual console on Alt+Fn12, but their
collide with the formatting of the other messages.
Second, time to time a message from USB_STORAGE debug slips on my currently active
virtual console:
<7>usb-storage: 2a 00 08 c5 e6 f0 00 00 f0 00<7>usb-storage: 8a 00 00 00 00 01 4a 9d 14 60 00 00 00 f0 00 00<7>usb-storage: 2a 00 0a 3e cd a0 00 00 f0 00<7>usb-storage: 2a 00 0c 48 ab a0 00 00 f0 00<7>usb-storage: 8a 00 00 00 00 01 55 47 87 50 00 00 00 f0 00 00<7>usb-storage: 2a 00 0c e9 c4 f0 00 00 f0 00<7>usb-storage: 2a 00 10 1f df 70 00 00 f0 00<7>usb-storage: 2a 00 10 32 e0 60 00 00 f0 00<7>usb-storage: 2a 00 10 8a a9 c0 00 00 f0 00<7>usb-storage: 8a 00 00 00 00 01 59 19 3f a8 00 00 00 f0 00 00<7>usb-storage: 2a 00 15 78 6e 70 00 00 f0 00<7>usb-storage: 2a 00 91 01 05 30 00 00 f0 00<7>usb-storage: 2a 00 93 40 48 00 00 00 f0 00<7>usb-storage: 2a 00 18 93 02 20 00 00 f0 00<7>usb-storage: 2a 00 18 de 08 00 00 00 f0 00<7>usb-storage: 2a 00 1c 0c 94 30 00 00 f0 00<7>usb-storage: 2a 00 1d 06 78 c0 00 00 f0 00<7>usb-storage: 2a 00 1d 6f ea b0 00 00 f0 00<7>usb-storage: 2a 00 20 f9 8f 80 00 00 f0 00<7>usb-storage: 2a 00 22 e2 cf 80 00 00 f0 00<7>usb-storage: 2a 00 e0
80 a8 f0 00 00 10 00<7>usb-storage: 2a 00 2e 48 08 f0 00 00 f0 00<7>usb-storage: 2a 00 2b 87 ef 60 00 00 f0 00<7>usb-storage: 2a 00 2b 94 88 00 00 00 f0 00<7>usb-storage: 2a 00 2b b7 21
50 00 00 f0 00<7>usb-storage: 2a 00 32 f7 ce 90 00 00 f0 00<7>usb-storage: 8a 00 00 00 00 01 28 00 89 00 00 00 00 f0 00 00<7>usb-storage: 2a 00 36 1f da c0 00 00 f0 00<7>usb-storage: 2a 00 36 ca c7 c0 00 00 40 00Mar
Interestingly, these pairs of numbers are show in syslog ONLY if I read from the
USB3.0 socket using
"cp -rp /mnt/disk_on_the_TI_chipset_in_socket_next_to_MIC_and_OUT/blah /mnt/usb30_on_TI_chipset_next_to_eth_socket".
After I realized I do NOT trigger most of these messages when reading from an
INTERNAL SATA disk, I used that to trigger the crash while having relatively sane logs
Third, this is an authentic mess from /var/log/messages:
Mar 31 03:11:44 vostro syslogd 1.5.0: restart.
Mar 31 03:11:45 vostro kernel: klogd 1.5.0, ---------- state change ----------
Mar 31 03:11:45 vostro kernel: Loaded 71886 symbols from 4 modules.
Mar 31 03:14:55 vostro kernel: read sleeping.
Mar 31 03:20:24 vostro kernel: d done, result=0x0
Mar 31 03:21:09 vostro kernel: age: -- transfer complete
Mar 31 03:21:09 vostro kernel: <7usb-storage: *** thread awakened.
Mar 31 03:22:24 vostro kernel: storage: queuecommand_lck called
Mar 31 03:22:56 vostro kernel: r_sglist: xfer 122880 bytes, 12 entries
Mar 31 03:30:01 vostro kernel: tor_bulk_transfer_sglist: xfer 122880 bytes, 25 entries
Mar 31 03:31:30 vostro kernel: <7e 0; transferred 122880/122880
Mar 31 03:35:26 vostro kernel: 7>usb-storage: Bulk Status S 0x53425355 T 0x171c15 R 0 Stat 0x0
Mar 31 03:35:29 vostro kernel: HDMI hot plug event: Codec=3 Pin=5 Presence_Detect=0 ELD_Valid=1
Mar 31 03:35:29 vostro kernel: HDMI status: Codec=3 Pin=5 Presence_Detect=0 ELD_Valid=0
Mar 31 03:39:28 vostro kernel: tor_bulk_transfer_buf: xfer 31 bytes
Mar 31 03:39:49 vostro kernel: age: queuecommand_lck called
Mar 31 03:40:53 vostro kernel: <orage: scsi cmd done, result=0x0
Mar 31 03:45:10 vostro kernel: ueuecommand_lck called
Mar 31 03:47:16 vostro kernel: >usb-storage: Bulk Status S 0x53425355 T 0x1c7f81 R 0 Stat 0x0
Mar 31 03:50:41 vostro kernel: transfer result 0x0
Mar 31 03:51:13 vostro kernel: 122880 bytes, 23 entries
Mar 31 03:52:54 vostro kernel: <age: Status code 0; transferred 13/13
Mar 31 03:52:59 vostro kernel: <g.
Mar 31 03:52:59 vostro kernel: age: *** thread sleeping.
Mar 31 03:52:59 vostro kernel: <7lk Command S 0x43425355 T 0x1f2e1a L 122880 F 0 Trg 0 LUN 0 CL 16
Mar 31 03:53:21 vostro kernel: transferred 122880/122880
Mar 31 03:53:23 vostro kernel: <7nsfer_sglist: xfer 122880 bytes, 18 entries
Mar 31 03:53:24 vostro kernel: <7 xfer 122880 bytes, 30 entries
Mar 31 03:55:19 vostro kernel: t: xfer 122880 bytes, 30 entries
Mar 31 03:56:49 vostro kernel: esult=0x0
Mar 31 03:57:02 vostro kernel: torage: -- transfer complete
Mar 31 03:59:33 vostro kernel: xfer 122880 bytes, 30 entries
Mar 31 04:02:21 vostro kernel: <ommand) (16 bytes)
Mar 31 04:02:35 vostro kernel: storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Mar 31 04:08:19 vostro kernel: ulk_transfer_sglist: xfer 122880 bytes, 30 entries
Mar 31 04:08:27 vostro kernel: er_sglist: xfer 122880 bytes, 27 entries
Mar 31 04:08:32 vostro kernel: <: xfer 122880 bytes, 26 entries
Mar 31 04:11:20 vostro kernel: _bulk_transfer_buf: xfer 13 bytes
Mar 31 04:11:49 vostro kernel: 22880 bytes, 30 entries
Mar 31 04:20:05 vostro syslogd 1.5.0: restart.
Mar 31 04:20:06 vostro kernel: klogd 1.5.0, ---------- state change ----------
Mar 31 04:20:06 vostro kernel: Loaded 71886 symbols from 4 modules.
Mar 31 04:26:47 vostro kernel: >usb-storage: *** thread sleeping.
Mar 31 04:27:24 vostro kernel: <7sglist: xfer 122880 bytes, 30 entries
Mar 31 04:30:43 vostro kernel: sglist: xfer 122880 bytes, 29 entries
Mar 31 04:30:50 vostro kernel: 0
Mar 31 04:33:17 vostro kernel: lt=0x0
Mar 31 04:35:35 vostro kernel: done, result=0x0
Mar 31 04:39:11 vostro kernel: bytes)
Mar 31 04:40:42 vostro kernel: _bulk_transfer_sglist: xfer 122880 bytes, 20 entries
Mar 31 04:45:36 vostro kernel: <743425355 T 0x3b4833 L 122880 F 0 Trg 0 LUN 0 CL 16
Mar 31 04:48:50 vostro kernel: list: xfer 122880 bytes, 15 entries
Mar 31 05:06:45 vostro kernel: 122880 bytes, 20 entries
Mar 31 05:13:34 vostro kernel: 122880 bytes, 30 entries
Mar 31 05:14:31 vostro kernel: >usb-storage: queuecommand_lck called
Mar 31 05:16:42 vostro kernel: done, result=0x0
Mar 31 05:20:48 vostro kernel: < 122880 bytes, 18 entries
Mar 31 05:23:46 vostro kernel: xhci_hcd 0000:0b:00.0: WARN: transfer error on endpoint
Mar 31 05:23:46 vostro kernel: usb 4-1: reset SuperSpeed USB device number 5 using xhci_hcd
Mar 31 05:23:46 vostro kernel: xhci_hcd 0000:0b:00.0: WARN: short transfer on control ep
Mar 31 05:23:46 vostro kernel: xhci_hcd 0000:0b:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff88040db13bc0
Mar 31 05:23:46 vostro kernel: xhci_hcd 0000:0b:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff88040db13c00
Mar 31 05:24:17 vostro kernel: usb 4-1: reset SuperSpeed USB device number 5 using xhci_hcd
Mar 31 05:24:17 vostro kernel: xhci_hcd 0000:0b:00.0: WARN: short transfer on control ep
Mar 31 05:24:17 vostro kernel: xhci_hcd 0000:0b:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff88040db13bc0
Mar 31 05:24:17 vostro kernel: xhci_hcd 0000:0b:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff88040db13c00
Mar 31 05:24:27 vostro kernel: usb 4-1: reset SuperSpeed USB device number 5 using xhci_hcd
Mar 31 05:24:27 vostro kernel: xhci_hcd 0000:0b:00.0: WARN: short transfer on control ep
Mar 31 05:24:27 vostro kernel: xhci_hcd 0000:0b:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff88040db13bc0
Mar 31 05:24:27 vostro kernel: xhci_hcd 0000:0b:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff88040db13c00
Mar 31 05:24:29 vostro kernel: usb 4-1: USB disconnect, device number 5
Mar 31 05:24:32 vostro kernel: sd 8:0:0:0: Device offlined - not ready after error recovery
Mar 31 05:24:32 vostro kernel: sd 8:0:0:0: [sdd] Unhandled error code
Mar 31 05:24:32 vostro kernel: sd 8:0:0:0: [sdd] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK
Mar 31 05:24:32 vostro kernel: sd 8:0:0:0: [sdd] CDB: Write(10): 2a 00 36 e9 85 e0 00 00 f0 00
Mar 31 05:24:32 vostro kernel: EXT4-fs warning (device sdd1): ext4_end_bio:244: I/O error writing to inode 28181277 (offset 8110080 size 126976 starting block 115159258)
Mar 31 05:24:32 vostro kernel: EXT4-fs warning (device sdd1): ext4_end_bio:244: I/O error writing to inode 28181274 (offset 5529600 size 126976 starting block 113256070)
Mar 31 05:24:32 vostro kernel: EXT4-fs warning (device sdd1): ext4_end_bio:244: I/O error writing to inode 28181274 (offset 5652480 size 126976 starting block 113256100)
Mar 31 05:24:32 vostro kernel: EXT4-fs warning (device sdd1): ext4_end_bio:244: I/O error writing to inode 28181274 (offset 5775360 size 126976 starting block 113256130)
Mar 31 05:24:32 vostro kernel: EXT4-fs warning (device sdd1): ext4_end_bio:244: I/O error writing to inode 28181274 (offset 5898240 size 126976 starting block 113256160)
Mar 31 05:24:32 vostro kernel: EXT4-fs warning (device sdd1): ext4_end_bio:244: I/O error writing to inode 28181274 (offset 6021120 size 126976 starting block 113256190)
Here is how I "watched for the error":
# tail -f /var/log/debug | grep -i error
Mar 31 05:23:46 vostro kernel: usb-storage: -- unknown error
Mar 31 05:23:46 vostro kernel: usb-storage: -- transport indicates error, resetting
EXT4-fs error (device sdd1): ext4_journal_start_sb:327: Detected aborted journal
EXT4-fs error (device sdd1) in ext4_da_writepages:2298: IO failure
EXT4-fs error (device sdd1): ext4_journal_start_sb:327: Detected aborted journal
EXT4-fs (sdd1): Remounting filesystem read-only
EXT4-fs (sdd1): ext4_da_writepages: jbd2_start: 9223372036854773759 pages, ino 28181295; err -30
journal commit I/O error
EXT4-fs error (device sdd1): ext4_find_entry:935: inode #172490753: comm cp: reading directory lblock 0
journal commit I/O error
journal commit I/O error
journal commit I/O error
journal commit I/O error
journal commit I/O error
^C
Thanks for clues,
Martin
P.S.: I copied away /var/log/{messages,debug,kern}.log as well as messages after fresh
bootup if you want to have a better overview of all the detected devices.
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
