Interesting.... most interesting is this line: > usb-storage: usb_stor_bulk_msg() returned 0 xferred 0/512
This means an URB was submitted and (apparently) completed without error, but also without transferring all the data. I don't think that is supposed to be possible. This looks like an HCD bug to me... Matt On Thu, Apr 29, 2004 at 08:29:38PM -0700, Philippe Troin wrote: > [ Please CC me since I am not subscribed, thanks! ] > > Hi Matthew (& others), > > I was experimenting with an iRiver H120 and usb-storage with a vanilla > 2.4.26 kernel, I am getting some random I/O errors... By random I mean > that retrying the copy on the faulty file works. > > These are the kernel messages issued for the I/O error: > > USB Mass Storage device found at 18 > SCSI disk error : host 1 channel 0 id 0 lun 0 return code = 8000000 > Current sd08:21: sense key None > I/O error: dev 08:21, sector 2225382 > > After recompiling with debug message, here are the messages before the > error: > > usb-storage: queuecommand() called > usb-storage: *** thread awakened. > usb-storage: Command READ_10 (10 bytes) > usb-storage: 28 00 01 e5 1f 5c 00 00 01 00 00 00 > usb-storage: Bulk command S 0x43425355 T 0x944 Trg 0 LUN 0 L 512 F 128 CL 10 > usb-storage: Bulk command transfer result=0 > usb-storage: usb_stor_transfer_partial(): xfer 512 bytes > usb-storage: usb_stor_bulk_msg() returned 0 xferred 512/512 > usb-storage: usb_stor_transfer_partial(): transfer complete > usb-storage: Bulk data transfer result 0x0 > usb-storage: Attempting to get CSW... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x944 R 0 Stat 0x0 > usb-storage: scsi cmd done, result=0x0 > usb-storage: *** thread sleeping. > usb-storage: queuecommand() called > usb-storage: *** thread awakened. > usb-storage: Command READ_10 (10 bytes) > usb-storage: 28 00 00 a3 e9 21 00 00 01 00 00 00 > usb-storage: Bulk command S 0x43425355 T 0x945 Trg 0 LUN 0 L 512 F 128 CL 10 > usb-storage: Bulk command transfer result=0 > usb-storage: usb_stor_transfer_partial(): xfer 512 bytes > usb-storage: usb_stor_bulk_msg() returned 0 xferred 0/512 > usb-storage: Bulk data transfer result 0x1 > usb-storage: Attempting to get CSW... > usb-storage: clearing endpoint halt for pipe 0xc0011e80 > usb-storage: usb_stor_clear_halt: result=0 > usb-storage: Attempting to get CSW (2nd try)... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x945 R 512 Stat 0x0 > usb-storage: -- unexpectedly short transfer > usb-storage: Issuing auto-REQUEST_SENSE > usb-storage: Bulk command S 0x43425355 T 0x946 Trg 0 LUN 0 L 18 F 128 CL 6 > usb-storage: Bulk command transfer result=0 > usb-storage: usb_stor_transfer_partial(): xfer 18 bytes > usb-storage: usb_stor_bulk_msg() returned 0 xferred 18/18 > usb-storage: usb_stor_transfer_partial(): transfer complete > usb-storage: Bulk data transfer result 0x0 > usb-storage: Attempting to get CSW... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x946 R 0 Stat 0x0 > usb-storage: -- Result from auto-sense is 0 > usb-storage: -- code: 0x70, key: 0x0, ASC: 0x0, ASCQ: 0x0 > usb-storage: No Sense: no additional sense information > usb-storage: scsi cmd done, result=0x0 > usb-storage: *** thread sleeping. > SCSI disk error : host 1 channel 0 id 0 lun 0 return code = 8000000 > Current sd08:21: sense key None > I/O error: dev 08:21, sector 10741986 > > I found this patch on the net: > > http://www.kernel.org/pub/linux/kernel/people/gregkh/usb/2.6/2.6.3/usb-storage-05-2.6.3.patch > > It does not apply cleanly, but here's my rendition of it for 2.4.26: > > --- linux-2.4.26/drivers/usb/storage/transport.c~ Wed Feb 18 05:36:31 2004 > +++ linux-2.4.26/drivers/usb/storage/transport.c Thu Apr 29 18:48:22 2004 > @@ -651,6 +651,8 @@ > return; > } > > + srb->result = SAM_STAT_GOOD; > + > /* Determine if we need to auto-sense > * > * I normally don't use a flag like this, but it's almost impossible > @@ -690,8 +692,8 @@ > } > > /* > - * Also, if we have a short transfer on a command that can't have > - * a short transfer, we're going to do this. > + * A short transfer on a command where we don't expect it > + * is unusual, but it doesn't mean we need to auto-sense. > */ > if ((srb->result == US_BULK_TRANSFER_SHORT) && > !((srb->cmnd[0] == REQUEST_SENSE) || > @@ -700,7 +702,6 @@ > (srb->cmnd[0] == LOG_SENSE) || > (srb->cmnd[0] == MODE_SENSE_10))) { > US_DEBUGP("-- unexpectedly short transfer\n"); > - need_auto_sense = 1; > } > > /* Now, if we need to do the auto-sense, let's do it */ > @@ -793,26 +794,15 @@ > /* set the result so the higher layers expect this data */ > srb->result = CHECK_CONDITION << 1; > > - /* If things are really okay, then let's show that */ > - if ((srb->sense_buffer[2] & 0xf) == 0x0) > + /* If things are really okay, then let's show that. Zero > + * out the sense buffer so the higher layers won't realize > + * we did an unsolicited auto-sense. */ > + if (result == USB_STOR_TRANSPORT_GOOD && > + (srb->sense_buffer[2] & 0xf) == 0x0) { > srb->result = GOOD << 1; > - } else /* if (need_auto_sense) */ > - srb->result = GOOD << 1; > - > - /* Regardless of auto-sense, if we _know_ we have an error > - * condition, show that in the result code > - */ > - if (result == USB_STOR_TRANSPORT_FAILED) > - srb->result = CHECK_CONDITION << 1; > - > - /* If we think we're good, then make sure the sense data shows it. > - * This is necessary because the auto-sense for some devices always > - * sets byte 0 == 0x70, even if there is no error > - */ > - if ((us->protocol == US_PR_CB || us->protocol == US_PR_DPCM_USB) && > - (result == USB_STOR_TRANSPORT_GOOD) && > - ((srb->sense_buffer[2] & 0xf) == 0x0)) > - srb->sense_buffer[0] = 0x0; > + srb->sense_buffer[0] = 0x0; > + } > + } > } > > /* > > With this patch applied, I can transfer files to and from the iRiver > without these pesky I/O errors. The funny thing is that with the > patch, I do not get anymore 'unexpectedly short transfer' messages... > > However, I do get these: > > usb-storage: *** thread awakened. > usb-storage: Command READ_10 (10 bytes) > usb-storage: 28 00 01 df 4d 25 00 00 ff 00 00 00 > usb-storage: Bulk command S 0x43425355 T 0x1aab Trg 0 LUN 0 L 130560 F 128 CL 10 > usb-storage: Bulk command transfer result=0 > usb-storage: usb_stor_transfer_partial(): xfer 4096 bytes > usb-storage: usb_stor_bulk_msg() returned 0 xferred 0/4096 > usb-storage: Bulk data transfer result 0x1 > usb-storage: Attempting to get CSW... > usb-storage: clearing endpoint halt for pipe 0xc0011e80 > usb-storage: usb_stor_clear_halt: result=0 > usb-storage: Attempting to get CSW (2nd try)... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x1aab R 130560 Stat 0x0 > usb-storage: scsi cmd done, result=0x0 > usb-storage: *** thread sleeping. > usb-storage: queuecommand() called > usb-storage: *** thread awakened. > usb-storage: Command READ_10 (10 bytes) > usb-storage: 28 00 01 df 4e 24 00 00 c9 00 00 00 > usb-storage: Bulk command S 0x43425355 T 0x1aac Trg 0 LUN 0 L 102912 F 128 CL 10 > usb-storage: Bulk command transfer result=0 > usb-storage: usb_stor_transfer_partial(): xfer 512 bytes > usb-storage: command_abort() called > usb-storage: usb_stor_bulk_msg() returned -104 xferred 0/512 > usb-storage: usb_stor_transfer_partial(): transfer aborted > usb-storage: Bulk data transfer result 0x3 > usb-storage: -- transport indicates command was aborted > usb-storage: Bulk reset requested > usb-storage: usb_stor_clear_halt: result=0 > usb-storage: usb_stor_clear_halt: result=0 > usb-storage: Bulk soft reset completed > usb-storage: scsi command aborted > usb-storage: *** thread sleeping. > > This does not look good. I also noticed fs corruption (probably my > lack of understanding when patching). > > If I just patch like this: > > --- linux-2.4.26/drivers/usb/storage/transport.c~ Wed Feb 18 05:36:31 2004 > +++ linux-2.4.26/drivers/usb/storage/transport.c Thu Apr 29 18:48:22 2004 > @@ -690,8 +692,8 @@ > } > > /* > - * Also, if we have a short transfer on a command that can't have > - * a short transfer, we're going to do this. > + * A short transfer on a command where we don't expect it > + * is unusual, but it doesn't mean we need to auto-sense. > */ > if ((srb->result == US_BULK_TRANSFER_SHORT) && > !((srb->cmnd[0] == REQUEST_SENSE) || > @@ -700,7 +702,6 @@ > (srb->cmnd[0] == LOG_SENSE) || > (srb->cmnd[0] == MODE_SENSE_10))) { > US_DEBUGP("-- unexpectedly short transfer\n"); > - need_auto_sense = 1; > } > > /* Now, if we need to do the auto-sense, let's do it */ > > Then I have a reset on every short read... > > usb-storage: *** thread awakened. > usb-storage: Command READ_10 (10 bytes) > usb-storage: 28 00 01 8f 06 24 00 00 c9 00 00 00 > usb-storage: Bulk command S 0x43425355 T 0x3728 Trg 0 LUN 0 L 102912 F 128 CL 10 > usb-storage: Bulk command transfer result=0 > usb-storage: usb_stor_transfer_partial(): xfer 512 bytes > usb-storage: command_abort() called > usb-storage: usb_stor_bulk_msg() returned -104 xferred 0/512 > usb-storage: usb_stor_transfer_partial(): transfer aborted > usb-storage: Bulk data transfer result 0x3 > usb-storage: -- transport indicates command was aborted > usb-storage: Bulk reset requested > usb-storage: usb_stor_clear_halt: result=0 > usb-storage: usb_stor_clear_halt: result=0 > usb-storage: Bulk soft reset completed > usb-storage: scsi command aborted > 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 00 00 c9 00 00 00 > usb-storage: Bulk command S 0x43425355 T 0x3729 Trg 0 LUN 0 L 0 F 0 CL 6 > usb-storage: Bulk command transfer result=0 > usb-storage: Attempting to get CSW... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x3729 R 0 Stat 0x0 > usb-storage: scsi cmd done, result=0x0 > usb-storage: *** thread sleeping. > usb-storage: queuecommand() called > usb-storage: *** thread awakened. > usb-storage: Command READ_10 (10 bytes) > usb-storage: 28 00 01 8f 06 24 00 00 c9 00 00 00 > usb-storage: Bulk command S 0x43425355 T 0x372a Trg 0 LUN 0 L 102912 F 128 CL 10 > usb-storage: Bulk command transfer result=0 > usb-storage: usb_stor_transfer_partial(): xfer 512 bytes > usb-storage: usb_stor_bulk_msg() returned 0 xferred 512/512 > usb-storage: usb_stor_transfer_partial(): transfer complete > usb-storage: usb_stor_transfer_partial(): xfer 4096 bytes > usb-storage: usb_stor_bulk_msg() returned 0 xferred 4096/4096 > usb-storage: usb_stor_transfer_partial(): transfer complete > > Is there a way to retry the short read without resetting? Resetting > all the time stalls I/O throughput quite a bit (2-5 seconds without > any activity)? > > Thanks, > Phil. -- Matthew Dharm Home: [EMAIL PROTECTED] Maintainer, Linux USB Mass Storage Driver A: The most ironic oxymoron wins ... DP: "Microsoft Works" A: Uh, okay, you win. -- A.J. & Dust Puppy User Friendly, 1/18/1998
pgp00000.pgp
Description: PGP signature
