Strange behaviour of MSC driver.

[mudrovc]

I found a bug in my code, which provokes a strange behaviour on MSC device driver. I have the following code for tud_msc_write10_cb()

int32_t tud_msc_write10_cb(uint8_t lun, uint32_t lba, uint32_t offset, uint8_t* buffer, uint32_t bufsize)
{
  (void)lun;
  int result;
  uint32_t blocks_to_read;

  /* We can operate in complete block sizes only */
  if((g_usb_prv.msd_rw_processing_b == false) &&
     (offset == 0) &&
     ((bufsize % g_usb_prv.msd_block_size) == 0))
  {
    blocks_to_read = bufsize / g_usb_prv.msd_block_size;
    if((lba + blocks_to_read) < g_usb_prv.msd_block_cnt)
    {
      g_usb_prv.msd_rw_req.is_read = false;
      g_usb_prv.msd_rw_req.bufsize = bufsize;
      g_usb_prv.msd_rw_req.buffer = buffer;
      g_usb_prv.msd_rw_req.lba = lba;

      g_usb_prv.msd_rw_processing_b = true;
      osThreadFlagsSet(g_usb_prv.thread_id, EVENT_MASK(USB_EVT_MSC_RW));
      result = TUD_MSC_RET_ASYNC;
      debug_Printf(DEBUG_USB_PRINT_MSD_READ_WRITE_REQUESTS, "MSD_w10:%d:%d\r\n", lba, bufsize);
    }
    else
     result = TUD_MSC_RET_ERROR;
  }
  else
     result = TUD_MSC_RET_ERROR;

  return result;
}

There is bug in my code here:

if((lba + blocks_to_read) < g_usb_prv.msd_block_cnt)

This effectively blocks the writting in last sector of the card (it must be <= instead of <). So the function returns TUD_MSC_RET_ERROR.
Up to here, all is normal, it's my bug. But as soon as it returns TUD_MSC_RET_ERROR, the following ASSERT is rised in usbd_edpt_xfer():

// Attempt to transfer on a busy endpoint, sound like an race condition !
TU_ASSERT(_usbd_dev.ep_status[epnum][dir].busy == 0);

Currently I don't know - is it due to my wrong handling of SCSI write10 error, or it's a bug in the MSC code. But in my head - to return TUD_MSC_RET_ERROR is not a forbiden case, it can happen in real life, so the MSC should react properly. Or maybe I'm wrong?

This is the debug report on level 2.

USBD Setup Received 02 01 00 00 81 00 00 00 
  Clear Feature
    Clear Stall EP 81
  MSC control request
  Queue EP 81 with 13 bytes ...
  Queue EP 80 with 0 bytes ...
USBD Xfer Complete on EP 80 with 0 bytes
USBD Xfer Complete on EP 81 with 13 bytes
  MSC xfer callback
  SCSI Status [Lun0] = 0
  Queue EP 01 with 31 bytes ...
USBD Xfer Complete on EP 01 with 31 bytes
  MSC xfer callback
  SCSI Command [Lun0]: Read Capacity10
  Queue EP 81 with 8 bytes ...
USBD Xfer Complete on EP 81 with 8 bytes
  MSC xfer callback
  SCSI Data [Lun0]
  Queue EP 81 with 13 bytes ...
USBD Xfer Complete on EP 81 with 13 bytes
  MSC xfer callback
  SCSI Status [Lun0] = 0
  Queue EP 01 with 31 bytes ...
USBD Xfer Complete on EP 01 with 31 bytes
  MSC xfer callback
  SCSI Command [Lun0]: Inquiry
  Queue EP 81 with 36 bytes ...
USBD Xfer Complete on EP 81 with USBD Xfer Complete on EP 01 with 31 bytes
  MSC xfer callback
  SCSI Command [Lun0]: Write10
  Queue EP 01 with 512 bytes ...
USBD Xfer Complete on EP 01 with 512 bytes
  MSC xfer callback
  SCSI Data [Lun0]
USBD Func Call 
  Queue EP 81 with 13 bytes ...
USBD Xfer Complete on EP 81 with 13 bytes
  MSC xfer callback
  SCSI Status [Lun0] = 0
  Queue EP 01 with 31 bytes ...
USBD Xfer Complete on EP 01 with 31 bytes
  MSC xfer callback
  SCSI Command [Lun0]: Read10
USBD Func Call 
  Queue EP 81 with 512 bytes ...
USBD Xfer Complete on EP 81 with 512 bytes
  MSC xfer callback
  SCSI Data [Lun0]
  Queue EP 81 with 13 bytes ...
USBD Xfer Complete on EP 81 with 13 bytes
  MSC xfer callback
  SCSI Status [Lun0] = 0
  Queue EP 01 with 31 bytes ...
USBD Xfer Complete on EP 01 with 31 bytes
  MSC xfer callback
  SCSI Command [Lun0]: Write10
  Queue EP 01 with 512 bytes ...
USBD Xfer Complete on EP 01 with 512 bytes
  MSC xfer callback
  SCSI Data [Lun0]
  IO write() failed
    Stall EP 01
  Queue EP 81 with 13 bytes ...
USBD Xfer Complete on EP 81 with 13 bytes
  MSC xfer callback
  SCSI Status [Lun0] = 1
  Queue EP 01 with 31 bytes ...
usbd_edpt_xfer 1387: ASSERT FAILED

[HiFiPhile]

I think I've spotted an issue while on travel, if OUT EP is stalled then cbw should not be queued:

tinyusb/src/class/msc/msc_device.c

Line 124 in 83fa3bb

return usbd_edpt_xfer(rhport, p_msc->ep_out, _mscd_epbuf.buf, sizeof(msc_cbw_t), false);

Just like the check for IN EP:

tinyusb/src/class/msc/msc_device.c

Line 207 in 83fa3bb

// skip status if epin is currently stalled, will do it when received Clear Stall request

[mudrovc]

Here my knowledge for usb endpoint state processing is not enough... If you give me an exact lines to patch it - I can try it. But I don't feel good enough to change this code by myself.

[HiFiPhile]

Have a try:

diff --git a/src/class/msc/msc_device.c b/src/class/msc/msc_device.c
index 15bfafc35..bdaa8c703 100644
--- a/src/class/msc/msc_device.c
+++ b/src/class/msc/msc_device.c
@@ -121,7 +121,12 @@ TU_ATTR_ALWAYS_INLINE static inline bool send_csw(mscd_interface_t* p_msc) {
 TU_ATTR_ALWAYS_INLINE static inline bool prepare_cbw(mscd_interface_t* p_msc) {
   uint8_t rhport = p_msc->rhport;
   p_msc->stage = MSC_STAGE_CMD;
-  return usbd_edpt_xfer(rhport, p_msc->ep_out,  _mscd_epbuf.buf, sizeof(msc_cbw_t), false);
+  // skip command if epout is currently stalled, will do it when received Clear Stall request
+  if (!usbd_edpt_stalled(rhport, p_msc->ep_out)) {
+    return usbd_edpt_xfer(rhport, p_msc->ep_out,  _mscd_epbuf.buf, sizeof(msc_cbw_t), false);
+  } else {
+    return true;
+  }
 }
 
 static void fail_scsi_op(mscd_interface_t* p_msc, uint8_t status) {

[mudrovc]

I will try it, but after the holidays.

Merry Christmas and a Happy New Year!

[HiFiPhile]

Hi, do you have any update ?

[mudrovc]

Sorry for the delay. The management of our company postponed my project, so I'm currently working on a different one.

Anyway - I tried your patch. I'm confirming - it works as I expecting.
There is no more asserts when TUD_MSC_RET_ERROR is returned. Later, as soon as TUD_MSC_RET_ASYNC is returned, the process returns to normal flow.

[HiFiPhile]

Nice, PR is up in #3471