tinyusb: Race condition with cdc auto flush() on transfer completion

Set up [Mandatory] Provide details of your setup help us to reproduce the issue as quick as possible

• PC OS : Ubuntu 20.04
• Board : Feather nRF52840 Express
• Firmware: Arduino with FreeRTOS, original issue is filed here https://github.com/adafruit/Adafruit_nRF52_Arduino/issues/565

Note: The race condition only happen if we use an additional mutex. Semaphore or any other type won’t cause the issue. Explanation is below

void setup() {

  // put your setup code here, to run once:
  Serial.begin(115200);
  while ( !Serial ) delay(10);   // for nrf52840 with native usb

  Serial.println("Bluefruit52 USB Serial Test");
  Serial.println("-----------------------------------\n");

  uint32_t t2 = millis() + 5000;
  uint32_t wrsize = 0;
  SemaphoreHandle_t mutex = xSemaphoreCreateMutex();
  while (millis() < t2) {
    if (xSemaphoreTake(mutex, portMAX_DELAY) == pdTRUE)
    {
      wrsize += Serial.println("AaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaCcccBbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb");
      xSemaphoreGive(mutex);
    }
  }
  vSemaphoreDelete(mutex);
  delay(1000);
  Serial.print(wrsize / 5);
  Serial.println("bytes/Sec");
}

void loop() {
}

Screenshots

Describe the bug Using above systemview screenshot for reference, the endpoint here is CDC Endpoint In for printing text to host:

• Previously: there is pending transfer on EP
• At event 130: loop task call tud_cdc_write() which will acquire the mutex that lock the CDC TX fifo for writing
• 132-136: USB ISR transfer complete
• 137-139: usbd task run and call cdcd_xfer_cb() -> auto flush with tud_cdc_write_flush(), and is blocked when trying to read from tx fifo https://github.com/hathach/tinyusb/blob/master/src/class/cdc/cdc_device.c#L167 (currently held by loop at 130).
• 140: Since usbd is blcoked by mutex, the priority inherit happen -> loop’s priority = usbd’s priority
• 142-143: loop run and finish the write(), release the mutex.
• 144: loop continue to run !!! At this time, the usbd task should be the one running, since the mutex is released by loop, a context switch should happen, but it is NOT 😕
• 146: loop call write_flush(), which successfully submit transfer to dcd edpt. loop continue to run until it yield()
• 150-151: just ignore this
• 152: usbd task resume and it now read from fifo and try to submit another transfer to an BUSY endpoint !!! DCD will reject this and cause the dropped characters in print() !!!

Additional context

The issue can’t happen if at 144 a context switch happens, (which it should but not), then usbd task could complete its write_flush() first, and set the edpt busy. Busy flag will prevent the loop task submitting transfer. It turns out that FreeRTOS does not fully implement mutex priority (dis)-inheritance. Priority inherit is not properly reverted when the mutex is released. Using following example

At the end of 3) when When the LP task gives the mutex back it returns to its original priority.. in reality, it only go back to its original priority if it doesn’t held ANY other mutex, even those the other mutex has nothing to do with the High task. In the above Arduino sketch, the mutex literally does nothing, but still prevent the loop() to go back to its low priority at 144. In fact, the loop() remain in the high priority after the inherit occurs as long as it still hold at least a random mutex

FreeRTOS kernel code https://github.com/FreeRTOS/FreeRTOS-Kernel/blob/master/tasks.c#L4150 and it is intended for simple implementation https://www.freertos.org/FreeRTOS_Support_Forum_Archive/December_2016/freertos_xTaskPriorityDisinherit_when_other_mutexes_are_held_4d6144d1j.html