minor debug log

This commit is contained in:
hathach 2022-12-21 11:46:58 +07:00
parent d1ea3844f7
commit cb2af4c0bc
3 changed files with 63 additions and 43 deletions

View File

@ -33,6 +33,12 @@
#include "cdc_host.h"
// Debug level, TUSB_CFG_DEBUG must be at least this level for debug message
#define CDCH_DEBUG 2
#define TU_LOG_CDCH(...) TU_LOG(CDCH_DEBUG, __VA_ARGS__)
//--------------------------------------------------------------------+
// MACRO CONSTANT TYPEDEF
//--------------------------------------------------------------------+
@ -348,6 +354,8 @@ bool tuh_cdc_set_control_line_state(uint8_t idx, uint16_t line_state, tuh_xfer_c
cdch_interface_t* p_cdc = get_itf(idx);
TU_VERIFY(p_cdc && p_cdc->acm_capability.support_line_request);
TU_LOG_CDCH("CDC Set Control Line State\r\n");
tusb_control_request_t const request =
{
.bmRequestType_bit =

View File

@ -33,6 +33,11 @@
#include "msc_host.h"
// Debug level, TUSB_CFG_DEBUG must be at least this level for debug message
#define MSCH_DEBUG 2
#define TU_LOG_MSCH(...) TU_LOG(MSCH_DEBUG, __VA_ARGS__)
//--------------------------------------------------------------------+
// MACRO CONSTANT TYPEDEF
//--------------------------------------------------------------------+
@ -417,7 +422,7 @@ bool msch_set_config(uint8_t dev_addr, uint8_t itf_num)
p_msc->configured = true;
//------------- Get Max Lun -------------//
TU_LOG2("MSC Get Max Lun\r\n");
TU_LOG_MSCH("MSC Get Max Lun\r\n");
tusb_control_request_t const request =
{
.bmRequestType_bit =
@ -456,7 +461,7 @@ static void config_get_maxlun_complete (tuh_xfer_t* xfer)
p_msc->max_lun++; // MAX LUN is minus 1 by specs
// TODO multiple LUN support
TU_LOG2("SCSI Test Unit Ready\r\n");
TU_LOG_MSCH("SCSI Test Unit Ready\r\n");
uint8_t const lun = 0;
tuh_msc_test_unit_ready(daddr, lun, config_test_unit_ready_complete, 0);
}
@ -469,14 +474,14 @@ static bool config_test_unit_ready_complete(uint8_t dev_addr, tuh_msc_complete_d
if (csw->status == 0)
{
// Unit is ready, read its capacity
TU_LOG2("SCSI Read Capacity\r\n");
TU_LOG_MSCH("SCSI Read Capacity\r\n");
tuh_msc_read_capacity(dev_addr, cbw->lun, (scsi_read_capacity10_resp_t*) ((void*) _msch_buffer), config_read_capacity_complete, 0);
}else
{
// Note: During enumeration, some device fails Test Unit Ready and require a few retries
// with Request Sense to start working !!
// TODO limit number of retries
TU_LOG2("SCSI Request Sense\r\n");
TU_LOG_MSCH("SCSI Request Sense\r\n");
TU_ASSERT(tuh_msc_request_sense(dev_addr, cbw->lun, _msch_buffer, config_request_sense_complete, 0));
}

View File

@ -46,8 +46,10 @@
#define CFG_TUH_INTERFACE_MAX 8
#endif
// Debug level of USBD
#define USBH_DBG_LVL 2
// Debug level, TUSB_CFG_DEBUG must be at least this level for debug message
#define USBH_DEBUG 2
#define TU_LOG_USBH(...) TU_LOG(USBH_DEBUG, __VA_ARGS__)
//--------------------------------------------------------------------+
// USBH-HCD common data structure
@ -324,11 +326,11 @@ bool tuh_init(uint8_t controller_id)
// skip if already initialized
if ( tuh_inited() ) return true;
TU_LOG2("USBH init on controller %u\r\n", controller_id);
TU_LOG2_INT(sizeof(usbh_device_t));
TU_LOG2_INT(sizeof(hcd_event_t));
TU_LOG2_INT(sizeof(_ctrl_xfer));
TU_LOG2_INT(sizeof(tuh_xfer_t));
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));
// Event queue
_usbh_q = osal_queue_create( &_usbh_qdef );
@ -353,7 +355,7 @@ bool tuh_init(uint8_t controller_id)
// Class drivers
for (uint8_t drv_id = 0; drv_id < USBH_CLASS_DRIVER_COUNT; drv_id++)
{
TU_LOG2("%s init\r\n", usbh_class_drivers[drv_id].name);
TU_LOG_USBH("%s init\r\n", usbh_class_drivers[drv_id].name);
usbh_class_drivers[drv_id].init();
}
@ -401,12 +403,12 @@ void tuh_task_ext(uint32_t timeout_ms, bool in_isr)
case HCD_EVENT_DEVICE_ATTACH:
// TODO due to the shared _usbh_ctrl_buf, we must complete enumerating
// one device before enumerating another one.
TU_LOG2("[%u:] USBH DEVICE ATTACH\r\n", event.rhport);
TU_LOG_USBH("[%u:] USBH DEVICE ATTACH\r\n", event.rhport);
enum_new_device(&event);
break;
case HCD_EVENT_DEVICE_REMOVE:
TU_LOG2("[%u:%u:%u] USBH DEVICE REMOVED\r\n", event.rhport, event.connection.hub_addr, event.connection.hub_port);
TU_LOG_USBH("[%u:%u:%u] USBH DEVICE REMOVED\r\n", event.rhport, event.connection.hub_addr, event.connection.hub_port);
process_device_unplugged(event.rhport, event.connection.hub_addr, event.connection.hub_port);
#if CFG_TUH_HUB
@ -425,7 +427,7 @@ void tuh_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_LOG2("on EP %02X with %u bytes\r\n", ep_addr, (unsigned int) event.xfer_complete.len);
TU_LOG_USBH("on EP %02X with %u bytes\r\n", ep_addr, (unsigned int) event.xfer_complete.len);
if (event.dev_addr == 0)
{
@ -449,7 +451,7 @@ void tuh_task_ext(uint32_t timeout_ms, bool in_isr)
uint8_t drv_id = dev->ep2drv[epnum][ep_dir];
if(drv_id < USBH_CLASS_DRIVER_COUNT)
{
TU_LOG2("%s xfer callback\r\n", usbh_class_drivers[drv_id].name);
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, event.xfer_complete.result, event.xfer_complete.len);
}
else
@ -539,9 +541,11 @@ bool tuh_control_xfer (tuh_xfer_t* xfer)
TU_VERIFY(is_idle);
const uint8_t rhport = usbh_get_rhport(daddr);
TU_LOG2("[%u:%u] %s: ", rhport, daddr, xfer->setup->bRequest <= TUSB_REQ_SYNCH_FRAME ? tu_str_std_request[xfer->setup->bRequest] : "Unknown Request");
TU_LOG2_PTR(xfer->setup);
TU_LOG2("\r\n");
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_USBH("\r\n");
if (xfer->complete_cb)
{
@ -585,7 +589,7 @@ TU_ATTR_ALWAYS_INLINE static inline void _set_control_xfer_stage(uint8_t stage)
static void _xfer_complete(uint8_t daddr, xfer_result_t result)
{
TU_LOG2("\r\n");
TU_LOG_USBH("\r\n");
// duplicate xfer since user can execute control transfer within callback
tusb_control_request_t const request = _ctrl_xfer.request;
@ -643,8 +647,8 @@ static bool usbh_control_xfer_cb (uint8_t dev_addr, uint8_t ep_addr, xfer_result
case CONTROL_STAGE_DATA:
if (request->wLength)
{
TU_LOG2("[%u:%u] Control data:\r\n", rhport, dev_addr);
TU_LOG2_MEM(_ctrl_xfer.buffer, xferred_bytes, 2);
TU_LOG_USBH("[%u:%u] Control data:\r\n", rhport, dev_addr);
TU_LOG_MEM(USBH_DEBUG, _ctrl_xfer.buffer, xferred_bytes, 2);
}
_ctrl_xfer.actual_len = (uint16_t) xferred_bytes;
@ -760,7 +764,7 @@ bool usbh_edpt_xfer_with_callback(uint8_t dev_addr, uint8_t ep_addr, uint8_t * b
uint8_t const dir = tu_edpt_dir(ep_addr);
tu_edpt_state_t* ep_state = &dev->ep_status[epnum][dir];
TU_LOG2(" Queue EP %02X with %u bytes ... ", ep_addr, total_bytes);
TU_LOG_USBH(" Queue EP %02X with %u bytes ... ", ep_addr, total_bytes);
// Attempt to transfer on a busy endpoint, sound like an race condition !
TU_ASSERT(ep_state->busy == 0);
@ -776,7 +780,7 @@ bool usbh_edpt_xfer_with_callback(uint8_t dev_addr, uint8_t ep_addr, uint8_t * b
if ( hcd_edpt_xfer(dev->rhport, dev_addr, ep_addr, buffer, total_bytes) )
{
TU_LOG2("OK\r\n");
TU_LOG_USBH("OK\r\n");
return true;
}else
{
@ -791,7 +795,7 @@ bool usbh_edpt_xfer_with_callback(uint8_t dev_addr, uint8_t ep_addr, uint8_t * b
static bool usbh_edpt_control_open(uint8_t dev_addr, uint8_t max_packet_size)
{
TU_LOG2("[%u:%u] Open EP0 with Size = %u\r\n", usbh_get_rhport(dev_addr), dev_addr, max_packet_size);
TU_LOG_USBH("[%u:%u] Open EP0 with Size = %u\r\n", usbh_get_rhport(dev_addr), dev_addr, max_packet_size);
tusb_desc_endpoint_t ep0_desc =
{
@ -960,7 +964,7 @@ bool tuh_descriptor_get_serial_string(uint8_t daddr, uint16_t language_id, void*
bool tuh_descriptor_get_hid_report(uint8_t daddr, uint8_t itf_num, uint8_t desc_type, uint8_t index, void* buffer, uint16_t len,
tuh_xfer_cb_t complete_cb, uintptr_t user_data)
{
TU_LOG2("HID Get Report Descriptor\r\n");
TU_LOG_USBH("HID Get Report Descriptor\r\n");
tusb_control_request_t const request =
{
.bmRequestType_bit =
@ -999,7 +1003,7 @@ bool tuh_descriptor_get_hid_report(uint8_t daddr, uint8_t itf_num, uint8_t desc_
bool tuh_configuration_set(uint8_t daddr, uint8_t config_num,
tuh_xfer_cb_t complete_cb, uintptr_t user_data)
{
TU_LOG2("Set Configuration = %d\r\n", config_num);
TU_LOG_USBH("Set Configuration = %d\r\n", config_num);
tusb_control_request_t const request =
{
@ -1103,11 +1107,11 @@ static void process_device_unplugged(uint8_t rhport, uint8_t hub_addr, uint8_t h
(hub_port == 0 || dev->hub_port == hub_port) && // hub_port = 0 means all devices of downstream hub
dev->connected)
{
TU_LOG2(" Address = %u\r\n", dev_addr);
TU_LOG_USBH(" Address = %u\r\n", dev_addr);
if (is_hub_addr(dev_addr))
{
TU_LOG(USBH_DBG_LVL, "HUB address = %u is unmounted\r\n", dev_addr);
TU_LOG(USBH_DEBUG, "HUB address = %u is unmounted\r\n", dev_addr);
// If the device itself is a usb hub, unplug downstream devices.
// FIXME un-roll recursive calls to prevent potential stack overflow
process_device_unplugged(rhport, dev_addr, 0);
@ -1120,7 +1124,7 @@ static void process_device_unplugged(uint8_t rhport, uint8_t hub_addr, uint8_t h
// Close class driver
for (uint8_t drv_id = 0; drv_id < USBH_CLASS_DRIVER_COUNT; drv_id++)
{
TU_LOG2("%s close\r\n", usbh_class_drivers[drv_id].name);
TU_LOG_USBH("%s close\r\n", usbh_class_drivers[drv_id].name);
usbh_class_drivers[drv_id].close(dev_addr);
}
@ -1245,7 +1249,7 @@ static void process_enumeration(tuh_xfer_t* xfer)
TU_ASSERT( usbh_edpt_control_open(addr0, 8), );
// Get first 8 bytes of device descriptor for Control Endpoint size
TU_LOG2("Get 8 byte of Device Descriptor\r\n");
TU_LOG_USBH("Get 8 byte of Device Descriptor\r\n");
TU_ASSERT(tuh_descriptor_get_device(addr0, _usbh_ctrl_buf, 8, process_enumeration, ENUM_SET_ADDR), );
}
break;
@ -1254,7 +1258,7 @@ static void process_enumeration(tuh_xfer_t* xfer)
case ENUM_RESET_2:
// TODO not used by now, but may be needed for some devices !?
// Reset device again before Set Address
TU_LOG2("Port reset2 \r\n");
TU_LOG_USBH("Port reset2 \r\n");
if (_dev0.hub_addr == 0)
{
// connected directly to roothub
@ -1294,7 +1298,7 @@ static void process_enumeration(tuh_xfer_t* xfer)
TU_ASSERT( usbh_edpt_control_open(new_addr, new_dev->ep0_size), );
// Get full device descriptor
TU_LOG2("Get Device Descriptor\r\n");
TU_LOG_USBH("Get Device Descriptor\r\n");
TU_ASSERT(tuh_descriptor_get_device(new_addr, _usbh_ctrl_buf, sizeof(tusb_desc_device_t), process_enumeration, ENUM_GET_9BYTE_CONFIG_DESC), );
}
break;
@ -1315,7 +1319,7 @@ static void process_enumeration(tuh_xfer_t* xfer)
// Get 9-byte for total length
uint8_t const config_idx = CONFIG_NUM - 1;
TU_LOG2("Get Configuration[0] Descriptor (9 bytes)\r\n");
TU_LOG_USBH("Get Configuration[0] Descriptor (9 bytes)\r\n");
TU_ASSERT( tuh_descriptor_get_configuration(daddr, config_idx, _usbh_ctrl_buf, 9, process_enumeration, ENUM_GET_FULL_CONFIG_DESC), );
}
break;
@ -1332,7 +1336,7 @@ static void process_enumeration(tuh_xfer_t* xfer)
// Get full configuration descriptor
uint8_t const config_idx = CONFIG_NUM - 1;
TU_LOG2("Get Configuration[0] Descriptor\r\n");
TU_LOG_USBH("Get Configuration[0] Descriptor\r\n");
TU_ASSERT( tuh_descriptor_get_configuration(daddr, config_idx, _usbh_ctrl_buf, total_len, process_enumeration, ENUM_SET_CONFIG), );
}
break;
@ -1347,7 +1351,7 @@ static void process_enumeration(tuh_xfer_t* xfer)
case ENUM_CONFIG_DRIVER:
{
TU_LOG2("Device configured\r\n");
TU_LOG_USBH("Device configured\r\n");
usbh_device_t* dev = get_device(daddr);
TU_ASSERT(dev, );
@ -1387,7 +1391,7 @@ static bool enum_new_device(hcd_event_t* event)
if ( !hcd_port_connect_status(_dev0.rhport) ) return true;
_dev0.speed = hcd_port_speed_get(_dev0.rhport );
TU_LOG2("%s Speed\r\n", tu_str_speed[_dev0.speed]);
TU_LOG_USBH("%s Speed\r\n", tu_str_speed[_dev0.speed]);
// fake transfer to kick-off the enumeration process
tuh_xfer_t xfer;
@ -1444,7 +1448,7 @@ static bool enum_request_set_addr(void)
uint8_t const new_addr = get_new_address(desc_device->bDeviceClass == TUSB_CLASS_HUB);
TU_ASSERT(new_addr != 0);
TU_LOG2("Set Address = %d\r\n", new_addr);
TU_LOG_USBH("Set Address = %d\r\n", new_addr);
usbh_device_t* new_dev = get_device(new_addr);
@ -1488,9 +1492,12 @@ static bool _parse_configuration_descriptor(uint8_t dev_addr, tusb_desc_configur
{
usbh_device_t* dev = get_device(dev_addr);
uint8_t const* desc_end = ((uint8_t const*) desc_cfg) + tu_le16toh(desc_cfg->wTotalLength);
uint16_t const total_len = tu_le16toh(desc_cfg->wTotalLength);
uint8_t const* desc_end = ((uint8_t const*) desc_cfg) + total_len;
uint8_t const* p_desc = tu_desc_next(desc_cfg);
TU_LOG_USBH("Parsing Configuration descriptor (wTotalLength = %u)\r\n", total_len);
// parse each interfaces
while( p_desc < desc_end )
{
@ -1535,7 +1542,7 @@ static bool _parse_configuration_descriptor(uint8_t dev_addr, tusb_desc_configur
if ( driver->open(dev->rhport, dev_addr, desc_itf, drv_len) )
{
// open successfully
TU_LOG2(" %s opened\r\n", driver->name);
TU_LOG_USBH(" %s opened\r\n", driver->name);
// bind (associated) interfaces to found driver
for(uint8_t i=0; i<assoc_itf_count; i++)
@ -1555,7 +1562,7 @@ static bool _parse_configuration_descriptor(uint8_t dev_addr, tusb_desc_configur
if( drv_id >= USBH_CLASS_DRIVER_COUNT )
{
TU_LOG(USBH_DBG_LVL, "Interface %u: class = %u subclass = %u protocol = %u is not supported\r\n",
TU_LOG(USBH_DEBUG, "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);
}
}
@ -1580,7 +1587,7 @@ void usbh_driver_set_config_complete(uint8_t dev_addr, uint8_t itf_num)
if (drv_id != DRVID_INVALID)
{
usbh_class_driver_t const * driver = &usbh_class_drivers[drv_id];
TU_LOG2("%s set config: itf = %u\r\n", driver->name, itf_num);
TU_LOG_USBH("%s set config: itf = %u\r\n", driver->name, itf_num);
driver->set_config(dev_addr, itf_num);
break;
}
@ -1593,7 +1600,7 @@ void usbh_driver_set_config_complete(uint8_t dev_addr, uint8_t itf_num)
if (is_hub_addr(dev_addr))
{
TU_LOG(USBH_DBG_LVL, "HUB address = %u is mounted\r\n", dev_addr);
TU_LOG(USBH_DEBUG, "HUB address = %u is mounted\r\n", dev_addr);
}else
{
// Invoke callback if available