From patchwork Fri Jul 25 16:19:05 2014 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Felipe Balbi X-Patchwork-Id: 34296 Return-Path: X-Original-To: linaro@patches.linaro.org Delivered-To: linaro@patches.linaro.org Received: from mail-oi0-f72.google.com (mail-oi0-f72.google.com [209.85.218.72]) by ip-10-151-82-157.ec2.internal (Postfix) with ESMTPS id CD52220551 for ; Fri, 25 Jul 2014 16:19:32 +0000 (UTC) Received: by mail-oi0-f72.google.com with SMTP id a141sf17891085oig.3 for ; Fri, 25 Jul 2014 09:19:32 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:delivered-to:from:to:cc:subject:date:message-id :mime-version:sender:precedence:list-id:x-original-sender :x-original-authentication-results:mailing-list:list-post:list-help :list-archive:list-unsubscribe:content-type; bh=coZU0DH1PI2fLH9KFevuj+a9CMneEuSbfp6Tj+ZRhes=; b=KhTJ+44dsfw3ZmgPl7WfWrSInAVx+2m6p+EAACdTvb+II7U605WUXQRLKeyTrsT8d3 wOjapCihJX8Zbc84qIX0Rs3h557uSUyeNo7jU2P6uxq3RR58AWfh4VKLFM5WmQW8vAEX mPO29ZWNuA1jjSKaoX65sv8YA8kvBajcsJxZ2bZMlgIpxWyUEiuEze5TD8BNWyoQ42zv QpeQc9PlvVkV0dcqvpfHDbqCLXNcFHH6JsVQ4fqBy9aKiP8Vm5fvk6N8cBJOg+Lxlho0 K8L85H8DFi+GKXt5PdHxRemfxbatT3kjmGTZ9xcdD9H+AIwRCzShBbmHR25UxuVKKeUE J95A== X-Gm-Message-State: ALoCoQmYmUeawf0mDDa4ehUZA7SPn91v6qF4vJHrexFiCkL7X1LhcswosJVwnqH3zQamI3ZctPaI X-Received: by 10.50.41.66 with SMTP id d2mr2624763igl.2.1406305172365; Fri, 25 Jul 2014 09:19:32 -0700 (PDT) X-BeenThere: patchwork-forward@linaro.org Received: by 10.140.39.39 with SMTP id u36ls526081qgu.63.gmail; Fri, 25 Jul 2014 09:19:32 -0700 (PDT) X-Received: by 10.220.119.8 with SMTP id x8mr3378732vcq.62.1406305172241; Fri, 25 Jul 2014 09:19:32 -0700 (PDT) Received: from mail-vc0-f172.google.com (mail-vc0-f172.google.com [209.85.220.172]) by mx.google.com with ESMTPS id mo1si7840542vec.31.2014.07.25.09.19.32 for (version=TLSv1 cipher=ECDHE-RSA-RC4-SHA bits=128/128); Fri, 25 Jul 2014 09:19:32 -0700 (PDT) Received-SPF: pass (google.com: domain of patch+caf_=patchwork-forward=linaro.org@linaro.org designates 209.85.220.172 as permitted sender) client-ip=209.85.220.172; Received: by mail-vc0-f172.google.com with SMTP id im17so7584418vcb.31 for ; Fri, 25 Jul 2014 09:19:32 -0700 (PDT) X-Received: by 10.52.129.200 with SMTP id ny8mr18620561vdb.27.1406305172066; Fri, 25 Jul 2014 09:19:32 -0700 (PDT) X-Forwarded-To: patchwork-forward@linaro.org X-Forwarded-For: patch@linaro.org patchwork-forward@linaro.org Delivered-To: patch@linaro.org Received: by 10.221.37.5 with SMTP id tc5csp49944vcb; Fri, 25 Jul 2014 09:19:31 -0700 (PDT) X-Received: by 10.66.174.17 with SMTP id bo17mr19861671pac.98.1406305171109; Fri, 25 Jul 2014 09:19:31 -0700 (PDT) Received: from vger.kernel.org (vger.kernel.org. [209.132.180.67]) by mx.google.com with ESMTP id be7si4828659pdb.415.2014.07.25.09.19.30 for ; Fri, 25 Jul 2014 09:19:31 -0700 (PDT) Received-SPF: none (google.com: linux-usb-owner@vger.kernel.org does not designate permitted sender hosts) client-ip=209.132.180.67; Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S933516AbaGYQT3 (ORCPT + 3 others); Fri, 25 Jul 2014 12:19:29 -0400 Received: from comal.ext.ti.com ([198.47.26.152]:45056 "EHLO comal.ext.ti.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S932582AbaGYQT2 (ORCPT ); Fri, 25 Jul 2014 12:19:28 -0400 Received: from dflxv15.itg.ti.com ([128.247.5.124]) by comal.ext.ti.com (8.13.7/8.13.7) with ESMTP id s6PGJRFU002078 for ; Fri, 25 Jul 2014 11:19:27 -0500 Received: from DLEE70.ent.ti.com (dlee70.ent.ti.com [157.170.170.113]) by dflxv15.itg.ti.com (8.14.3/8.13.8) with ESMTP id s6PGJRr5013874 for ; Fri, 25 Jul 2014 11:19:27 -0500 Received: from dlep32.itg.ti.com (157.170.170.100) by DLEE70.ent.ti.com (157.170.170.113) with Microsoft SMTP Server id 14.3.174.1; Fri, 25 Jul 2014 11:19:27 -0500 Received: from localhost (ileax41-snat.itg.ti.com [10.172.224.153]) by dlep32.itg.ti.com (8.14.3/8.13.8) with ESMTP id s6PGJQxx004475; Fri, 25 Jul 2014 11:19:26 -0500 From: Felipe Balbi To: Linux USB Mailing List CC: Felipe Balbi Subject: [PATCH] usb: dwc3: add tracepoints to aid debugging Date: Fri, 25 Jul 2014 11:19:05 -0500 Message-ID: <1406305145-1409-1-git-send-email-balbi@ti.com> X-Mailer: git-send-email 2.0.1.563.g66f467c MIME-Version: 1.0 Sender: linux-usb-owner@vger.kernel.org Precedence: list List-ID: X-Mailing-List: linux-usb@vger.kernel.org X-Removed-Original-Auth: Dkim didn't pass. X-Original-Sender: balbi@ti.com X-Original-Authentication-Results: mx.google.com; spf=pass (google.com: domain of patch+caf_=patchwork-forward=linaro.org@linaro.org designates 209.85.220.172 as permitted sender) smtp.mail=patch+caf_=patchwork-forward=linaro.org@linaro.org Mailing-list: list patchwork-forward@linaro.org; contact patchwork-forward+owners@linaro.org X-Google-Group-Id: 836684582541 List-Post: , List-Help: , List-Archive: List-Unsubscribe: , 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 --- Hi folks, I have been meaning to send this for quite a while now but never had the time to test everything and make sure it works. Logs are looking pretty good to my eyes with a much smaller overhead than with dev_* macros. If you have a real good reason to add more logs, just let me know and we will look at the possibility for adding it, I have a feeling people will want traces for endpoint 0 state machine but I'm not entirely sure it's needed, so I left it out for now. If folks think it's important, I'll add it in no time. Please give it a good review because we will have to support tracepoints for the next 60 years. cheers drivers/usb/dwc3/Makefile | 5 +- drivers/usb/dwc3/debug.c | 33 ++++++++++++ drivers/usb/dwc3/debug.h | 3 ++ drivers/usb/dwc3/ep0.c | 2 + drivers/usb/dwc3/gadget.c | 22 ++++++++ drivers/usb/dwc3/io.h | 30 +++++++++-- drivers/usb/dwc3/trace.c | 19 +++++++ drivers/usb/dwc3/trace.h | 130 ++++++++++++++++++++++++++++++++++++++++++++++ 8 files changed, 240 insertions(+), 4 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/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 + * + * 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, ...) +{ + 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 fceb39d..ff5e524 100644 --- a/drivers/usb/dwc3/debug.h +++ b/drivers/usb/dwc3/debug.h @@ -18,6 +18,9 @@ #include "core.h" +void dwc3_trace(void (*trace)(struct va_format *), + const char *fmt, ...); + #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 349cacc..ac06447 100644 --- a/drivers/usb/dwc3/gadget.c +++ b/drivers/usb/dwc3/gadget.c @@ -266,6 +266,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); @@ -800,6 +801,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; } @@ -807,7 +810,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); } @@ -1233,6 +1239,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); @@ -1253,6 +1260,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) { @@ -2022,6 +2031,8 @@ static void dwc3_endpoint_interrupt(struct dwc3 *dwc, dev_vdbg(dwc->dev, "%s: %s\n", dep->name, dwc3_ep_event_string(event->endpoint_event)); + dwc3_trace(trace_dwc3_event, "%s: %s", dep->name, + dwc3_ep_event_string(event->endpoint_event)); if (epnum == 0 || epnum == 1) { dwc3_ep0_interrupt(dwc, event); @@ -2216,6 +2227,7 @@ static void dwc3_gadget_disconnect_interrupt(struct dwc3 *dwc) int reg; dev_vdbg(dwc->dev, "%s\n", __func__); + dwc3_trace(trace_dwc3_event, "disconnect interrupt"); reg = dwc3_readl(dwc->regs, DWC3_DCTL); reg &= ~DWC3_DCTL_INITU1ENA; @@ -2236,6 +2248,7 @@ static void dwc3_gadget_reset_interrupt(struct dwc3 *dwc) u32 reg; dev_vdbg(dwc->dev, "%s\n", __func__); + dwc3_trace(trace_dwc3_event, "reset interrupt"); /* * WORKAROUND: DWC3 revisions <1.88a have an issue which @@ -2322,6 +2335,7 @@ static void dwc3_gadget_conndone_interrupt(struct dwc3 *dwc) u8 speed; dev_vdbg(dwc->dev, "%s\n", __func__); + dwc3_trace(trace_dwc3_event, "connection done interrupt"); reg = dwc3_readl(dwc->regs, DWC3_DSTS); speed = reg & DWC3_DSTS_CONNECTSPD; @@ -2421,6 +2435,7 @@ 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__); + dwc3_trace(trace_dwc3_event, "wakeup interrupt"); /* * TODO take core out of low power mode when that's @@ -2530,6 +2545,10 @@ static void dwc3_gadget_linksts_change_interrupt(struct dwc3 *dwc, dwc3_gadget_link_string(dwc->link_state), dwc->link_state, dwc3_gadget_link_string(next), next); + dwc3_trace(trace_dwc3_event, "link change: %s [%d] -> %s [%d]", + dwc3_gadget_link_string(dwc->link_state), + dwc->link_state, dwc3_gadget_link_string(next), next); + dwc->link_state = next; } @@ -2538,6 +2557,8 @@ static void dwc3_gadget_hibernation_interrupt(struct dwc3 *dwc, { unsigned int is_ss = evtinfo & BIT(4); + dwc3_trace(trace_dwc3_event, "hibernation interrupt"); + /** * WORKAROUND: DWC3 revison 2.20a with hibernation support * have a known issue which can cause USB CV TD.9.23 to fail @@ -2699,6 +2720,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 - +#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 + * + * 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..ed602608 --- /dev/null +++ b/drivers/usb/dwc3/trace.h @@ -0,0 +1,130 @@ +/** + * trace.h - DesignWare USB3 DRD Controller Trace Support + * + * Copyright (C) 2014 Texas Instruments Incorporated - http://www.ti.com + * + * Author: Felipe Balbi + * + * 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 +#include +#include +#include "core.h" + +#define DWC3_MSG_MAX 500 + +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 %x bRequest %x wValue %02x wIndex %02x wLength %02x", + __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