Hi,
I've been looking at the sense stuff coming from a resumed device.
And this stuff makes no sense (no pun intended)
ffff8800b1b7eb00 575486975 S Ci:2:001:0 s a3 00 0000 0001 0004 4 <
ffff8800b1b7eb00 575487256 C Ci:2:001:0 0 4 = 00010000
ffff8800b1b7eb00 575487272 S Ci:2:001:0 s a3 00 0000 0002 0004 4 <
ffff8800b1b7eb00 575487277 C Ci:2:001:0 0 4 = 00010000
ffff8800b1b7eb00 575487282 S Ci:2:001:0 s a3 00 0000 0003 0004 4 <
ffff8800b1b7eb00 575487287 C Ci:2:001:0 0 4 = 00010000
ffff8800b1b7eb00 575487292 S Ci:2:001:0 s a3 00 0000 0004 0004 4 <
ffff8800b1b7eb00 575487296 C Ci:2:001:0 0 4 = 07050000
ffff8800b1b7eb00 575487305 S Ci:2:001:0 s a3 00 0000 0005 0004 4 <
ffff8800b1b7eb00 575487309 C Ci:2:001:0 0 4 = 07050000
ffff8800b1b7eb00 575487316 S Ci:2:001:0 s a3 00 0000 0006 0004 4 <
ffff8800b1b7eb00 575487321 C Ci:2:001:0 0 4 = 00010000
ffff880135e3c200 575487356 S Ii:2:001:1 -115:2048 4 <
ffff8800b1b7eb00 575487482 S Ci:2:001:0 s a3 00 0000 0004 0004 4 <
ffff8800b1b7eb00 575487534 C Ci:2:001:0 0 4 = 07050000
ffff8800b1b7eb00 575487579 S Co:2:001:0 s 23 01 0002 0004 0000 0
ffff8800b1b7eb00 575487655 C Co:2:001:0 0 0
ffff8800b1b7eb00 575518894 S Ci:2:001:0 s a3 00 0000 0004 0004 4 <
ffff8800b1b7eb00 575519024 C Ci:2:001:0 0 4 = 03050400
ffff8800b1b7eb00 575534873 S Co:2:001:0 s 23 01 0012 0004 0000 0
ffff8800b1b7eb00 575534881 C Co:2:001:0 0 0
ffff8800b1b7eb00 575534907 S Ci:2:003:0 s 80 00 0000 0000 0002 2 <
ffff8800b1b7eb00 575535188 C Ci:2:003:0 0 2 = 0000
ffff88010e685440 575535314 S Bo:2:003:1 -115 31 = 55534243 63000000 00020000 80000a28 00000000 ea000001 00000000 000000
ffff88010e685440 575535399 C Bo:2:003:1 0 31 >
So the trace shows that everything is woken and the first command goes out:
Feb 23 15:58:41 vanamonde kernel: usb 2-4: finish resume
Feb 23 15:58:41 vanamonde kernel: usb-storage: usb_stor_resume
Feb 23 15:58:41 vanamonde kernel: usb-storage: Command READ_10 (10 bytes)
Feb 23 15:58:41 vanamonde kernel: usb-storage: 28 00 00 00 00 ea 00 00 01 00
Feb 23 15:58:41 vanamonde kernel: usb-storage: Bulk Command S 0x43425355 T 0x63 L 512 F 128 Trg 0 LUN 0 CL 10
Feb 23 15:58:41 vanamonde kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Feb 23 15:58:41 vanamonde kernel: usb-storage: Status code 0; transferred 31/31
Feb 23 15:58:41 vanamonde kernel: usb-storage: -- transfer complete
Then the data stage stalls
ffff8800b1b7eb00 575535443 S Bi:2:003:2 -115 512 <
ffff8800b1b7eb00 575750560 C Bi:2:003:2 -32 0
ffff88010e685440 575750638 S Co:2:003:0 s 02 01 0000 0082 0000 0
ffff88010e685440 575750932 C Co:2:003:0 0 0
Feb 23 15:58:41 vanamonde kernel: usb-storage: Bulk command transfer result=0
Feb 23 15:58:41 vanamonde kernel: usb-storage: usb_stor_bulk_transfer_sglist: xfer 512 bytes, 1 entries
Feb 23 15:58:41 vanamonde kernel: usb-storage: Status code -32; transferred 0/512
Feb 23 15:58:41 vanamonde kernel: usb-storage: clearing endpoint halt for pipe 0xc0010380
Feb 23 15:58:41 vanamonde kernel: usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=82 len=0
Feb 23 15:58:41 vanamonde kernel: usb-storage: usb_stor_clear_halt: result = 0
but the halt is cleared.
Feb 23 15:58:41 vanamonde kernel: usb-storage: Bulk data transfer result 0x2
Feb 23 15:58:41 vanamonde kernel: usb-storage: Attempting to get CSW...
Feb 23 15:58:41 vanamonde kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 13 bytes
Feb 23 15:58:41 vanamonde kernel: usb-storage: Status code 0; transferred 13/13
Feb 23 15:58:41 vanamonde kernel: usb-storage: -- transfer complete
Feb 23 15:58:41 vanamonde kernel: usb-storage: Bulk status result = 0
Feb 23 15:58:41 vanamonde kernel: usb-storage: Bulk Status S 0x53425355 T 0x63 R 512 Stat 0x1
Feb 23 15:58:41 vanamonde kernel: usb-storage: -- transport indicates command failure
Feb 23 15:58:41 vanamonde kernel: usb-storage: -- unexpectedly short transfer
Feb 23 15:58:41 vanamonde kernel: usb-storage: Issuing auto-REQUEST_SENSE
Feb 23 15:58:41 vanamonde kernel: usb-storage: Bulk Command S 0x43425355 T 0x64 L 18 F 128 Trg 0 LUN 0 CL 6
Feb 23 15:58:41 vanamonde kernel: usb-storage: usb_stor_bulk_transfer_buf: xfer 31 bytes
Feb 23 15:58:41 vanamonde kernel: usb-storage: Status code 0; transferred 31/31
Feb 23 15:58:41 vanamonde kernel: usb-storage: -- transfer complete
ffff88010e685440 575751499 S Bo:2:003:1 -115 31 = 55534243 64000000 12000000 80000603 00000012 00000000 00000000 000000
ffff88010e685440 575751653 C Bo:2:003:1 0 31 >
ffff8800b1b7eb00 575751789 S Bi:2:003:2 -115 18 <
ffff8800b1b7eb00 575751921 C Bi:2:003:2 0 18 = 00000000 00000000 00000000 00000000 0000
Autosense is done.
Up to now everything was normal. An error had occured but was handled.
But now the device returns a sense buffer of all zeros.
Feb 23 15:58:41 vanamonde kernel: usb-storage: Bulk Status S 0x53425355 T 0x64 R 0 Stat 0x0
Feb 23 15:58:41 vanamonde kernel: usb-storage: -- Result from auto-sense is 0
Feb 23 15:58:41 vanamonde kernel: usb-storage: -- code: 0xf0, key: 0x6, ASC: 0x28, ASCQ: 0x0
Feb 23 15:58:41 vanamonde kernel: usb-storage: Unit Attention: Not ready to ready change, medium may have changed
Feb 23 15:58:41 vanamonde kernel: usb-storage: scsi cmd done, result=0x2
But the storage driver reports something else entirely.
The device transparent SCSI, Bulk only:
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 0
bNumEndpoints 2
bInterfaceClass 8 Mass Storage
bInterfaceSubClass 6 SCSI
bInterfaceProtocol 80 Bulk (Zip)
So usb_stor_transparent_scsi_command -> usb_stor_invoke_transport -> usb_stor_Bulk_transport.
And the actual sensebuffer is stated:
US_DEBUGP("-- Result from auto-sense is %d\n", temp_result);
US_DEBUGP("-- code: 0x%x, key: 0x%x, ASC: 0x%x, ASCQ: 0x%x\n",
srb->sense_buffer[0],
srb->sense_buffer[2] & 0xf,
srb->sense_buffer[12],
srb->sense_buffer[13]);
Somebody please tell me what I am overlooking.
Regards
Oliver
--
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
