Re: dwc3: unusual handling of setup requests with wLength == 0

[Thinh Nguyen]

On Fri, Sep 01, 2023, Alan Stern wrote:
> On Fri, Sep 01, 2023 at 01:27:34AM +0000, Thinh Nguyen wrote:
> > > Does Windows really work this way?  Does it not send a task management 
> > > request?  That would definitely seem to be against the intent of the 
> > > spec, if not against the letter.
> > 
> > Unfortunately yes, I don't see any Task Management request aborting the
> > transfer.
> 
> Is it possible that the packets are there but you don't see them because 
> of the filtering or data presentation done by the USB analyzer?

There's no Task Management transfer. All the packets are captured, but
it's not easy to show in a single email as I need to manually export
which view to see. Some view level (such as SCSI) would group the
transfers, which may not show the entire picture. But it helps with the
high level view. If there's Task Management command, then you would see
it from the SCSI level.

> 
> > Here's a snippet captured at the SCSI level from Samsung T7 device
> > response to CLEAR_FEATURE(halt-ep) to IN data endpoint from host
> > (Windows 10). Similar behavior is observed for OUT endpoint.
> 
> Hmmm.  The SCSI level may not provide enough detail.
> 

<snip>

> 
> Is is possible to show all the data packets (not the token or 
> handshaking ones) for both the command and status endpoints?  I'm 
> particularly interested in seeing what sort of status message the device 
> sends for the failed command, and where it occurs in relation to the 
> other transfers.
> 
> I wouldn't mind seeing a summary of the packets on the data-IN endpoint 
> as well.  Not a detailed view -- multiple 500-KB transfers aren't very 
> interesting -- but just to see what happens in the vicinity of the 
> transaction error.
> 

Actually, something else was probably happened here.

Some context:
* Bulk OUT endp 4 is for command endpoint
* Bulk IN endp 1 is for data endpoint
* Bulk IN endp 3 is for status endpoint

_______|_______________________________________________________________________
Transfer(261) Left("Left") G2(x1) Bulk(OUT) ADDR(3) ENDP(4) UASP  Command IU 
_______| Tag(0x0002) Logical Unit Number(0x 0000 0000 0000 0000) SCSI CDB 
_______| READ(10) Time(184.510 us) Time Stamp(10 . 005 791 128) 
_______|_______________________________________________________________________
Transfer(264) Left("Left") G2(x1) Bulk(IN) ADDR(3) ENDP(1) Stream ID(0x0002) 
_______| UASP  Data IN Bytes Transferred(524288) Time(945.654 us) 
_______| Time Stamp(10 . 005 975 638) 
_______|_______________________________________________________________________
Transfer(266) Left("Left") G2(x1) Bulk(IN) ADDR(3) ENDP(3) Stream ID(0x0002) 
_______| UASP Sense IU  Tag(0x0002) STATUS(GOOD) Time( 47.370 us) 
_______| Time Stamp(10 . 006 921 292) 
_______|_______________________________________________________________________
Transfer(267) Left("Left") G2(x1) Bulk(OUT) ADDR(3) ENDP(4) UASP  Command IU 
_______| Tag(0x0002) Logical Unit Number(0x 0000 0000 0000 0000) SCSI CDB 
_______| READ(10) Time(161.454 us) Time Stamp(10 . 006 968 662) 
_______|_______________________________________________________________________
Transfer(272) Left("Left") G2(x1) Bulk(IN) ADDR(3) ENDP(1) Stream ID(0x0002) 
_______| UASP  Data IN Bytes Transferred(146432) Time(  2.519 ms) 
_______| Time Stamp(10 . 007 130 116) 
_______|_______________________________________________________________________


## Transaction error occurs, the transfer stopped short at 146432 bytes
## instead of 512K.


Transfer(289) Left("Left") G2(x1) Control(SET) ADDR(3) ENDP(0) 
_______| bRequest(CLEAR_FEATURE) wValue(ENDPOINT_HALT) wLength(0) 
_______| Time(166.322 us) Time Stamp(10 . 009 649 516) 
_______|_______________________________________________________________________


# Host issues CLEAR_FEATURE(halt_ep)


Transfer(291) Left("Left") G2(x1) Bulk(OUT) ADDR(3) ENDP(4) UASP  Command IU 
_______| Tag(0x0002) Logical Unit Number(0x 0000 0000 0000 0000) SCSI CDB 
_______| READ(10) Time(158.848 us) Time Stamp(10 . 009 815 838) 
_______|_______________________________________________________________________


# Host completely dropped the SCSI command with transaction error. It
# doesn't request for the status. Since it's dropped, tag 2 is
# available. Now, a new SCSI command can use Tag 2.


Transfer(292) Left("Left") G2(x1) Bulk(IN) ADDR(3) ENDP(3) Stream ID(0x0002) 
_______| UASP Response IU  Tag(0x0002) RESPONSE_CODE(OVERLAPPED TAG) 
_______| Time(207.006 us) Time Stamp(10 . 009 974 686) 
_______|_______________________________________________________________________


# Thinking that the previous Tag 2 command was still active and
# responded with an OVERLAPPED TAG. This probably causes the gadget to
# cancel the transfer and drop the command so it can be in sync again.


Transfer(295) Left("Left") G2(x1) Bulk(OUT) ADDR(3) ENDP(4) UASP  Command IU 
_______| Tag(0x0002) Logical Unit Number(0x 0000 0000 0000 0000) SCSI CDB 
_______| READ(10) Time(884.218 ms) Time Stamp(10 . 010 181 692) 
_______|_______________________________________________________________________
Transfer(313) Left("Left") G2(x1) Bulk(IN) ADDR(3) ENDP(1) Stream ID(0x0002) 
_______| UASP  Data IN Bytes Transferred(524288) Time(554.648 us) 
_______| Time Stamp(10 . 894 399 886) 
_______|_______________________________________________________________________
Transfer(314) Left("Left") G2(x1) Bulk(IN) ADDR(3) ENDP(3) Stream ID(0x0002) 
_______| UASP Sense IU  Tag(0x0002) STATUS(GOOD) Time(127.515 ms) 
_______| Time Stamp(10 . 894 954 534) 
_______|_______________________________________________________________________
Transfer(315) Left("Left") G2(x1) Bulk(OUT) ADDR(3) ENDP(4) UASP  Command IU 
_______| Tag(0x0002) Logical Unit Number(0x 0000 0000 0000 0000) SCSI CDB 
_______| READ(10) Time(278.770 us) Time Stamp(11 . 022 469 104) 
_______|_______________________________________________________________________
Transfer(316) Left("Left") G2(x1) Bulk(IN) ADDR(3) ENDP(1) Stream ID(0x0002) 
_______| UASP  Data IN Bytes Transferred(524288) Time(554.236 us) 
_______| Time Stamp(11 . 022 747 874) 
_______|_______________________________________________________________________
Transfer(317) Left("Left") G2(x1) Bulk(IN) ADDR(3) ENDP(3) Stream ID(0x0002) 
_______| UASP Sense IU  Tag(0x0002) STATUS(GOOD) Time( 49.406 us) 
_______| Time Stamp(11 . 023 302 110) 
_______|_______________________________________________________________________


So, for this scenario, the host was probably stay in sync with the
device due to the overlap command tag id canceling the transfer. I'm not
sure if this is the intent of the Windows UASP class driver, which seems
like a non-conventional way of synchronization. Perhaps it was done
because some devices may not support TASK_MANAGEMENT(Abort_task)?

Regardless, if the host resets the endpoint, the transfer must be
canceled otherwise we risk data corruption.

Also whenever there's a OVERLAPPED tag error, Windows host takes a long
time (~1 sec) to send a new command (check delta time of Transfer 295
and 313). If the gadget driver can base off of the
CLEAR_FEATURE(halt_ep), this improves performance.

BR,
Thinh