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

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



> From: Felipe Balbi [mailto:balbi@xxxxxx]
> Sent: Friday, August 22, 2014 1:47 PM
> 
> On Tue, Aug 19, 2014 at 11:36:05PM +0000, Paul Zimmerman wrote:
> 
> > From: Felipe Balbi <balbi@xxxxxx>
> > Date: Wed, 30 Apr 2014 17:45:10 -0500

> > > diff --git a/drivers/usb/dwc3/debug.c b/drivers/usb/dwc3/debug.c
> > > new file mode 100644
> > > index 0000000..6e109ce
> > > --- /dev/null
> > > +++ b/drivers/usb/dwc3/debug.c
> > > @@ -0,0 +1,73 @@
> > > +/**
> > > + * debug.c - DesignWare USB3 DRD Controller Debug/Trace Support
> > > + *
> > > + * Copyright (C) 2014 Texas Instruments Incorporated - http://www.ti.com
> > > + *
> > > + * Author: Felipe Balbi <balbi@xxxxxx>
> > > + *
> > > + * This program is free software: you can redistribute it and/or modify
> > > + * it under the terms of the GNU General Public License version 2  of
> > > + * the License as published by the Free Software Foundation.
> > > + *
> > > + * This program is distributed in the hope that it will be useful,
> > > + * but WITHOUT ANY WARRANTY; without even the implied warranty of
> > > + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
> > > + * GNU General Public License for more details.
> > > + */
> > > +
> > > +#include "core.h"
> > > +#include "debug.h"
> > > +
> > > +static char event_str[DWC3_MSG_MAX];
> > > +
> > > +static void dwc3_endpoint_event_str(struct dwc3 *dwc,
> > > +		const struct dwc3_event_depevt *event)
> > > +{
> > > +	struct dwc3_ep *dep = dwc->eps[event->endpoint_number];
> > > +
> > > +	snprintf(event_str, DWC3_MSG_MAX, "%s %s", dep->name,
> > > +			dwc3_ep_event_string(event->endpoint_event));
> >
> > Maybe you should also include the raw event data in the trace? Some
> > of the other bits in the event besides the event number can tell you
> > useful things while debugging.
> 
> I changed this to print only the raw event code. It's not that difficult
> to decode by hand anyways and makes the code a lot simpler.
> 
> We can add decoding later if it really becomes annoying.
> 
> In any case here's another version, I also changed a few things in ep0,
> there are no more dev_{v,}dbg inside ep0.c, this is so that we avoid
> high overhead while debugging ep0 (which can be finicky at times).
> 
> Anyway, please give it another round of review. And as always, if
> there's anything we might wanna add, please speak up :-)
> 
> 8<--------------------------------------------------------------------
> 
> From b38435444c882a94b011e28da0f094ce98aeee59 Mon Sep 17 00:00:00 2001
> From: Felipe Balbi <balbi@xxxxxx>
> Date: Wed, 30 Apr 2014 17:45:10 -0500
> Subject: [PATCH] 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.
> 
> Signed-off-by: Felipe Balbi <balbi@xxxxxx>
> ---
>  drivers/usb/dwc3/Makefile |   5 +-
>  drivers/usb/dwc3/core.h   |   2 +
>  drivers/usb/dwc3/debug.c  |  33 +++++++++++
>  drivers/usb/dwc3/debug.h  |   3 +
>  drivers/usb/dwc3/ep0.c    |  65 ++++++++++++---------
>  drivers/usb/dwc3/gadget.c |  24 +++-----
>  drivers/usb/dwc3/io.h     |  30 +++++++++-
>  drivers/usb/dwc3/trace.c  |  19 ++++++
>  drivers/usb/dwc3/trace.h  | 143 ++++++++++++++++++++++++++++++++++++++++++++++
>  9 files changed, 277 insertions(+), 47 deletions(-)
>  create mode 100644 drivers/usb/dwc3/debug.c
>  create mode 100644 drivers/usb/dwc3/trace.c
>  create mode 100644 drivers/usb/dwc3/trace.h
> 
> diff --git a/drivers/usb/dwc3/Makefile b/drivers/usb/dwc3/Makefile
> index 10ac3e7..7793e6c 100644
> --- a/drivers/usb/dwc3/Makefile
> +++ b/drivers/usb/dwc3/Makefile
> @@ -1,9 +1,12 @@
> +# define_trace.h needs to know how to find our header
> +CFLAGS_trace.o				:= -I$(src)
> +
>  ccflags-$(CONFIG_USB_DWC3_DEBUG)	:= -DDEBUG
>  ccflags-$(CONFIG_USB_DWC3_VERBOSE)	+= -DVERBOSE_DEBUG
> 
>  obj-$(CONFIG_USB_DWC3)			+= dwc3.o
> 
> -dwc3-y					:= core.o
> +dwc3-y					:= core.o debug.o trace.o
> 
>  ifneq ($(filter y,$(CONFIG_USB_DWC3_HOST) $(CONFIG_USB_DWC3_DUAL_ROLE)),)
>  	dwc3-y				+= host.o
> diff --git a/drivers/usb/dwc3/core.h b/drivers/usb/dwc3/core.h
> index 48fb264..dbdad87 100644
> --- a/drivers/usb/dwc3/core.h
> +++ b/drivers/usb/dwc3/core.h
> @@ -33,6 +33,8 @@
> 
>  #include <linux/phy/phy.h>
> 
> +#define DWC3_MSG_MAX	500
> +
>  /* Global constants */
>  #define DWC3_EP0_BOUNCE_SIZE	512
>  #define DWC3_ENDPOINTS_NUM	32
> diff --git a/drivers/usb/dwc3/debug.c b/drivers/usb/dwc3/debug.c
> new file mode 100644
> index 0000000..6d01e0c
> --- /dev/null
> +++ b/drivers/usb/dwc3/debug.c
> @@ -0,0 +1,33 @@
> +/**
> + * debug.c - DesignWare USB3 DRD Controller Debug/Trace Support
> + *
> + * Copyright (C) 2014 Texas Instruments Incorporated - http://www.ti.com
> + *
> + * Author: Felipe Balbi <balbi@xxxxxx>
> + *
> + * This program is free software: you can redistribute it and/or modify
> + * it under the terms of the GNU General Public License version 2  of
> + * the License as published by the Free Software Foundation.
> + *
> + * This program is distributed in the hope that it will be useful,
> + * but WITHOUT ANY WARRANTY; without even the implied warranty of
> + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
> + * GNU General Public License for more details.
> + */
> +
> +#include "debug.h"
> +
> +void dwc3_trace(void (*trace)(struct va_format *),
> +		const char *fmt, ...)

Unnecessary line wrap? It looks like this would fit on one line.

> +{
> +	struct va_format vaf;
> +	va_list args;
> +
> +	va_start(args, fmt);
> +	vaf.fmt = fmt;
> +	vaf.va = &args;
> +
> +	trace(&vaf);
> +
> +	va_end(args);
> +}
> diff --git a/drivers/usb/dwc3/debug.h b/drivers/usb/dwc3/debug.h
> index 12ff4c9..3dfcd15 100644
> --- a/drivers/usb/dwc3/debug.h
> +++ b/drivers/usb/dwc3/debug.h
> @@ -214,6 +214,9 @@ static inline const char *dwc3_gadget_event_type_string(u8 event)
>  	}
>  }
> 
> +void dwc3_trace(void (*trace)(struct va_format *),
> +		const char *fmt, ...);

Same here.

> +
>  #ifdef CONFIG_DEBUG_FS
>  extern int dwc3_debugfs_init(struct dwc3 *);
>  extern void dwc3_debugfs_exit(struct dwc3 *);
> diff --git a/drivers/usb/dwc3/ep0.c b/drivers/usb/dwc3/ep0.c
> index 21a3520..79b883f 100644
> --- a/drivers/usb/dwc3/ep0.c
> +++ b/drivers/usb/dwc3/ep0.c
> @@ -65,7 +65,7 @@ static int dwc3_ep0_start_trans(struct dwc3 *dwc, u8 epnum, dma_addr_t buf_dma,
> 
>  	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;
>  	}
> 
> @@ -88,7 +88,8 @@ static int dwc3_ep0_start_trans(struct dwc3 *dwc, u8 epnum, dma_addr_t buf_dma,
>  	ret = dwc3_send_gadget_ep_cmd(dwc, dep->number,
>  			DWC3_DEPCMD_STARTTRANSFER, &params);
>  	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;
>  	}
> 
> @@ -153,7 +154,8 @@ static int __dwc3_gadget_ep0_queue(struct dwc3_ep *dep,
>  		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;
>  	}
> @@ -217,7 +219,8 @@ int dwc3_gadget_ep0_queue(struct usb_ep *ep, struct usb_request *request,
> 
>  	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;
> @@ -229,7 +232,8 @@ int dwc3_gadget_ep0_queue(struct usb_ep *ep, struct usb_request *request,
>  		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));
> 
> @@ -485,12 +489,13 @@ static int dwc3_ep0_set_address(struct dwc3 *dwc, struct usb_ctrlrequest *ctrl)
> 
>  	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;
>  	}
> 
> @@ -556,7 +561,8 @@ static int dwc3_ep0_set_config(struct dwc3 *dwc, struct usb_ctrlrequest *ctrl)
>  			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");

Unnecessary line wrap?

>  		}
>  		break;
> 
> @@ -680,35 +686,35 @@ static int dwc3_ep0_std_request(struct dwc3 *dwc, struct usb_ctrlrequest *ctrl)
> 
>  	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;
>  	}
> @@ -726,6 +732,8 @@ static void dwc3_ep0_inspect_setup(struct dwc3 *dwc,
>  	if (!dwc->gadget_driver)
>  		goto out;
> 
> +	trace_dwc3_ctrl_req(ctrl);

I don't see this function defined anywhere in this patch. Same for some
of the other trace functions. I guess these are automatically defined
by some tracing macro magic? Is there any way to see what the event
will look like short of running the code? These are probably dumb
questions, but I haven't done anything yet with the tracing API, so
I'm pretty clueless about it.

Other than that, I can't think of anything else to be added at this
point. As you say, other trace points can be added later if desired.

-- 
Paul

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html




[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux