add usbd edpt open

- RTT mode is blocking to prevent log lost
- Improve logging message

3 files changed, 37 insertions, 12 deletions

diff --git a/src/device/usbd.c b/src/device/usbd.c
index 219dd23be..f0b7fcefc 100644
--- a/src/device/usbd.c
+++ b/src/device/usbd.c
@@ -356,7 +356,8 @@ void tud_task (void)
 
     if ( !osal_queue_receive(_usbd_q, &event) ) return;
 
-    TU_LOG2("USBD: event %s\r\n", event.event_id < DCD_EVENT_COUNT ? _usbd_event_str[event.event_id] : "CORRUPTED");
+    TU_LOG2("USBD: %s", event.event_id < DCD_EVENT_COUNT ? _usbd_event_str[event.event_id] : "CORRUPTED");
+    TU_LOG2("%s", (event.event_id != DCD_EVENT_XFER_COMPLETE && event.event_id != DCD_EVENT_SETUP_RECEIVED) ? "\r\n" : " ");
 
     switch ( event.event_id )
     {
@@ -372,7 +373,8 @@ void tud_task (void)
       break;
 
       case DCD_EVENT_SETUP_RECEIVED:
-        TU_LOG2_MEM(&event.setup_received, 8, 2);
+        TU_LOG2_VAR(&event.setup_received);
+        TU_LOG2("\r\n");
 
         // Mark as connected after receiving 1st setup packet.
         // But it is easier to set it every time instead of wasting time to check then set
@@ -395,7 +397,7 @@ void tud_task (void)
         uint8_t const epnum   = tu_edpt_number(ep_addr);
         uint8_t const ep_dir  = tu_edpt_dir(ep_addr);
 
-        TU_LOG2("  Endpoint: 0x%02X, Bytes: %u\r\n", ep_addr, (unsigned int) event.xfer_complete.len);
+        TU_LOG2("on EP %02X with %u bytes\r\n", ep_addr, (unsigned int) event.xfer_complete.len);
 
         _usbd_dev.ep_status[epnum][ep_dir].busy = false;
 
@@ -472,10 +474,11 @@ static bool process_control_request(uint8_t rhport, tusb_control_request_t const
     return tud_vendor_control_request_cb(rhport, p_request);
   }
 
-#if CFG_TUSB_DEBUG > 1
+#if CFG_TUSB_DEBUG >= 2
   if (TUSB_REQ_TYPE_STANDARD == p_request->bmRequestType_bit.type && p_request->bRequest <= TUSB_REQ_SYNCH_FRAME)
   {
-    TU_LOG2("  %s\r\n", _tusb_std_request_str[p_request->bRequest]);
+    TU_LOG2("  %s", _tusb_std_request_str[p_request->bRequest]);
+    if (TUSB_REQ_GET_DESCRIPTOR != p_request->bRequest) TU_LOG2("\r\n");
   }
 #endif
 
@@ -702,7 +705,7 @@ static bool process_set_config(uint8_t rhport, uint8_t cfg_num)
         // Interface number must not be used already
         TU_ASSERT( DRVID_INVALID == _usbd_dev.itf2drv[desc_itf->bInterfaceNumber] );
 
-        TU_LOG2("  %s open\r\n", _usbd_driver[drv_id].name);
+        TU_LOG2("  %s opened\r\n", _usbd_driver[drv_id].name);
         _usbd_dev.itf2drv[desc_itf->bInterfaceNumber] = drv_id;
 
         // If IAD exist, assign all interfaces to the same driver
@@ -767,6 +770,8 @@ static bool process_get_descriptor(uint8_t rhport, tusb_control_request_t const
   {
     case TUSB_DESC_DEVICE:
     {
+      TU_LOG2(" Device\r\n");
+
       uint16_t len = sizeof(tusb_desc_device_t);
 
       // Only send up to EP0 Packet Size if not addressed
@@ -785,6 +790,8 @@ static bool process_get_descriptor(uint8_t rhport, tusb_control_request_t const
 
     case TUSB_DESC_BOS:
     {
+      TU_LOG2(" BOS\r\n");
+
       // requested by host if USB > 2.0 ( i.e 2.1 or 3.x )
       if (!tud_descriptor_bos_cb) return false;
 
@@ -798,6 +805,8 @@ static bool process_get_descriptor(uint8_t rhport, tusb_control_request_t const
 
     case TUSB_DESC_CONFIGURATION:
     {
+      TU_LOG2(" Configuration[%u]\r\n", desc_index);
+
       tusb_desc_configuration_t const* desc_config = (tusb_desc_configuration_t const*) tud_descriptor_configuration_cb(desc_index);
       TU_ASSERT(desc_config);
 
@@ -809,6 +818,8 @@ static bool process_get_descriptor(uint8_t rhport, tusb_control_request_t const
     break;
 
     case TUSB_DESC_STRING:
+      TU_LOG2(" String[%u]\r\n", desc_index);
+
       // String Descriptor always uses the desc set from user
       if ( desc_index == 0xEE )
       {
@@ -827,6 +838,8 @@ static bool process_get_descriptor(uint8_t rhport, tusb_control_request_t const
     break;
 
     case TUSB_DESC_DEVICE_QUALIFIER:
+      TU_LOG2(" Device Qualifier\r\n");
+
       // TODO If not highspeed capable stall this request otherwise
       // return the descriptor that could work in highspeed
       return false;
@@ -920,7 +933,7 @@ bool usbd_open_edpt_pair(uint8_t rhport, uint8_t const* p_desc, uint8_t ep_count
     tusb_desc_endpoint_t const * desc_ep = (tusb_desc_endpoint_t const *) p_desc;
 
     TU_ASSERT(TUSB_DESC_ENDPOINT == desc_ep->bDescriptorType && xfer_type == desc_ep->bmAttributes.xfer);
-    TU_ASSERT(dcd_edpt_open(rhport, desc_ep));
+    TU_ASSERT(usbd_edpt_open(rhport, desc_ep));
 
     if ( tu_edpt_dir(desc_ep->bEndpointAddress) == TUSB_DIR_IN )
     {
@@ -955,15 +968,24 @@ void usbd_defer_func(osal_task_func_t func, void* param, bool in_isr)
 // USBD Endpoint API
 //--------------------------------------------------------------------+
 
+bool usbd_edpt_open(uint8_t rhport, tusb_desc_endpoint_t const * desc_ep)
+{
+  TU_LOG2("  Open EP %02X with Size = %u\r\n", desc_ep->bEndpointAddress, desc_ep->wMaxPacketSize.size);
+
+  return dcd_edpt_open(rhport, desc_ep);
+}
+
 bool usbd_edpt_xfer(uint8_t rhport, uint8_t ep_addr, uint8_t * buffer, uint16_t total_bytes)
 {
   uint8_t const epnum = tu_edpt_number(ep_addr);
   uint8_t const dir   = tu_edpt_dir(ep_addr);
 
+  TU_LOG2("  Queue EP %02X with %u bytes ... ", ep_addr, total_bytes);
+
   TU_VERIFY( dcd_edpt_xfer(rhport, ep_addr, buffer, total_bytes) );
   _usbd_dev.ep_status[epnum][dir].busy = true;
 
-  TU_LOG2("  XFER Endpoint: 0x%02X, Bytes: %d\r\n", ep_addr, total_bytes);
+  TU_LOG2("OK\r\n");
 
   return true;
 }
diff --git a/src/device/usbd_control.c b/src/device/usbd_control.c
index c61606f18..b0ae85e3b 100644
--- a/src/device/usbd_control.c
+++ b/src/device/usbd_control.c
@@ -63,7 +63,7 @@ static inline bool _status_stage_xact(uint8_t rhport, tusb_control_request_t con
   // Opposite to endpoint in Data Phase
   uint8_t const ep_addr = request->bmRequestType_bit.direction ? EDPT_CTRL_OUT : EDPT_CTRL_IN;
 
-  TU_LOG2("  XFER Endpoint: 0x%02X, Bytes: %d\r\n", ep_addr, 0);
+  TU_LOG2("  Queue EP %02X with zlp Status\r\n", ep_addr);
 
   // status direction is reversed to one in the setup packet
   // Note: Status must always be DATA1
@@ -96,7 +96,7 @@ static bool _data_stage_xact(uint8_t rhport)
     if ( xact_len ) memcpy(_usbd_ctrl_buf, _ctrl_xfer.buffer, xact_len);
   }
 
-  TU_LOG2("  XACT Control: 0x%02X, Bytes: %d\r\n", ep_addr, xact_len);
+  TU_LOG2("  Queue EP %02X with %u bytes\r\n", ep_addr, xact_len);
 
   return dcd_edpt_xfer(rhport, ep_addr, xact_len ? _usbd_ctrl_buf : NULL, xact_len);
 }
@@ -118,7 +118,7 @@ bool tud_control_xfer(uint8_t rhport, tusb_control_request_t const * request, vo
       TU_ASSERT(buffer);
     }
 
-    TU_LOG2("  XFER Endpoint: 0x%02X, Bytes: %d\r\n", request->bmRequestType_bit.direction ? EDPT_CTRL_IN : EDPT_CTRL_OUT, _ctrl_xfer.data_len);
+//    TU_LOG2("  Control total data length is %u bytes\r\n", _ctrl_xfer.data_len);
 
     // Data stage
     TU_ASSERT( _data_stage_xact(rhport) );
diff --git a/src/device/usbd_pvt.h b/src/device/usbd_pvt.h
index 26b9700e8..48188ec99 100644
--- a/src/device/usbd_pvt.h
+++ b/src/device/usbd_pvt.h
@@ -37,7 +37,10 @@
 // USBD Endpoint API
 //--------------------------------------------------------------------+
 
-//bool usbd_edpt_open(uint8_t rhport, tusb_desc_endpoint_t const * p_endpoint_desc);
+// Open an endpoint
+bool usbd_edpt_open(uint8_t rhport, tusb_desc_endpoint_t const * desc_ep);
+
+// Close an endpoint
 void usbd_edpt_close(uint8_t rhport, uint8_t ep_addr);
 
 // Submit a usb transfer