On Tue, 6 Jun 2006, Vivek Dharmadhikari wrote: > Alan > > >Vivek, can you please run the same test over again? This time also > >collect the usb-storage verbose debugging log so we can see exactly what > >happens from the host's point of view and compare it with the Catalyst's > >record. We'd like to get as much detailed information as possible leading > >up to the point where the problem occurs. You can stop the test as soon > >as one of those 30-second timeouts occurs. > > I re-ran the test with usb-storage verbose debugging enabled. The > usb-storage log,usbmon log and Catalyst log are in aggrement with each > other. I am reproducing the the usb-storage log below.
You didn't understand me. You need to post the relevant information on the mailing list so that _we_ can look at it. You don't know what's happening well enough to give a suitable interpretation. For example, your log here includes a lot of unnecessary stuff from before the problem occurred. I'm going to skip it... > usb-storage: queuecommand called > usb-storage: *** thread awakened. > usb-storage: Command WRITE_10 (10 bytes) > usb-storage: 2a 00 00 01 87 f9 00 00 01 00 > usb-storage: Bulk Command S 0x43425355 T 0xad L 512 F 0 Trg 0 LUN 0 CL 10 > 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_sglist: xfer 512 bytes, 1 entries > usb-storage: Status code 0; transferred 512/512 > 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 0xad 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 WRITE_10 (10 bytes) > usb-storage: 2a 00 00 01 87 fa 00 00 01 00 > usb-storage: Bulk Command S 0x43425355 T 0xae L 512 F 0 Trg 0 LUN 0 CL 10 > 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_sglist: xfer 512 bytes, 1 entries Here is the first problem. We need to know what the Catalyst trace shows at exactly this point. > usb-storage: command_abort called > usb-storage: usb_stor_stop_transport called > usb-storage: -- cancelling sg request > usb-storage: Status code -131; transferred 0/512 > usb-storage: -- transfer cancelled > usb-storage: Bulk data transfer result 0x4 > usb-storage: -- command was aborted > 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: clearing bulk-in endpoint halt > usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=82 len=0 > usb-storage: usb_stor_clear_halt: result = 0 > usb-storage: Soft reset: clearing bulk-out endpoint halt > usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=01 len=0 > usb-storage: usb_stor_clear_halt: result = 0 > usb-storage: Soft reset done > usb-storage: scsi command aborted > usb-storage: queuecommand called > usb-storage: *** thread sleeping. > 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 0xae L 0 F 0 Trg 0 LUN 0 CL 6 > 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 This is the second problem. > usb-storage: command_abort called > usb-storage: usb_stor_stop_transport called > usb-storage: -- cancelling URB > usb-storage: Status code -131; transferred 0/13 > usb-storage: -- transfer cancelled > usb-storage: Bulk status result = 4 > usb-storage: -- command was aborted > 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: clearing bulk-in endpoint halt > usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=82 len=0 > usb-storage: usb_stor_clear_halt: result = 0 > usb-storage: Soft reset: clearing bulk-out endpoint halt > usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=01 len=0 > usb-storage: usb_stor_clear_halt: result = 0 > usb-storage: Soft reset done > usb-storage: scsi command aborted > usb-storage: device_reset called > 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: *** thread sleeping. > usb-storage: Soft reset: clearing bulk-in endpoint halt > usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=82 len=0 > usb-storage: usb_stor_clear_halt: result = 0 > usb-storage: Soft reset: clearing bulk-out endpoint halt > usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=01 len=0 > usb-storage: usb_stor_clear_halt: result = 0 > usb-storage: Soft reset done > > The line "usb-storage: Status code -131; transferred 0/13" in the above > log is where the 30 seconds delay occurs. The sequence leading to 30 > seconds delay is as below. Note that the first problem occurred earlier. > 1. The usb host driver queue 13 bytes handed over by scsi layer for > transmission. No. The bytes are not handed over by the SCSI layer and they are queued for reception, not for transmission. > 2. The device responds with NYET. > 3. 30 seconds IDLE time on bus If there are SOF packets present then the bus isn't truly IDLE. > 4. The host issue class type request 0x21ff to reset the device and device > ack it. > 5. 6 seconds IDEL time on bus. > 5. The host issue clear endpoint feature for IN and OUT endpoints. > 6. The data transfer resumes. > > The above sequence get repeated quite a few times during the data transfer. > > As David suggested, is it possible to implement code in the host to pull > the device out of NYET state ? I would like to experiment with such code > if you can point to right place. I can't. In any case, you don't need to pull the device out of NYET state; you need to push the host controller to send another PING. > Let me know if you need more details. I will be happy to provide them. What does the Catalyst trace show for the time period where the first problem occurred (that is, the period before the first "command_abort called" line)? What does the usbmon log show for that same period? Alan Stern _______________________________________________ linux-usb-devel@lists.sourceforge.net To unsubscribe, use the last form field at: https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
