diff --git a/src/class/msc/msc_device.c b/src/class/msc/msc_device.c index 159a11259..a409c4e27 100644 --- a/src/class/msc/msc_device.c +++ b/src/class/msc/msc_device.c @@ -34,13 +34,16 @@ #include "msc_device.h" +// Level where CFG_TUSB_DEBUG must be at least for this driver is logged +#ifndef CFG_TUD_MSC_LOG_LEVEL + #define CFG_TUD_MSC_LOG_LEVEL 2 +#endif + +#define TU_LOG_DRV(...) TU_LOG(CFG_TUD_MSC_LOG_LEVEL, __VA_ARGS__) + //--------------------------------------------------------------------+ // MACRO CONSTANT TYPEDEF //--------------------------------------------------------------------+ - -// Can be selectively disabled to reduce logging when troubleshooting other driver -#define MSC_DEBUG 2 - enum { MSC_STAGE_CMD = 0, @@ -164,7 +167,7 @@ uint8_t rdwr10_validate_cmd(msc_cbw_t const* cbw) { if ( block_count ) { - TU_LOG(MSC_DEBUG, " SCSI case 2 (Hn < Di) or case 3 (Hn < Do) \r\n"); + TU_LOG_DRV(" SCSI case 2 (Hn < Di) or case 3 (Hn < Do) \r\n"); status = MSC_CSW_STATUS_PHASE_ERROR; }else { @@ -174,22 +177,22 @@ uint8_t rdwr10_validate_cmd(msc_cbw_t const* cbw) { if ( SCSI_CMD_READ_10 == cbw->command[0] && !is_data_in(cbw->dir) ) { - TU_LOG(MSC_DEBUG, " SCSI case 10 (Ho <> Di)\r\n"); + TU_LOG_DRV(" SCSI case 10 (Ho <> Di)\r\n"); status = MSC_CSW_STATUS_PHASE_ERROR; } else if ( SCSI_CMD_WRITE_10 == cbw->command[0] && is_data_in(cbw->dir) ) { - TU_LOG(MSC_DEBUG, " SCSI case 8 (Hi <> Do)\r\n"); + TU_LOG_DRV(" SCSI case 8 (Hi <> Do)\r\n"); status = MSC_CSW_STATUS_PHASE_ERROR; } else if ( 0 == block_count ) { - TU_LOG(MSC_DEBUG, " SCSI case 4 Hi > Dn (READ10) or case 9 Ho > Dn (WRITE10) \r\n"); + TU_LOG_DRV(" SCSI case 4 Hi > Dn (READ10) or case 9 Ho > Dn (WRITE10) \r\n"); status = MSC_CSW_STATUS_FAILED; } else if ( cbw->total_bytes / block_count == 0 ) { - TU_LOG(MSC_DEBUG, " Computed block size = 0. SCSI case 7 Hi < Di (READ10) or case 13 Ho < Do (WRIT10)\r\n"); + TU_LOG_DRV(" Computed block size = 0. SCSI case 7 Hi < Di (READ10) or case 13 Ho < Do (WRIT10)\r\n"); status = MSC_CSW_STATUS_PHASE_ERROR; } } @@ -352,7 +355,7 @@ bool mscd_control_xfer_cb(uint8_t rhport, uint8_t stage, tusb_control_request_t switch ( request->bRequest ) { case MSC_REQ_RESET: - TU_LOG(MSC_DEBUG, " MSC BOT Reset\r\n"); + TU_LOG_DRV(" MSC BOT Reset\r\n"); TU_VERIFY(request->wValue == 0 && request->wLength == 0); // driver state reset @@ -363,7 +366,7 @@ bool mscd_control_xfer_cb(uint8_t rhport, uint8_t stage, tusb_control_request_t case MSC_REQ_GET_MAX_LUN: { - TU_LOG(MSC_DEBUG, " MSC Get Max Lun\r\n"); + TU_LOG_DRV(" MSC Get Max Lun\r\n"); TU_VERIFY(request->wValue == 0 && request->wLength == 1); uint8_t maxlun = 1; @@ -400,7 +403,7 @@ bool mscd_xfer_cb(uint8_t rhport, uint8_t ep_addr, xfer_result_t event, uint32_t if ( !(xferred_bytes == sizeof(msc_cbw_t) && p_cbw->signature == MSC_CBW_SIGNATURE) ) { - TU_LOG(MSC_DEBUG, " SCSI CBW is not valid\r\n"); + TU_LOG_DRV(" SCSI CBW is not valid\r\n"); // BOT 6.6.1 If CBW is not valid stall both endpoints until reset recovery p_msc->stage = MSC_STAGE_NEED_RESET; @@ -412,7 +415,7 @@ bool mscd_xfer_cb(uint8_t rhport, uint8_t ep_addr, xfer_result_t event, uint32_t return false; } - TU_LOG(MSC_DEBUG, " SCSI Command [Lun%u]: %s\r\n", p_cbw->lun, tu_lookup_find(&_msc_scsi_cmd_table, p_cbw->command[0])); + TU_LOG_DRV(" SCSI Command [Lun%u]: %s\r\n", p_cbw->lun, tu_lookup_find(&_msc_scsi_cmd_table, p_cbw->command[0])); //TU_LOG_MEM(MSC_DEBUG, p_cbw, xferred_bytes, 2); p_csw->signature = MSC_CSW_SIGNATURE; @@ -457,7 +460,7 @@ bool mscd_xfer_cb(uint8_t rhport, uint8_t ep_addr, xfer_result_t event, uint32_t { if (p_cbw->total_bytes > sizeof(_mscd_buf)) { - TU_LOG(MSC_DEBUG, " SCSI reject non READ10/WRITE10 with large data\r\n"); + TU_LOG_DRV(" SCSI reject non READ10/WRITE10 with large data\r\n"); fail_scsi_op(rhport, p_msc, MSC_CSW_STATUS_FAILED); }else { @@ -479,7 +482,7 @@ bool mscd_xfer_cb(uint8_t rhport, uint8_t ep_addr, xfer_result_t event, uint32_t if ( resplen < 0 ) { // unsupported command - TU_LOG(MSC_DEBUG, " SCSI unsupported or failed command\r\n"); + TU_LOG_DRV(" SCSI unsupported or failed command\r\n"); fail_scsi_op(rhport, p_msc, MSC_CSW_STATUS_FAILED); } else if (resplen == 0) @@ -514,7 +517,7 @@ bool mscd_xfer_cb(uint8_t rhport, uint8_t ep_addr, xfer_result_t event, uint32_t break; case MSC_STAGE_DATA: - TU_LOG(MSC_DEBUG, " SCSI Data [Lun%u]\r\n", p_cbw->lun); + TU_LOG_DRV(" SCSI Data [Lun%u]\r\n", p_cbw->lun); //TU_LOG_MEM(MSC_DEBUG, _mscd_buf, xferred_bytes, 2); if (SCSI_CMD_READ_10 == p_cbw->command[0]) @@ -546,7 +549,7 @@ bool mscd_xfer_cb(uint8_t rhport, uint8_t ep_addr, xfer_result_t event, uint32_t if ( cb_result < 0 ) { // unsupported command - TU_LOG(MSC_DEBUG, " SCSI unsupported command\r\n"); + TU_LOG_DRV(" SCSI unsupported command\r\n"); fail_scsi_op(rhport, p_msc, MSC_CSW_STATUS_FAILED); }else { @@ -575,7 +578,7 @@ bool mscd_xfer_cb(uint8_t rhport, uint8_t ep_addr, xfer_result_t event, uint32_t // Wait for the Status phase to complete if( (ep_addr == p_msc->ep_in) && (xferred_bytes == sizeof(msc_csw_t)) ) { - TU_LOG(MSC_DEBUG, " SCSI Status [Lun%u] = %u\r\n", p_cbw->lun, p_csw->status); + TU_LOG_DRV(" SCSI Status [Lun%u] = %u\r\n", p_cbw->lun, p_csw->status); // TU_LOG_MEM(MSC_DEBUG, p_csw, xferred_bytes, 2); // Invoke complete callback if defined @@ -845,7 +848,7 @@ static void proc_read10_cmd(uint8_t rhport, mscd_interface_t* p_msc) if ( nbytes < 0 ) { // negative means error -> endpoint is stalled & status in CSW set to failed - TU_LOG(MSC_DEBUG, " tud_msc_read10_cb() return -1\r\n"); + TU_LOG_DRV(" tud_msc_read10_cb() return -1\r\n"); // set sense set_sense_medium_not_present(p_cbw->lun); @@ -907,7 +910,7 @@ static void proc_write10_new_data(uint8_t rhport, mscd_interface_t* p_msc, uint3 if ( nbytes < 0 ) { // negative means error -> failed this scsi op - TU_LOG(MSC_DEBUG, " tud_msc_write10_cb() return -1\r\n"); + TU_LOG_DRV(" tud_msc_write10_cb() return -1\r\n"); // update actual byte before failed p_msc->xferred_len += xferred_bytes; diff --git a/src/device/usbd.c b/src/device/usbd.c index 44c2530ce..9429cf664 100644 --- a/src/device/usbd.c +++ b/src/device/usbd.c @@ -43,9 +43,6 @@ #define CFG_TUD_TASK_QUEUE_SZ 16 #endif -// Debug level of USBD -#define USBD_DBG 2 - //--------------------------------------------------------------------+ // Device Data //--------------------------------------------------------------------+ @@ -81,7 +78,7 @@ tu_static usbd_device_t _usbd_dev; //--------------------------------------------------------------------+ // Class Driver //--------------------------------------------------------------------+ -#if CFG_TUSB_DEBUG >= 2 +#if CFG_TUSB_DEBUG >= CFG_TUD_LOG_LEVEL #define DRIVER_NAME(_name) .name = _name, #else #define DRIVER_NAME(_name) @@ -308,7 +305,7 @@ bool usbd_control_xfer_cb (uint8_t rhport, uint8_t ep_addr, xfer_result_t event, //--------------------------------------------------------------------+ // Debug //--------------------------------------------------------------------+ -#if CFG_TUSB_DEBUG >= 2 +#if CFG_TUSB_DEBUG >= CFG_TUD_LOG_LEVEL tu_static char const* const _usbd_event_str[DCD_EVENT_COUNT] = { "Invalid" , @@ -330,7 +327,7 @@ void usbd_driver_print_control_complete_name(usbd_control_xfer_cb_t callback) usbd_class_driver_t const * driver = get_driver(i); if ( driver && driver->control_xfer_cb == callback ) { - TU_LOG(USBD_DBG, " %s control complete\r\n", driver->name); + TU_LOG_USBD(" %s control complete\r\n", driver->name); return; } } @@ -396,10 +393,10 @@ bool tud_init (uint8_t rhport) // skip if already initialized if ( tud_inited() ) return true; - TU_LOG(USBD_DBG, "USBD init on controller %u\r\n", rhport); - TU_LOG_INT(USBD_DBG, sizeof(usbd_device_t)); - TU_LOG_INT(USBD_DBG, sizeof(tu_fifo_t)); - TU_LOG_INT(USBD_DBG, sizeof(tu_edpt_stream_t)); + TU_LOG_USBD("USBD init on controller %u\r\n", rhport); + TU_LOG_INT(CFG_TUD_LOG_LEVEL, sizeof(usbd_device_t)); + TU_LOG_INT(CFG_TUD_LOG_LEVEL, sizeof(tu_fifo_t)); + TU_LOG_INT(CFG_TUD_LOG_LEVEL, sizeof(tu_edpt_stream_t)); tu_varclr(&_usbd_dev); @@ -424,7 +421,7 @@ bool tud_init (uint8_t rhport) { usbd_class_driver_t const * driver = get_driver(i); TU_ASSERT(driver); - TU_LOG(USBD_DBG, "%s init\r\n", driver->name); + TU_LOG_USBD("%s init\r\n", driver->name); driver->init(); } @@ -496,21 +493,21 @@ void tud_task_ext(uint32_t timeout_ms, bool in_isr) dcd_event_t event; if ( !osal_queue_receive(_usbd_q, &event, timeout_ms) ) return; -#if CFG_TUSB_DEBUG >= 2 - if (event.event_id == DCD_EVENT_SETUP_RECEIVED) TU_LOG(USBD_DBG, "\r\n"); // extra line for setup - TU_LOG(USBD_DBG, "USBD %s ", event.event_id < DCD_EVENT_COUNT ? _usbd_event_str[event.event_id] : "CORRUPTED"); +#if CFG_TUSB_DEBUG >= CFG_TUD_LOG_LEVEL + if (event.event_id == DCD_EVENT_SETUP_RECEIVED) TU_LOG_USBD("\r\n"); // extra line for setup + TU_LOG_USBD("USBD %s ", event.event_id < DCD_EVENT_COUNT ? _usbd_event_str[event.event_id] : "CORRUPTED"); #endif switch ( event.event_id ) { case DCD_EVENT_BUS_RESET: - TU_LOG(USBD_DBG, ": %s Speed\r\n", tu_str_speed[event.bus_reset.speed]); + TU_LOG_USBD(": %s Speed\r\n", tu_str_speed[event.bus_reset.speed]); usbd_reset(event.rhport); _usbd_dev.speed = event.bus_reset.speed; break; case DCD_EVENT_UNPLUGGED: - TU_LOG(USBD_DBG, "\r\n"); + TU_LOG_USBD("\r\n"); usbd_reset(event.rhport); // invoke callback @@ -518,8 +515,8 @@ void tud_task_ext(uint32_t timeout_ms, bool in_isr) break; case DCD_EVENT_SETUP_RECEIVED: - TU_LOG_PTR(USBD_DBG, &event.setup_received); - TU_LOG(USBD_DBG, "\r\n"); + TU_LOG_PTR(CFG_TUD_LOG_LEVEL, &event.setup_received); + TU_LOG_USBD("\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 @@ -534,7 +531,7 @@ void tud_task_ext(uint32_t timeout_ms, bool in_isr) // Process control request if ( !process_control_request(event.rhport, &event.setup_received) ) { - TU_LOG(USBD_DBG, " Stall EP0\r\n"); + TU_LOG_USBD(" Stall EP0\r\n"); // Failed -> stall both control endpoint IN and OUT dcd_edpt_stall(event.rhport, 0); dcd_edpt_stall(event.rhport, 0 | TUSB_DIR_IN_MASK); @@ -548,7 +545,7 @@ void tud_task_ext(uint32_t timeout_ms, bool in_isr) uint8_t const epnum = tu_edpt_number(ep_addr); uint8_t const ep_dir = tu_edpt_dir(ep_addr); - TU_LOG(USBD_DBG, "on EP %02X with %u bytes\r\n", ep_addr, (unsigned int) event.xfer_complete.len); + TU_LOG_USBD("on EP %02X with %u bytes\r\n", ep_addr, (unsigned int) event.xfer_complete.len); _usbd_dev.ep_status[epnum][ep_dir].busy = 0; _usbd_dev.ep_status[epnum][ep_dir].claimed = 0; @@ -563,7 +560,7 @@ void tud_task_ext(uint32_t timeout_ms, bool in_isr) usbd_class_driver_t const * driver = get_driver( _usbd_dev.ep2drv[epnum][ep_dir] ); TU_ASSERT(driver, ); - TU_LOG(USBD_DBG, " %s xfer callback\r\n", driver->name); + TU_LOG_USBD(" %s xfer callback\r\n", driver->name); driver->xfer_cb(event.rhport, ep_addr, (xfer_result_t) event.xfer_complete.result, event.xfer_complete.len); } } @@ -575,27 +572,27 @@ void tud_task_ext(uint32_t timeout_ms, bool in_isr) // e.g suspend -> resume -> unplug/plug. Skip suspend/resume if not connected if ( _usbd_dev.connected ) { - TU_LOG(USBD_DBG, ": Remote Wakeup = %u\r\n", _usbd_dev.remote_wakeup_en); + TU_LOG_USBD(": Remote Wakeup = %u\r\n", _usbd_dev.remote_wakeup_en); if (tud_suspend_cb) tud_suspend_cb(_usbd_dev.remote_wakeup_en); }else { - TU_LOG(USBD_DBG, " Skipped\r\n"); + TU_LOG_USBD(" Skipped\r\n"); } break; case DCD_EVENT_RESUME: if ( _usbd_dev.connected ) { - TU_LOG(USBD_DBG, "\r\n"); + TU_LOG_USBD("\r\n"); if (tud_resume_cb) tud_resume_cb(); }else { - TU_LOG(USBD_DBG, " Skipped\r\n"); + TU_LOG_USBD(" Skipped\r\n"); } break; case USBD_EVENT_FUNC_CALL: - TU_LOG(USBD_DBG, "\r\n"); + TU_LOG_USBD("\r\n"); if ( event.func_call.func ) event.func_call.func(event.func_call.param); break; @@ -620,7 +617,7 @@ void tud_task_ext(uint32_t timeout_ms, bool in_isr) static bool invoke_class_control(uint8_t rhport, usbd_class_driver_t const * driver, tusb_control_request_t const * request) { usbd_control_set_complete_callback(driver->control_xfer_cb); - TU_LOG(USBD_DBG, " %s control request\r\n", driver->name); + TU_LOG_USBD(" %s control request\r\n", driver->name); return driver->control_xfer_cb(rhport, CONTROL_STAGE_SETUP, request); } @@ -641,11 +638,11 @@ static bool process_control_request(uint8_t rhport, tusb_control_request_t const return tud_vendor_control_xfer_cb(rhport, CONTROL_STAGE_SETUP, p_request); } -#if CFG_TUSB_DEBUG >= 2 +#if CFG_TUSB_DEBUG >= CFG_TUD_LOG_LEVEL if (TUSB_REQ_TYPE_STANDARD == p_request->bmRequestType_bit.type && p_request->bRequest <= TUSB_REQ_SYNCH_FRAME) { - TU_LOG(USBD_DBG, " %s", tu_str_std_request[p_request->bRequest]); - if (TUSB_REQ_GET_DESCRIPTOR != p_request->bRequest) TU_LOG(USBD_DBG, "\r\n"); + TU_LOG_USBD(" %s", tu_str_std_request[p_request->bRequest]); + if (TUSB_REQ_GET_DESCRIPTOR != p_request->bRequest) TU_LOG_USBD("\r\n"); } #endif @@ -701,7 +698,7 @@ static bool process_control_request(uint8_t rhport, tusb_control_request_t const if ( _usbd_dev.cfg_num ) { // already configured: need to clear all endpoints and driver first - TU_LOG(USBD_DBG, " Clear current Configuration (%u) before switching\r\n", _usbd_dev.cfg_num); + TU_LOG_USBD(" Clear current Configuration (%u) before switching\r\n", _usbd_dev.cfg_num); // close all non-control endpoints, cancel all pending transfers if any dcd_edpt_close_all(rhport); @@ -730,7 +727,7 @@ static bool process_control_request(uint8_t rhport, tusb_control_request_t const // Only support remote wakeup for device feature TU_VERIFY(TUSB_REQ_FEATURE_REMOTE_WAKEUP == p_request->wValue); - TU_LOG(USBD_DBG, " Enable Remote Wakeup\r\n"); + TU_LOG_USBD(" Enable Remote Wakeup\r\n"); // Host may enable remote wake up before suspending especially HID device _usbd_dev.remote_wakeup_en = true; @@ -741,7 +738,7 @@ static bool process_control_request(uint8_t rhport, tusb_control_request_t const // Only support remote wakeup for device feature TU_VERIFY(TUSB_REQ_FEATURE_REMOTE_WAKEUP == p_request->wValue); - TU_LOG(USBD_DBG, " Disable Remote Wakeup\r\n"); + TU_LOG_USBD(" Disable Remote Wakeup\r\n"); // Host may disable remote wake up after resuming _usbd_dev.remote_wakeup_en = false; @@ -924,7 +921,7 @@ static bool process_set_config(uint8_t rhport, uint8_t cfg_num) if ( (sizeof(tusb_desc_interface_t) <= drv_len) && (drv_len <= remaining_len) ) { // Open successfully - TU_LOG(USBD_DBG, " %s opened\r\n", driver->name); + TU_LOG_USBD(" %s opened\r\n", driver->name); // Some drivers use 2 or more interfaces but may not have IAD e.g MIDI (always) or // BTH (even CDC) with class in device descriptor (single interface) @@ -983,7 +980,7 @@ static bool process_get_descriptor(uint8_t rhport, tusb_control_request_t const { case TUSB_DESC_DEVICE: { - TU_LOG(USBD_DBG, " Device\r\n"); + TU_LOG_USBD(" Device\r\n"); void* desc_device = (void*) (uintptr_t) tud_descriptor_device_cb(); @@ -1007,7 +1004,7 @@ static bool process_get_descriptor(uint8_t rhport, tusb_control_request_t const case TUSB_DESC_BOS: { - TU_LOG(USBD_DBG, " BOS\r\n"); + TU_LOG_USBD(" BOS\r\n"); // requested by host if USB > 2.0 ( i.e 2.1 or 3.x ) if (!tud_descriptor_bos_cb) return false; @@ -1029,12 +1026,12 @@ static bool process_get_descriptor(uint8_t rhport, tusb_control_request_t const if ( desc_type == TUSB_DESC_CONFIGURATION ) { - TU_LOG(USBD_DBG, " Configuration[%u]\r\n", desc_index); + TU_LOG_USBD(" Configuration[%u]\r\n", desc_index); desc_config = (uintptr_t) tud_descriptor_configuration_cb(desc_index); }else { // Host only request this after getting Device Qualifier descriptor - TU_LOG(USBD_DBG, " Other Speed Configuration\r\n"); + TU_LOG_USBD(" Other Speed Configuration\r\n"); TU_VERIFY( tud_descriptor_other_speed_configuration_cb ); desc_config = (uintptr_t) tud_descriptor_other_speed_configuration_cb(desc_index); } @@ -1050,7 +1047,7 @@ static bool process_get_descriptor(uint8_t rhport, tusb_control_request_t const case TUSB_DESC_STRING: { - TU_LOG(USBD_DBG, " String[%u]\r\n", desc_index); + TU_LOG_USBD(" String[%u]\r\n", desc_index); // String Descriptor always uses the desc set from user uint8_t const* desc_str = (uint8_t const*) tud_descriptor_string_cb(desc_index, tu_le16toh(p_request->wIndex)); @@ -1063,7 +1060,7 @@ static bool process_get_descriptor(uint8_t rhport, tusb_control_request_t const case TUSB_DESC_DEVICE_QUALIFIER: { - TU_LOG(USBD_DBG, " Device Qualifier\r\n"); + TU_LOG_USBD(" Device Qualifier\r\n"); TU_VERIFY( tud_descriptor_device_qualifier_cb ); @@ -1248,7 +1245,7 @@ bool usbd_edpt_xfer(uint8_t rhport, uint8_t ep_addr, uint8_t * buffer, uint16_t // TODO skip ready() check for now since enumeration also use this API // TU_VERIFY(tud_ready()); - TU_LOG(USBD_DBG, " Queue EP %02X with %u bytes ...\r\n", ep_addr, total_bytes); + TU_LOG_USBD(" Queue EP %02X with %u bytes ...\r\n", ep_addr, total_bytes); // Attempt to transfer on a busy endpoint, sound like an race condition ! TU_ASSERT(_usbd_dev.ep_status[epnum][dir].busy == 0); @@ -1265,7 +1262,7 @@ bool usbd_edpt_xfer(uint8_t rhport, uint8_t ep_addr, uint8_t * buffer, uint16_t // DCD error, mark endpoint as ready to allow next transfer _usbd_dev.ep_status[epnum][dir].busy = 0; _usbd_dev.ep_status[epnum][dir].claimed = 0; - TU_LOG(USBD_DBG, "FAILED\r\n"); + TU_LOG_USBD("FAILED\r\n"); TU_BREAKPOINT(); return false; } @@ -1282,7 +1279,7 @@ bool usbd_edpt_xfer_fifo(uint8_t rhport, uint8_t ep_addr, tu_fifo_t * ff, uint16 uint8_t const epnum = tu_edpt_number(ep_addr); uint8_t const dir = tu_edpt_dir(ep_addr); - TU_LOG(USBD_DBG, " Queue ISO EP %02X with %u bytes ... ", ep_addr, total_bytes); + TU_LOG_USBD(" Queue ISO EP %02X with %u bytes ... ", ep_addr, total_bytes); // Attempt to transfer on a busy endpoint, sound like an race condition ! TU_ASSERT(_usbd_dev.ep_status[epnum][dir].busy == 0); @@ -1293,14 +1290,14 @@ bool usbd_edpt_xfer_fifo(uint8_t rhport, uint8_t ep_addr, tu_fifo_t * ff, uint16 if (dcd_edpt_xfer_fifo(rhport, ep_addr, ff, total_bytes)) { - TU_LOG(USBD_DBG, "OK\r\n"); + TU_LOG_USBD("OK\r\n"); return true; }else { // DCD error, mark endpoint as ready to allow next transfer _usbd_dev.ep_status[epnum][dir].busy = 0; _usbd_dev.ep_status[epnum][dir].claimed = 0; - TU_LOG(USBD_DBG, "failed\r\n"); + TU_LOG_USBD("failed\r\n"); TU_BREAKPOINT(); return false; } @@ -1326,7 +1323,7 @@ void usbd_edpt_stall(uint8_t rhport, uint8_t ep_addr) // only stalled if currently cleared if ( !_usbd_dev.ep_status[epnum][dir].stalled ) { - TU_LOG(USBD_DBG, " Stall EP %02X\r\n", ep_addr); + TU_LOG_USBD(" Stall EP %02X\r\n", ep_addr); dcd_edpt_stall(rhport, ep_addr); _usbd_dev.ep_status[epnum][dir].stalled = 1; _usbd_dev.ep_status[epnum][dir].busy = 1; @@ -1343,7 +1340,7 @@ void usbd_edpt_clear_stall(uint8_t rhport, uint8_t ep_addr) // only clear if currently stalled if ( _usbd_dev.ep_status[epnum][dir].stalled ) { - TU_LOG(USBD_DBG, " Clear Stall EP %02X\r\n", ep_addr); + TU_LOG_USBD(" Clear Stall EP %02X\r\n", ep_addr); dcd_edpt_clear_stall(rhport, ep_addr); _usbd_dev.ep_status[epnum][dir].stalled = 0; _usbd_dev.ep_status[epnum][dir].busy = 0; @@ -1371,7 +1368,7 @@ void usbd_edpt_close(uint8_t rhport, uint8_t ep_addr) rhport = _usbd_rhport; TU_ASSERT(dcd_edpt_close, /**/); - TU_LOG(USBD_DBG, " CLOSING Endpoint: 0x%02X\r\n", ep_addr); + TU_LOG_USBD(" CLOSING Endpoint: 0x%02X\r\n", ep_addr); uint8_t const epnum = tu_edpt_number(ep_addr); uint8_t const dir = tu_edpt_dir(ep_addr); diff --git a/src/device/usbd_control.c b/src/device/usbd_control.c index 2afe967b5..c580e6ecf 100644 --- a/src/device/usbd_control.c +++ b/src/device/usbd_control.c @@ -32,10 +32,7 @@ #include "tusb.h" #include "device/usbd_pvt.h" -// Debug level of USBD Control -#define USBD_CONTROL_DEBUG 2 - -#if CFG_TUSB_DEBUG >= USBD_CONTROL_DEBUG +#if CFG_TUSB_DEBUG >= CFG_TUD_LOG_LEVEL extern void usbd_driver_print_control_complete_name(usbd_control_xfer_cb_t callback); #endif @@ -191,7 +188,7 @@ bool usbd_control_xfer_cb (uint8_t rhport, uint8_t ep_addr, xfer_result_t result { TU_VERIFY(_ctrl_xfer.buffer); memcpy(_ctrl_xfer.buffer, _usbd_ctrl_buf, xferred_bytes); - TU_LOG_MEM(USBD_CONTROL_DEBUG, _usbd_ctrl_buf, xferred_bytes, 2); + TU_LOG_MEM(CFG_TUD_LOG_LEVEL, _usbd_ctrl_buf, xferred_bytes, 2); } _ctrl_xfer.total_xferred += (uint16_t) xferred_bytes; @@ -208,7 +205,7 @@ bool usbd_control_xfer_cb (uint8_t rhport, uint8_t ep_addr, xfer_result_t result // callback can still stall control in status phase e.g out data does not make sense if ( _ctrl_xfer.complete_cb ) { - #if CFG_TUSB_DEBUG >= USBD_CONTROL_DEBUG + #if CFG_TUSB_DEBUG >= CFG_TUD_LOG_LEVEL usbd_driver_print_control_complete_name(_ctrl_xfer.complete_cb); #endif diff --git a/src/device/usbd_pvt.h b/src/device/usbd_pvt.h index 8393d3469..940b2858b 100644 --- a/src/device/usbd_pvt.h +++ b/src/device/usbd_pvt.h @@ -33,13 +33,20 @@ extern "C" { #endif +// Level where CFG_TUSB_DEBUG must be at least for USBD is logged +#ifndef CFG_TUD_LOG_LEVEL +#define CFG_TUD_LOG_LEVEL 2 +#endif + +#define TU_LOG_USBD(...) TU_LOG(CFG_TUD_LOG_LEVEL, __VA_ARGS__) + //--------------------------------------------------------------------+ // Class Driver API //--------------------------------------------------------------------+ typedef struct { - #if CFG_TUSB_DEBUG >= 2 + #if CFG_TUSB_DEBUG >= CFG_TUD_LOG_LEVEL char const* name; #endif diff --git a/src/host/usbh.c b/src/host/usbh.c index 184bda23b..ecc672198 100644 --- a/src/host/usbh.c +++ b/src/host/usbh.c @@ -38,17 +38,19 @@ //--------------------------------------------------------------------+ #ifndef CFG_TUH_TASK_QUEUE_SZ -#define CFG_TUH_TASK_QUEUE_SZ 16 + #define CFG_TUH_TASK_QUEUE_SZ 16 #endif #ifndef CFG_TUH_INTERFACE_MAX -#define CFG_TUH_INTERFACE_MAX 8 + #define CFG_TUH_INTERFACE_MAX 8 #endif -// Debug level, TUSB_CFG_DEBUG must be at least this level for debug message -#define USBH_DEBUG 2 +// Level where CFG_TUSB_DEBUG must be at least for USBH is logged +#ifndef CFG_TUH_LOG_LEVEL + #define CFG_TUH_LOG_LEVEL 2 +#endif -#define TU_LOG_USBH(...) TU_LOG(USBH_DEBUG, __VA_ARGS__) +#define TU_LOG_USBH(...) TU_LOG(CFG_TUH_LOG_LEVEL, __VA_ARGS__) //--------------------------------------------------------------------+ // USBH-HCD common data structure @@ -322,12 +324,12 @@ bool tuh_init(uint8_t controller_id) if ( tuh_inited() ) return true; TU_LOG_USBH("USBH init on controller %u\r\n", controller_id); - TU_LOG_INT(USBH_DEBUG, sizeof(usbh_device_t)); - TU_LOG_INT(USBH_DEBUG, sizeof(hcd_event_t)); - TU_LOG_INT(USBH_DEBUG, sizeof(_ctrl_xfer)); - TU_LOG_INT(USBH_DEBUG, sizeof(tuh_xfer_t)); - TU_LOG_INT(USBH_DEBUG, sizeof(tu_fifo_t)); - TU_LOG_INT(USBH_DEBUG, sizeof(tu_edpt_stream_t)); + TU_LOG_INT(CFG_TUH_LOG_LEVEL, sizeof(usbh_device_t)); + TU_LOG_INT(CFG_TUH_LOG_LEVEL, sizeof(hcd_event_t)); + TU_LOG_INT(CFG_TUH_LOG_LEVEL, sizeof(_ctrl_xfer)); + TU_LOG_INT(CFG_TUH_LOG_LEVEL, sizeof(tuh_xfer_t)); + TU_LOG_INT(CFG_TUH_LOG_LEVEL, sizeof(tu_fifo_t)); + TU_LOG_INT(CFG_TUH_LOG_LEVEL, sizeof(tu_edpt_stream_t)); // Event queue _usbh_q = osal_queue_create( &_usbh_qdef ); @@ -450,39 +452,28 @@ void tuh_task_ext(uint32_t timeout_ms, bool in_isr) TU_LOG_USBH("on EP %02X with %u bytes: %s\r\n", ep_addr, (unsigned int) event.xfer_complete.len, tu_str_xfer_result[event.xfer_complete.result]); - if (event.dev_addr == 0) - { + if (event.dev_addr == 0) { // device 0 only has control endpoint TU_ASSERT(epnum == 0, ); usbh_control_xfer_cb(event.dev_addr, ep_addr, (xfer_result_t) event.xfer_complete.result, event.xfer_complete.len); - } - else - { + } else { usbh_device_t* dev = get_device(event.dev_addr); TU_VERIFY(dev && dev->connected, ); dev->ep_status[epnum][ep_dir].busy = 0; dev->ep_status[epnum][ep_dir].claimed = 0; - if ( 0 == epnum ) - { - usbh_control_xfer_cb(event.dev_addr, ep_addr, (xfer_result_t) event.xfer_complete.result, event.xfer_complete.len); - }else - { - uint8_t drv_id = dev->ep2drv[epnum][ep_dir]; - if(drv_id < USBH_CLASS_DRIVER_COUNT) - { - TU_LOG_USBH("%s xfer callback\r\n", usbh_class_drivers[drv_id].name); - usbh_class_drivers[drv_id].xfer_cb(event.dev_addr, ep_addr, (xfer_result_t) event.xfer_complete.result, event.xfer_complete.len); - } - else - { -#if CFG_TUH_API_EDPT_XFER - tuh_xfer_cb_t complete_cb = dev->ep_callback[epnum][ep_dir].complete_cb; - if ( complete_cb ) - { - tuh_xfer_t xfer = - { + if ( 0 == epnum ) { + usbh_control_xfer_cb(event.dev_addr, ep_addr, (xfer_result_t) event.xfer_complete.result, + event.xfer_complete.len); + }else { + // Prefer application callback over built-in one if available. This occurs when tuh_edpt_xfer() is used + // with enabled driver e.g HID endpoint + #if CFG_TUH_API_EDPT_XFER + tuh_xfer_cb_t const complete_cb = dev->ep_callback[epnum][ep_dir].complete_cb; + if ( complete_cb ) { + // re-construct xfer info + tuh_xfer_t xfer = { .daddr = event.dev_addr, .ep_addr = ep_addr, .result = event.xfer_complete.result, @@ -491,16 +482,21 @@ void tuh_task_ext(uint32_t timeout_ms, bool in_isr) .buffer = NULL, // not available .complete_cb = complete_cb, .user_data = dev->ep_callback[epnum][ep_dir].user_data - }; + }; - complete_cb(&xfer); - }else -#endif - { + complete_cb(&xfer); + }else + #endif + { + uint8_t const drv_id = dev->ep2drv[epnum][ep_dir]; + if ( drv_id < USBH_CLASS_DRIVER_COUNT ) { + TU_LOG_USBH("%s xfer callback\r\n", usbh_class_drivers[drv_id].name); + usbh_class_drivers[drv_id].xfer_cb(event.dev_addr, ep_addr, (xfer_result_t) event.xfer_complete.result, + event.xfer_complete.len); + } else { // no driver/callback responsible for this transfer - TU_ASSERT(false, ); + TU_ASSERT(false,); } - } } } @@ -565,7 +561,7 @@ bool tuh_control_xfer (tuh_xfer_t* xfer) TU_LOG_USBH("[%u:%u] %s: ", rhport, daddr, (xfer->setup->bmRequestType_bit.type == TUSB_REQ_TYPE_STANDARD && xfer->setup->bRequest <= TUSB_REQ_SYNCH_FRAME) ? tu_str_std_request[xfer->setup->bRequest] : "Class Request"); - TU_LOG_PTR(USBH_DEBUG, xfer->setup); + TU_LOG_PTR(CFG_TUH_LOG_LEVEL, xfer->setup); TU_LOG_USBH("\r\n"); if (xfer->complete_cb) @@ -671,7 +667,7 @@ static bool usbh_control_xfer_cb (uint8_t dev_addr, uint8_t ep_addr, xfer_result if (request->wLength) { TU_LOG_USBH("[%u:%u] Control data:\r\n", rhport, dev_addr); - TU_LOG_MEM(USBH_DEBUG, _ctrl_xfer.buffer, xferred_bytes, 2); + TU_LOG_MEM(CFG_TUH_LOG_LEVEL, _ctrl_xfer.buffer, xferred_bytes, 2); } _ctrl_xfer.actual_len = (uint16_t) xferred_bytes; @@ -1186,7 +1182,7 @@ static void process_removing_device(uint8_t rhport, uint8_t hub_addr, uint8_t hu TU_LOG_USBH("Device unplugged address = %u\r\n", daddr); if (is_hub_addr(daddr)) { - TU_LOG(USBH_DEBUG, " is a HUB device %u\r\n", daddr); + TU_LOG(CFG_TUH_LOG_LEVEL, " is a HUB device %u\r\n", daddr); // Submit removed event If the device itself is a hub (un-rolled recursive) // TODO a better to unroll recursrive is using array of removing_hubs and mark it here @@ -1657,7 +1653,7 @@ static bool _parse_configuration_descriptor(uint8_t dev_addr, tusb_desc_configur if( drv_id >= USBH_CLASS_DRIVER_COUNT ) { - TU_LOG(USBH_DEBUG, "Interface %u: class = %u subclass = %u protocol = %u is not supported\r\n", + TU_LOG(CFG_TUH_LOG_LEVEL, "Interface %u: class = %u subclass = %u protocol = %u is not supported\r\n", desc_itf->bInterfaceNumber, desc_itf->bInterfaceClass, desc_itf->bInterfaceSubClass, desc_itf->bInterfaceProtocol); } } @@ -1695,7 +1691,7 @@ void usbh_driver_set_config_complete(uint8_t dev_addr, uint8_t itf_num) if (is_hub_addr(dev_addr)) { - TU_LOG(USBH_DEBUG, "HUB address = %u is mounted\r\n", dev_addr); + TU_LOG(CFG_TUH_LOG_LEVEL, "HUB address = %u is mounted\r\n", dev_addr); }else { // Invoke callback if available