[v2] usb: dwc3: add tracepoints to aid debugging

Message ID 20140905145546.GD24449@saruman.home
State New
Headers show

Commit Message

Felipe Balbi Sept. 5, 2014, 2:55 p.m.
On Wed, Sep 03, 2014 at 11:58:26AM +0530, Pratyush Anand wrote:
> On Wed, Aug 27, 2014 at 05:26:37AM +0800, Felipe Balbi wrote:
> 
> Hi Felipe,
> 
> > Hi,
> > 
> > On Tue, Aug 26, 2014 at 09:21:55PM +0000, Paul Zimmerman wrote:
> > > > From: Felipe Balbi [mailto:balbi@ti.com]
> > > > Sent: Tuesday, August 26, 2014 1:42 PM
> > > > 
> > > > On Fri, Aug 22, 2014 at 04:56:46PM -0500, Felipe Balbi wrote:
> > > 
> > > ...
> > > 
> > > > yeah, it took longer than expected (been busy lately), but here's an
> > > > example trace with all trace points enabled:
> > > > 
> > > > # tracer: nop
> > > > #
> > > > # entries-in-buffer/entries-written: 1038/1038   #P:1
> > > > #
> > > > #                              _-----=> irqs-off
> > > > #                             / _----=> need-resched
> > > > #                            | / _---=> hardirq/softirq
> > > > #                            || / _--=> preempt-depth
> > > > #                            ||| /     delay
> > > > #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
> > > > #              | |       |   ||||       |         |
> > > >           <idle>-0     [000] d.h.   155.653881: dwc3_readl: add fa39c40c value 00000004
> > > >           <idle>-0     [000] d.h.   155.653903: dwc3_readl: add fa39c408 value 00000100
> > > >           <idle>-0     [000] d.h.   155.653908: dwc3_writel: addr fa39c408 value 80000100
> > > 
> > > Looks like there is an inconsistency between readl/writel (add vs.
> > > addr).
> > 
> > eagle eyes :-)
> > 
> > > Other than that, I really like this.
> > > 
> > > Reviewed-by: Paul Zimmerman <paulz@synopsys.com>
> > 
> > thanks, pushed to my dwc3-tracepoints branch with your Reviewed-by, if
> > nobody makes any other comments until Friday, I'll promote it to
> > testing/next and later to next.
> 
> If we can also add following two items:
> -- depcmd: trace depcmd params and cmd in dwc3_send_gadget_ep_cmd 
> -- TRB: trace trb fields, trb address and ep number for which trb has
> been prepared in dwc3_prepare_one_trb
> 
> These items were pretty helpful in debugging isoc issues.

here's a diff adding those, I'll combine into original patch and resend
full series here:

Patch

diff --git a/drivers/usb/dwc3/gadget.c b/drivers/usb/dwc3/gadget.c
index 0642ff9..f2dbaca 100644
--- a/drivers/usb/dwc3/gadget.c
+++ b/drivers/usb/dwc3/gadget.c
@@ -279,8 +279,7 @@  int dwc3_send_gadget_generic_command(struct dwc3 *dwc, unsigned cmd, u32 param)
 	u32		timeout = 500;
 	u32		reg;
 
-	dev_vdbg(dwc->dev, "generic cmd '%s' [%d] param %08x\n",
-			dwc3_gadget_generic_cmd_string(cmd), cmd, param);
+	trace_dwc3_gadget_generic_cmd(cmd, param);
 
 	dwc3_writel(dwc->regs, DWC3_DGCMDPAR, param);
 	dwc3_writel(dwc->regs, DWC3_DGCMD, cmd | DWC3_DGCMD_CMDACT);
@@ -311,10 +310,7 @@  int dwc3_send_gadget_ep_cmd(struct dwc3 *dwc, unsigned ep,
 	u32			timeout = 500;
 	u32			reg;
 
-	dev_vdbg(dwc->dev, "%s: cmd '%s' [%d] params %08x %08x %08x\n",
-			dep->name,
-			dwc3_gadget_ep_cmd_string(cmd), cmd, params->param0,
-			params->param1, params->param2);
+	trace_dwc3_gadget_ep_cmd(dep, cmd, params);
 
 	dwc3_writel(dwc->regs, DWC3_DEPCMDPAR0(ep), params->param0);
 	dwc3_writel(dwc->regs, DWC3_DEPCMDPAR1(ep), params->param1);
@@ -803,6 +799,8 @@  static void dwc3_prepare_one_trb(struct dwc3_ep *dep,
 		trb->ctrl |= DWC3_TRB_CTRL_SID_SOFN(req->request.stream_id);
 
 	trb->ctrl |= DWC3_TRB_CTRL_HWO;
+
+	trace_dwc3_prepare_trb(dep, trb);
 }
 
 /*
@@ -1760,6 +1758,8 @@  static int __dwc3_cleanup_done_trbs(struct dwc3 *dwc, struct dwc3_ep *dep,
 	unsigned int		s_pkt = 0;
 	unsigned int		trb_status;
 
+	trace_dwc3_complete_trb(dep, trb);
+
 	if ((trb->ctrl & DWC3_TRB_CTRL_HWO) && status != -ESHUTDOWN)
 		/*
 		 * We continue despite the error. There is not much we
diff --git a/drivers/usb/dwc3/trace.h b/drivers/usb/dwc3/trace.h
index 992cc38..78aff1d 100644
--- a/drivers/usb/dwc3/trace.h
+++ b/drivers/usb/dwc3/trace.h
@@ -25,6 +25,7 @@ 
 #include <linux/tracepoint.h>
 #include <asm/byteorder.h>
 #include "core.h"
+#include "debug.h"
 
 DECLARE_EVENT_CLASS(dwc3_log_msg,
 	TP_PROTO(struct va_format *vaf),
@@ -130,6 +131,82 @@  DEFINE_EVENT(dwc3_log_request, dwc3_gadget_giveback,
 	TP_ARGS(req)
 );
 
+DECLARE_EVENT_CLASS(dwc3_log_generic_cmd,
+	TP_PROTO(unsigned int cmd, u32 param),
+	TP_ARGS(cmd, param),
+	TP_STRUCT__entry(
+		__field(unsigned int, cmd)
+		__field(u32, param)
+	),
+	TP_fast_assign(
+		__entry->cmd = cmd;
+		__entry->param = param;
+	),
+	TP_printk("cmd '%s' [%d] param %08x\n",
+		dwc3_gadget_generic_cmd_string(__entry->cmd),
+		__entry->cmd, __entry->param
+	)
+);
+
+DEFINE_EVENT(dwc3_log_generic_cmd, dwc3_gadget_generic_cmd,
+	TP_PROTO(unsigned int cmd, u32 param),
+	TP_ARGS(cmd, param)
+);
+
+DECLARE_EVENT_CLASS(dwc3_log_gadget_ep_cmd,
+	TP_PROTO(struct dwc3_ep *dep, unsigned int cmd,
+		struct dwc3_gadget_ep_cmd_params *params),
+	TP_ARGS(dep, cmd, params),
+	TP_STRUCT__entry(
+		__field(struct dwc3_ep *, dep)
+		__field(unsigned int, cmd)
+		__field(struct dwc3_gadget_ep_cmd_params *, params)
+	),
+	TP_fast_assign(
+		__entry->dep = dep;
+		__entry->cmd = cmd;
+		__entry->params = params;
+	),
+	TP_printk("%s: cmd '%s' [%d] params %08x %08x %08x\n",
+		__entry->dep->name, dwc3_gadget_ep_cmd_string(__entry->cmd),
+		__entry->cmd, __entry->params->param0,
+		__entry->params->param1, __entry->params->param2
+	)
+);
+
+DEFINE_EVENT(dwc3_log_gadget_ep_cmd, dwc3_gadget_ep_cmd,
+	TP_PROTO(struct dwc3_ep *dep, unsigned int cmd,
+		struct dwc3_gadget_ep_cmd_params *params),
+	TP_ARGS(dep, cmd, params)
+);
+
+DECLARE_EVENT_CLASS(dwc3_log_trb,
+	TP_PROTO(struct dwc3_ep *dep, struct dwc3_trb *trb),
+	TP_ARGS(dep, trb),
+	TP_STRUCT__entry(
+		__field(struct dwc3_ep *, dep)
+		__field(struct dwc3_trb *, trb)
+	),
+	TP_fast_assign(
+		__entry->dep = dep;
+		__entry->trb = trb;
+	),
+	TP_printk("%s: trb %p bph %08x bpl %08x size %08x ctrl %08x\n",
+		__entry->dep->name, __entry->trb, __entry->trb->bph,
+		__entry->trb->bpl, __entry->trb->size, __entry->trb->ctrl
+	)
+);
+
+DEFINE_EVENT(dwc3_log_trb, dwc3_prepare_trb,
+	TP_PROTO(struct dwc3_ep *dep, struct dwc3_trb *trb),
+	TP_ARGS(dep, trb)
+);
+
+DEFINE_EVENT(dwc3_log_trb, dwc3_complete_trb,
+	TP_PROTO(struct dwc3_ep *dep, struct dwc3_trb *trb),
+	TP_ARGS(dep, trb)
+);
+
 #endif /* __DWC3_TRACE_H */
 
 /* this part has to be here */