usb: dwc3: add tracepoints to aid debugging
When we're debugging hard-to-reproduce and time-sensitive
use cases, printk() poses too much overhead. That's when
the kernel's tracing infrastructure comes into play.
This patch implements a few initial tracepoints for the
dwc3 driver. More traces can be added as necessary in order
to ease the task of debugging dwc3.
Reviewed-by: Paul Zimmerman <paulz@synopsys.com>
Signed-off-by: Felipe Balbi <balbi@ti.com>
diff --git a/drivers/usb/dwc3/ep0.c b/drivers/usb/dwc3/ep0.c
index 994e1d8..b359387 100644
--- a/drivers/usb/dwc3/ep0.c
+++ b/drivers/usb/dwc3/ep0.c
@@ -66,7 +66,7 @@
dep = dwc->eps[epnum];
if (dep->flags & DWC3_EP_BUSY) {
- dev_vdbg(dwc->dev, "%s: still busy\n", dep->name);
+ dwc3_trace(trace_dwc3_ep0, "%s still busy", dep->name);
return 0;
}
@@ -89,7 +89,8 @@
ret = dwc3_send_gadget_ep_cmd(dwc, dep->number,
DWC3_DEPCMD_STARTTRANSFER, ¶ms);
if (ret < 0) {
- dev_dbg(dwc->dev, "failed to send STARTTRANSFER command\n");
+ dwc3_trace(trace_dwc3_ep0, "%s STARTTRANSFER failed",
+ dep->name);
return ret;
}
@@ -154,7 +155,8 @@
if (dwc->ep0state == EP0_STATUS_PHASE)
__dwc3_ep0_do_control_status(dwc, dwc->eps[direction]);
else
- dev_dbg(dwc->dev, "too early for delayed status\n");
+ dwc3_trace(trace_dwc3_ep0,
+ "too early for delayed status");
return 0;
}
@@ -218,7 +220,8 @@
spin_lock_irqsave(&dwc->lock, flags);
if (!dep->endpoint.desc) {
- dev_dbg(dwc->dev, "trying to queue request %p to disabled %s\n",
+ dwc3_trace(trace_dwc3_ep0,
+ "trying to queue request %p to disabled %s",
request, dep->name);
ret = -ESHUTDOWN;
goto out;
@@ -230,7 +233,8 @@
goto out;
}
- dev_vdbg(dwc->dev, "queueing request %p to %s length %d, state '%s'\n",
+ dwc3_trace(trace_dwc3_ep0,
+ "queueing request %p to %s length %d state '%s'",
request, dep->name, request->length,
dwc3_ep0_state_string(dwc->ep0state));
@@ -486,12 +490,13 @@
addr = le16_to_cpu(ctrl->wValue);
if (addr > 127) {
- dev_dbg(dwc->dev, "invalid device address %d\n", addr);
+ dwc3_trace(trace_dwc3_ep0, "invalid device address %d", addr);
return -EINVAL;
}
if (state == USB_STATE_CONFIGURED) {
- dev_dbg(dwc->dev, "trying to set address when configured\n");
+ dwc3_trace(trace_dwc3_ep0,
+ "trying to set address when configured");
return -EINVAL;
}
@@ -557,7 +562,7 @@
dwc3_writel(dwc->regs, DWC3_DCTL, reg);
dwc->resize_fifos = true;
- dev_dbg(dwc->dev, "resize fifos flag SET\n");
+ dwc3_trace(trace_dwc3_ep0, "resize FIFOs flag SET");
}
break;
@@ -681,35 +686,35 @@
switch (ctrl->bRequest) {
case USB_REQ_GET_STATUS:
- dev_vdbg(dwc->dev, "USB_REQ_GET_STATUS\n");
+ dwc3_trace(trace_dwc3_ep0, "USB_REQ_GET_STATUS\n");
ret = dwc3_ep0_handle_status(dwc, ctrl);
break;
case USB_REQ_CLEAR_FEATURE:
- dev_vdbg(dwc->dev, "USB_REQ_CLEAR_FEATURE\n");
+ dwc3_trace(trace_dwc3_ep0, "USB_REQ_CLEAR_FEATURE\n");
ret = dwc3_ep0_handle_feature(dwc, ctrl, 0);
break;
case USB_REQ_SET_FEATURE:
- dev_vdbg(dwc->dev, "USB_REQ_SET_FEATURE\n");
+ dwc3_trace(trace_dwc3_ep0, "USB_REQ_SET_FEATURE\n");
ret = dwc3_ep0_handle_feature(dwc, ctrl, 1);
break;
case USB_REQ_SET_ADDRESS:
- dev_vdbg(dwc->dev, "USB_REQ_SET_ADDRESS\n");
+ dwc3_trace(trace_dwc3_ep0, "USB_REQ_SET_ADDRESS\n");
ret = dwc3_ep0_set_address(dwc, ctrl);
break;
case USB_REQ_SET_CONFIGURATION:
- dev_vdbg(dwc->dev, "USB_REQ_SET_CONFIGURATION\n");
+ dwc3_trace(trace_dwc3_ep0, "USB_REQ_SET_CONFIGURATION\n");
ret = dwc3_ep0_set_config(dwc, ctrl);
break;
case USB_REQ_SET_SEL:
- dev_vdbg(dwc->dev, "USB_REQ_SET_SEL\n");
+ dwc3_trace(trace_dwc3_ep0, "USB_REQ_SET_SEL\n");
ret = dwc3_ep0_set_sel(dwc, ctrl);
break;
case USB_REQ_SET_ISOCH_DELAY:
- dev_vdbg(dwc->dev, "USB_REQ_SET_ISOCH_DELAY\n");
+ dwc3_trace(trace_dwc3_ep0, "USB_REQ_SET_ISOCH_DELAY\n");
ret = dwc3_ep0_set_isoch_delay(dwc, ctrl);
break;
default:
- dev_vdbg(dwc->dev, "Forwarding to gadget driver\n");
+ dwc3_trace(trace_dwc3_ep0, "Forwarding to gadget driver\n");
ret = dwc3_ep0_delegate_req(dwc, ctrl);
break;
}
@@ -727,6 +732,8 @@
if (!dwc->gadget_driver)
goto out;
+ trace_dwc3_ctrl_req(ctrl);
+
len = le16_to_cpu(ctrl->wLength);
if (!len) {
dwc->three_stage_setup = false;
@@ -775,7 +782,7 @@
status = DWC3_TRB_SIZE_TRBSTS(trb->size);
if (status == DWC3_TRBSTS_SETUP_PENDING) {
- dev_dbg(dwc->dev, "Setup Pending received\n");
+ dwc3_trace(trace_dwc3_ep0, "Setup Pending received");
if (r)
dwc3_gadget_giveback(ep0, r, -ECONNRESET);
@@ -835,7 +842,7 @@
ret = dwc3_gadget_set_test_mode(dwc, dwc->test_mode_nr);
if (ret < 0) {
- dev_dbg(dwc->dev, "Invalid Test #%d\n",
+ dwc3_trace(trace_dwc3_ep0, "Invalid Test #%d",
dwc->test_mode_nr);
dwc3_ep0_stall_and_restart(dwc);
return;
@@ -844,7 +851,7 @@
status = DWC3_TRB_SIZE_TRBSTS(trb->size);
if (status == DWC3_TRBSTS_SETUP_PENDING)
- dev_dbg(dwc->dev, "Setup Pending received\n");
+ dwc3_trace(trace_dwc3_ep0, "Setup Pending received\n");
dwc->ep0state = EP0_SETUP_PHASE;
dwc3_ep0_out_start(dwc);
@@ -861,17 +868,17 @@
switch (dwc->ep0state) {
case EP0_SETUP_PHASE:
- dev_vdbg(dwc->dev, "Inspecting Setup Bytes\n");
+ dwc3_trace(trace_dwc3_ep0, "Setup Phase");
dwc3_ep0_inspect_setup(dwc, event);
break;
case EP0_DATA_PHASE:
- dev_vdbg(dwc->dev, "Data Phase\n");
+ dwc3_trace(trace_dwc3_ep0, "Data Phase");
dwc3_ep0_complete_data(dwc, event);
break;
case EP0_STATUS_PHASE:
- dev_vdbg(dwc->dev, "Status Phase\n");
+ dwc3_trace(trace_dwc3_ep0, "Status Phase");
dwc3_ep0_complete_status(dwc, event);
break;
default:
@@ -947,7 +954,7 @@
static void __dwc3_ep0_do_control_status(struct dwc3 *dwc, struct dwc3_ep *dep)
{
if (dwc->resize_fifos) {
- dev_dbg(dwc->dev, "starting to resize fifos\n");
+ dwc3_trace(trace_dwc3_ep0, "Resizing FIFOs");
dwc3_gadget_resize_tx_fifos(dwc);
dwc->resize_fifos = 0;
}
@@ -988,7 +995,7 @@
switch (event->status) {
case DEPEVT_STATUS_CONTROL_DATA:
- dev_vdbg(dwc->dev, "Control Data\n");
+ dwc3_trace(trace_dwc3_ep0, "Control Data");
/*
* We already have a DATA transfer in the controller's cache,
@@ -1002,7 +1009,8 @@
if (dwc->ep0_expect_in != event->endpoint_number) {
struct dwc3_ep *dep = dwc->eps[dwc->ep0_expect_in];
- dev_vdbg(dwc->dev, "Wrong direction for Data phase\n");
+ dwc3_trace(trace_dwc3_ep0,
+ "Wrong direction for Data phase");
dwc3_ep0_end_control_data(dwc, dep);
dwc3_ep0_stall_and_restart(dwc);
return;
@@ -1014,13 +1022,13 @@
if (dwc->ep0_next_event != DWC3_EP0_NRDY_STATUS)
return;
- dev_vdbg(dwc->dev, "Control Status\n");
+ dwc3_trace(trace_dwc3_ep0, "Control Status");
dwc->ep0state = EP0_STATUS_PHASE;
if (dwc->delayed_status) {
WARN_ON_ONCE(event->endpoint_number != 1);
- dev_vdbg(dwc->dev, "Mass Storage delayed status\n");
+ dwc3_trace(trace_dwc3_ep0, "Delayed Status");
return;
}
@@ -1033,7 +1041,7 @@
{
u8 epnum = event->endpoint_number;
- dev_dbg(dwc->dev, "%s while ep%d%s in state '%s'\n",
+ dwc3_trace(trace_dwc3_ep0, "%s while ep%d%s in state '%s'",
dwc3_ep_event_string(event->endpoint_event),
epnum >> 1, (epnum & 1) ? "in" : "out",
dwc3_ep0_state_string(dwc->ep0state));