Hi, On Tue, Aug 19, 2014 at 08:14:11PM +0000, Paul Zimmerman wrote: > > From: Felipe Balbi [mailto:balbi@xxxxxx] > > Sent: Tuesday, August 19, 2014 1:10 PM > > > > On Tue, Aug 19, 2014 at 08:00:27PM +0000, Paul Zimmerman wrote: > > > > From: Felipe Balbi [mailto:balbi@xxxxxx] > > > > Sent: Tuesday, August 19, 2014 12:09 PM > > > > > > > > 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> > > > > --- > > > > > > > > Hi guys, > > > > > > > > here's v2 of my dwc3 tracepoints patch. Please have a look and > > > > *CAREFULLY* consider if we want to add anything else. > > > > > > > > Paul, I believe you have much more experience in debugging early > > > > HW releases with FPGA models than any of us, so tracing is likely > > > > to help you, is there anything you'd want me to add to as a tracepoint ? > > > > > > What about the "unexpected" interrupt events? It would be nice to see if > > > we receive e.g. an EVENT_OVERFLOW interrupt. Especially since you have > > > some of those events enabled, but don't have handlers for all of them. > > > > > > Maybe a single tracepoint for all of the unexpected events? > > > > Makes sense, I was thinking of a neater way to just pass the event > > structure and decode it withing the trace itself. Then we can even > > remove all the event-specific traces, would that help ? > > Yeah, that's sounds even better. > > > I guess with that we would have a pretty neat setup where we can trace > > TRB lifetime, all register accesses and events. > > Nice. I didn't have time to test this yet (other than build testing), but how does this one look ? Now we will print cute little strings for all events and we still have proper link state tracking. 8<--------------------------------------------------------------------- From 513ba489d66ff81eca056b41fda0cc965e6fe3ed 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 | 73 ++++++++++++++++++++++++++ drivers/usb/dwc3/debug.h | 5 ++ drivers/usb/dwc3/ep0.c | 2 + drivers/usb/dwc3/gadget.c | 27 +++++----- drivers/usb/dwc3/io.h | 30 +++++++++-- drivers/usb/dwc3/trace.c | 19 +++++++ drivers/usb/dwc3/trace.h | 128 ++++++++++++++++++++++++++++++++++++++++++++++ 9 files changed, 272 insertions(+), 19 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..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)); +} + +static void dwc3_gadget_event_str(struct dwc3 *dwc, + const struct dwc3_event_devt *devt) +{ + snprintf(event_str, DWC3_MSG_MAX, "%s", + dwc3_gadget_event_type_string(devt->type)); + + if (devt->type == DWC3_DEVICE_EVENT_LINK_STATUS_CHANGE) { + enum dwc3_link_state next; + + next = devt->event_info & DWC3_LINK_STATE_MASK; + + snprintf(event_str, DWC3_MSG_MAX, " %s -> %s\n", + dwc3_gadget_link_string(dwc->link_state), + dwc3_gadget_link_string(next)); + } +} + +const char *dwc3_event_str(struct dwc3 *dwc, + const union dwc3_event *event) +{ + if (event->type.is_devspec == 0) + dwc3_endpoint_event_str(dwc, &event->depevt); + else + dwc3_gadget_event_str(dwc, &event->devt); + + return event_str; +} + +void dwc3_trace(void (*trace)(struct va_format *), + const char *fmt, ...) +{ + 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..a741864 100644 --- a/drivers/usb/dwc3/debug.h +++ b/drivers/usb/dwc3/debug.h @@ -214,6 +214,11 @@ static inline const char *dwc3_gadget_event_type_string(u8 event) } } +void dwc3_trace(void (*trace)(struct va_format *), + const char *fmt, ...); +const char *dwc3_event_str(struct dwc3 *dwc, + const union dwc3_event *event); + #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..8ec8d84 100644 --- a/drivers/usb/dwc3/ep0.c +++ b/drivers/usb/dwc3/ep0.c @@ -726,6 +726,8 @@ static void dwc3_ep0_inspect_setup(struct dwc3 *dwc, if (!dwc->gadget_driver) goto out; + trace_dwc3_ctrl_req(ctrl); + len = le16_to_cpu(ctrl->wLength); if (!len) { dwc->three_stage_setup = false; diff --git a/drivers/usb/dwc3/gadget.c b/drivers/usb/dwc3/gadget.c index 3ce350f..5faa076 100644 --- a/drivers/usb/dwc3/gadget.c +++ b/drivers/usb/dwc3/gadget.c @@ -267,6 +267,7 @@ void dwc3_gadget_giveback(struct dwc3_ep *dep, struct dwc3_request *req, dev_dbg(dwc->dev, "request %p from %s completed %d/%d ===> %d\n", req, dep->name, req->request.actual, req->request.length, status); + trace_dwc3_gadget_giveback(dwc, req); spin_unlock(&dwc->lock); req->request.complete(&dep->endpoint, &req->request); @@ -713,6 +714,8 @@ static struct usb_request *dwc3_gadget_ep_alloc_request(struct usb_ep *ep, req->epnum = dep->number; req->dep = dep; + trace_dwc3_alloc_request(dwc, req); + return &req->request; } @@ -720,7 +723,10 @@ static void dwc3_gadget_ep_free_request(struct usb_ep *ep, struct usb_request *request) { struct dwc3_request *req = to_dwc3_request(request); + struct dwc3_ep *dep = to_dwc3_ep(ep); + struct dwc3 *dwc = dep->dwc; + trace_dwc3_free_request(dwc, req); kfree(req); } @@ -1146,6 +1152,7 @@ static int dwc3_gadget_ep_queue(struct usb_ep *ep, struct usb_request *request, dev_vdbg(dwc->dev, "queing request %p to %s length %d\n", request, ep->name, request->length); + trace_dwc3_ep_queue(dwc, req); spin_lock_irqsave(&dwc->lock, flags); ret = __dwc3_gadget_ep_queue(dep, req); @@ -1166,6 +1173,8 @@ static int dwc3_gadget_ep_dequeue(struct usb_ep *ep, unsigned long flags; int ret = 0; + trace_dwc3_ep_dequeue(dwc, req); + spin_lock_irqsave(&dwc->lock, flags); list_for_each_entry(r, &dep->request_list, list) { @@ -1933,9 +1942,6 @@ static void dwc3_endpoint_interrupt(struct dwc3 *dwc, if (!(dep->flags & DWC3_EP_ENABLED)) return; - dev_vdbg(dwc->dev, "%s: %s\n", dep->name, - dwc3_ep_event_string(event->endpoint_event)); - if (epnum == 0 || epnum == 1) { dwc3_ep0_interrupt(dwc, event); return; @@ -2128,8 +2134,6 @@ static void dwc3_gadget_disconnect_interrupt(struct dwc3 *dwc) { int reg; - dev_vdbg(dwc->dev, "%s\n", __func__); - reg = dwc3_readl(dwc->regs, DWC3_DCTL); reg &= ~DWC3_DCTL_INITU1ENA; dwc3_writel(dwc->regs, DWC3_DCTL, reg); @@ -2148,8 +2152,6 @@ static void dwc3_gadget_reset_interrupt(struct dwc3 *dwc) { u32 reg; - dev_vdbg(dwc->dev, "%s\n", __func__); - /* * WORKAROUND: DWC3 revisions <1.88a have an issue which * would cause a missing Disconnect Event if there's a @@ -2234,8 +2236,6 @@ static void dwc3_gadget_conndone_interrupt(struct dwc3 *dwc) u32 reg; u8 speed; - dev_vdbg(dwc->dev, "%s\n", __func__); - reg = dwc3_readl(dwc->regs, DWC3_DSTS); speed = reg & DWC3_DSTS_CONNECTSPD; dwc->speed = speed; @@ -2333,8 +2333,6 @@ static void dwc3_gadget_conndone_interrupt(struct dwc3 *dwc) static void dwc3_gadget_wakeup_interrupt(struct dwc3 *dwc) { - dev_vdbg(dwc->dev, "%s\n", __func__); - /* * TODO take core out of low power mode when that's * implemented. @@ -2439,10 +2437,6 @@ static void dwc3_gadget_linksts_change_interrupt(struct dwc3 *dwc, break; } - dev_vdbg(dwc->dev, "link change: %s [%d] -> %s [%d]\n", - dwc3_gadget_link_string(dwc->link_state), - dwc->link_state, dwc3_gadget_link_string(next), next); - dwc->link_state = next; } @@ -2519,6 +2513,8 @@ static void dwc3_gadget_interrupt(struct dwc3 *dwc, static void dwc3_process_event_entry(struct dwc3 *dwc, const union dwc3_event *event) { + dwc3_trace(trace_dwc3_event, "%s", dwc3_event_str(dwc, event)); + /* Endpoint IRQ, handle it and return early */ if (event->type.is_devspec == 0) { /* depevt */ @@ -2612,6 +2608,7 @@ static irqreturn_t dwc3_check_event_buf(struct dwc3 *dwc, u32 buf) if (!count) return IRQ_NONE; + dwc3_trace(trace_dwc3_event, "pending %d events", count); evt->count = count; evt->flags |= DWC3_EVENT_PENDING; diff --git a/drivers/usb/dwc3/io.h b/drivers/usb/dwc3/io.h index d94441c..df8ac17 100644 --- a/drivers/usb/dwc3/io.h +++ b/drivers/usb/dwc3/io.h @@ -20,27 +20,51 @@ #define __DRIVERS_USB_DWC3_IO_H #include <linux/io.h> - +#include "trace.h" +#include "debug.h" #include "core.h" static inline u32 dwc3_readl(void __iomem *base, u32 offset) { + u32 offs = offset - DWC3_GLOBALS_REGS_START; + u32 value; + /* * We requested the mem region starting from the Globals address * space, see dwc3_probe in core.c. * However, the offsets are given starting from xHCI address space. */ - return readl(base + (offset - DWC3_GLOBALS_REGS_START)); + value = readl(base + offs); + + /* + * When tracing we want to make it easy to find the correct address on + * documentation, so we revert it back to the proper addresses, the + * same way they are described on SNPS documentation + */ + dwc3_trace(trace_dwc3_readl, "add %p value %08x", + base - DWC3_GLOBALS_REGS_START + offset, value); + + return value; } static inline void dwc3_writel(void __iomem *base, u32 offset, u32 value) { + u32 offs = offset - DWC3_GLOBALS_REGS_START; + /* * We requested the mem region starting from the Globals address * space, see dwc3_probe in core.c. * However, the offsets are given starting from xHCI address space. */ - writel(value, base + (offset - DWC3_GLOBALS_REGS_START)); + writel(value, base + offs); + + /* + * When tracing we want to make it easy to find the correct address on + * documentation, so we revert it back to the proper addresses, the + * same way they are described on SNPS documentation + */ + dwc3_trace(trace_dwc3_writel, "addr %p value %08x", + base - DWC3_GLOBALS_REGS_START + offset, value); } #endif /* __DRIVERS_USB_DWC3_IO_H */ diff --git a/drivers/usb/dwc3/trace.c b/drivers/usb/dwc3/trace.c new file mode 100644 index 0000000..6cd1664 --- /dev/null +++ b/drivers/usb/dwc3/trace.c @@ -0,0 +1,19 @@ +/** + * trace.c - DesignWare USB3 DRD Controller 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. + */ + +#define CREATE_TRACE_POINTS +#include "trace.h" diff --git a/drivers/usb/dwc3/trace.h b/drivers/usb/dwc3/trace.h new file mode 100644 index 0000000..0a0d0fd --- /dev/null +++ b/drivers/usb/dwc3/trace.h @@ -0,0 +1,128 @@ +/** + * trace.h - DesignWare USB3 DRD Controller 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. + */ + +#undef TRACE_SYSTEM +#define TRACE_SYSTEM dwc3 + +#if !defined(__DWC3_TRACE_H) || defined(TRACE_HEADER_MULTI_READ) +#define __DWC3_TRACE_H + +#include <linux/types.h> +#include <linux/tracepoint.h> +#include <asm/byteorder.h> +#include "core.h" + +DECLARE_EVENT_CLASS(dwc3_log_msg, + TP_PROTO(struct va_format *vaf), + TP_ARGS(vaf), + TP_STRUCT__entry(__dynamic_array(char, msg, DWC3_MSG_MAX)), + TP_fast_assign( + vsnprintf(__get_str(msg), DWC3_MSG_MAX, vaf->fmt, *vaf->va); + ), + TP_printk("%s", __get_str(msg)) +); + +DEFINE_EVENT(dwc3_log_msg, dwc3_readl, + TP_PROTO(struct va_format *vaf), + TP_ARGS(vaf) +); + +DEFINE_EVENT(dwc3_log_msg, dwc3_writel, + TP_PROTO(struct va_format *vaf), + TP_ARGS(vaf) +); + +DEFINE_EVENT(dwc3_log_msg, dwc3_event, + TP_PROTO(struct va_format *vaf), + TP_ARGS(vaf) +); + +DECLARE_EVENT_CLASS(dwc3_log_ctrl, + TP_PROTO(struct usb_ctrlrequest *ctrl), + TP_ARGS(ctrl), + TP_STRUCT__entry( + __field(struct usb_ctrlrequest *, ctrl) + ), + TP_fast_assign( + __entry->ctrl = ctrl; + ), + TP_printk("bRequestType %02x bRequest %02x wValue %04x wIndex %04x wLength %d", + __entry->ctrl->bRequestType, __entry->ctrl->bRequest, + le16_to_cpu(__entry->ctrl->wValue), le16_to_cpu(__entry->ctrl->wIndex), + le16_to_cpu(__entry->ctrl->wLength) + ) +); + +DEFINE_EVENT(dwc3_log_ctrl, dwc3_ctrl_req, + TP_PROTO(struct usb_ctrlrequest *ctrl), + TP_ARGS(ctrl) +); + +DECLARE_EVENT_CLASS(dwc3_log_request, + TP_PROTO(struct dwc3 *dwc, struct dwc3_request *req), + TP_ARGS(dwc, req), + TP_STRUCT__entry( + __field(struct dwc3 *, dwc) + __field(struct dwc3_request *, req) + ), + TP_fast_assign( + __entry->dwc = dwc; + __entry->req = req; + ), + TP_printk("%s: %s req %p length %u/%u ==> %d", + dev_name(__entry->dwc->dev), __entry->req->dep->name, + __entry->req, __entry->req->request.actual, + __entry->req->request.length, __entry->req->request.status + ) +); + +DEFINE_EVENT(dwc3_log_request, dwc3_alloc_request, + TP_PROTO(struct dwc3 *dwc, struct dwc3_request *req), + TP_ARGS(dwc, req) +); + +DEFINE_EVENT(dwc3_log_request, dwc3_free_request, + TP_PROTO(struct dwc3 *dwc, struct dwc3_request *req), + TP_ARGS(dwc, req) +); + +DEFINE_EVENT(dwc3_log_request, dwc3_ep_queue, + TP_PROTO(struct dwc3 *dwc, struct dwc3_request *req), + TP_ARGS(dwc, req) +); + +DEFINE_EVENT(dwc3_log_request, dwc3_ep_dequeue, + TP_PROTO(struct dwc3 *dwc, struct dwc3_request *req), + TP_ARGS(dwc, req) +); + +DEFINE_EVENT(dwc3_log_request, dwc3_gadget_giveback, + TP_PROTO(struct dwc3 *dwc, struct dwc3_request *req), + TP_ARGS(dwc, req) +); + +#endif /* __DWC3_TRACE_H */ + +/* this part has to be here */ + +#undef TRACE_INCLUDE_PATH +#define TRACE_INCLUDE_PATH . + +#undef TRACE_INCLUDE_FILE +#define TRACE_INCLUDE_FILE trace + +#include <trace/define_trace.h> -- 2.0.1.563.g66f467c -- balbi
Attachment:
signature.asc
Description: Digital signature
