[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <20250828224852.ukelgargocektp3z@synopsys.com>
Date: Thu, 28 Aug 2025 22:48:58 +0000
From: Thinh Nguyen <Thinh.Nguyen@...opsys.com>
To: Prashanth K <prashanth.k@....qualcomm.com>
CC: Thinh Nguyen <Thinh.Nguyen@...opsys.com>,
Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
"linux-usb@...r.kernel.org" <linux-usb@...r.kernel.org>,
"linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>
Subject: Re: [PATCH] usb: dwc3: Log dwc3 instance name in traces
Hi,
On Mon, Aug 25, 2025, Prashanth K wrote:
> When multiple DWC3 controllers are being used, trace events from
> different instances get mixed up making debugging difficult as
> there's no way to distinguish which instance generated the trace.
>
> Append the device name to trace events to clearly identify the
> source instance.
Can we print the base address instead of the device name? This will be
consistent across different device names, and it will be easier to
create filter.
>
> Example trace output,
> before -> dwc3_event: event (00000101): Reset [U0]
> after -> dwc3_event: a600000.usb: event (00000101): Reset [U0]
>
> Signed-off-by: Prashanth K <prashanth.k@....qualcomm.com>
> ---
> drivers/usb/dwc3/ep0.c | 2 +-
> drivers/usb/dwc3/gadget.c | 2 +-
> drivers/usb/dwc3/gadget.h | 1 +
> drivers/usb/dwc3/io.h | 12 ++++---
> drivers/usb/dwc3/trace.h | 76 ++++++++++++++++++++++++---------------
> 5 files changed, 59 insertions(+), 34 deletions(-)
>
> diff --git a/drivers/usb/dwc3/ep0.c b/drivers/usb/dwc3/ep0.c
> index 666ac432f52d..b814bbba18ac 100644
> --- a/drivers/usb/dwc3/ep0.c
> +++ b/drivers/usb/dwc3/ep0.c
> @@ -830,7 +830,7 @@ static void dwc3_ep0_inspect_setup(struct dwc3 *dwc,
> if (!dwc->gadget_driver || !dwc->softconnect || !dwc->connected)
> goto out;
>
> - trace_dwc3_ctrl_req(ctrl);
> + trace_dwc3_ctrl_req(dwc, ctrl);
>
> len = le16_to_cpu(ctrl->wLength);
> if (!len) {
> diff --git a/drivers/usb/dwc3/gadget.c b/drivers/usb/dwc3/gadget.c
> index 25db36c63951..e3621cc318ea 100644
> --- a/drivers/usb/dwc3/gadget.c
> +++ b/drivers/usb/dwc3/gadget.c
> @@ -271,7 +271,7 @@ int dwc3_send_gadget_generic_command(struct dwc3 *dwc, unsigned int cmd,
> status = -ETIMEDOUT;
> }
>
> - trace_dwc3_gadget_generic_cmd(cmd, param, status);
> + trace_dwc3_gadget_generic_cmd(dwc, cmd, param, status);
>
> return ret;
> }
> diff --git a/drivers/usb/dwc3/gadget.h b/drivers/usb/dwc3/gadget.h
> index d73e735e4081..dc9985523ed8 100644
> --- a/drivers/usb/dwc3/gadget.h
> +++ b/drivers/usb/dwc3/gadget.h
> @@ -131,6 +131,7 @@ int dwc3_gadget_start_config(struct dwc3 *dwc, unsigned int resource_index);
> static inline void dwc3_gadget_ep_get_transfer_index(struct dwc3_ep *dep)
> {
> u32 res_id;
> + struct dwc3 *dwc = dep->dwc;
This looks unused when it's not.
>
> res_id = dwc3_readl(dep->regs, DWC3_DEPCMD);
> dep->resource_index = DWC3_DEPCMD_GET_RSC_IDX(res_id);
> diff --git a/drivers/usb/dwc3/io.h b/drivers/usb/dwc3/io.h
> index 1e96ea339d48..8e8eb3265676 100644
> --- a/drivers/usb/dwc3/io.h
> +++ b/drivers/usb/dwc3/io.h
> @@ -16,7 +16,11 @@
> #include "debug.h"
> #include "core.h"
>
> -static inline u32 dwc3_readl(void __iomem *base, u32 offset)
> +/* Note: Caller must have a reference to dwc3 structure */
> +#define dwc3_readl(b, o) __dwc3_readl(dwc, b, o)
> +#define dwc3_writel(b, o, v) __dwc3_writel(dwc, b, o, v)
Can we not do this. This will be hard to read. If we just print the base
address, this will be simpler.
Thanks,
Thinh
> +
> +static inline u32 __dwc3_readl(struct dwc3 *dwc, void __iomem *base, u32 offset)
> {
> u32 value;
>
> @@ -32,12 +36,12 @@ static inline u32 dwc3_readl(void __iomem *base, u32 offset)
> * documentation, so we revert it back to the proper addresses, the
> * same way they are described on SNPS documentation
> */
> - trace_dwc3_readl(base - DWC3_GLOBALS_REGS_START, offset, value);
> + trace_dwc3_readl(dwc, base - DWC3_GLOBALS_REGS_START, offset, value);
>
> return value;
> }
>
> -static inline void dwc3_writel(void __iomem *base, u32 offset, u32 value)
> +static inline void __dwc3_writel(struct dwc3 *dwc, void __iomem *base, u32 offset, u32 value)
> {
> /*
> * We requested the mem region starting from the Globals address
> @@ -51,7 +55,7 @@ static inline void dwc3_writel(void __iomem *base, u32 offset, u32 value)
> * documentation, so we revert it back to the proper addresses, the
> * same way they are described on SNPS documentation
> */
> - trace_dwc3_writel(base - DWC3_GLOBALS_REGS_START, offset, value);
> + trace_dwc3_writel(dwc, base - DWC3_GLOBALS_REGS_START, offset, value);
> }
>
> #endif /* __DRIVERS_USB_DWC3_IO_H */
> diff --git a/drivers/usb/dwc3/trace.h b/drivers/usb/dwc3/trace.h
> index bdeb1aaf65d8..649bc536ca20 100644
> --- a/drivers/usb/dwc3/trace.h
> +++ b/drivers/usb/dwc3/trace.h
> @@ -20,46 +20,51 @@
> #include "debug.h"
>
> DECLARE_EVENT_CLASS(dwc3_log_io,
> - TP_PROTO(void *base, u32 offset, u32 value),
> - TP_ARGS(base, offset, value),
> + TP_PROTO(struct dwc3 *dwc, void *base, u32 offset, u32 value),
> + TP_ARGS(dwc, base, offset, value),
> TP_STRUCT__entry(
> + __string(dev_name, dev_name(dwc->dev))
> __field(void *, base)
> __field(u32, offset)
> __field(u32, value)
> ),
> TP_fast_assign(
> + __assign_str(dev_name);
> __entry->base = base;
> __entry->offset = offset;
> __entry->value = value;
> ),
> - TP_printk("addr %p offset %04x value %08x",
> + TP_printk("%s: addr %p offset %04x value %08x",
> + __get_str(dev_name),
> __entry->base + __entry->offset,
> __entry->offset,
> __entry->value)
> );
>
> DEFINE_EVENT(dwc3_log_io, dwc3_readl,
> - TP_PROTO(void __iomem *base, u32 offset, u32 value),
> - TP_ARGS(base, offset, value)
> + TP_PROTO(struct dwc3 *dwc, void __iomem *base, u32 offset, u32 value),
> + TP_ARGS(dwc, base, offset, value)
> );
>
> DEFINE_EVENT(dwc3_log_io, dwc3_writel,
> - TP_PROTO(void __iomem *base, u32 offset, u32 value),
> - TP_ARGS(base, offset, value)
> + TP_PROTO(struct dwc3 *dwc, void __iomem *base, u32 offset, u32 value),
> + TP_ARGS(dwc, base, offset, value)
> );
>
> DECLARE_EVENT_CLASS(dwc3_log_event,
> TP_PROTO(u32 event, struct dwc3 *dwc),
> TP_ARGS(event, dwc),
> TP_STRUCT__entry(
> + __string(dev_name, dev_name(dwc->dev))
> __field(u32, event)
> __field(u32, ep0state)
> ),
> TP_fast_assign(
> + __assign_str(dev_name);
> __entry->event = event;
> __entry->ep0state = dwc->ep0state;
> ),
> - TP_printk("event (%08x): %s", __entry->event,
> + TP_printk("%s: event (%08x): %s", __get_str(dev_name), __entry->event,
> dwc3_decode_event(__get_buf(DWC3_MSG_MAX), DWC3_MSG_MAX,
> __entry->event, __entry->ep0state))
> );
> @@ -70,9 +75,10 @@ DEFINE_EVENT(dwc3_log_event, dwc3_event,
> );
>
> DECLARE_EVENT_CLASS(dwc3_log_ctrl,
> - TP_PROTO(struct usb_ctrlrequest *ctrl),
> - TP_ARGS(ctrl),
> + TP_PROTO(struct dwc3 *dwc, struct usb_ctrlrequest *ctrl),
> + TP_ARGS(dwc, ctrl),
> TP_STRUCT__entry(
> + __string(dev_name, dev_name(dwc->dev))
> __field(__u8, bRequestType)
> __field(__u8, bRequest)
> __field(__u16, wValue)
> @@ -80,13 +86,15 @@ DECLARE_EVENT_CLASS(dwc3_log_ctrl,
> __field(__u16, wLength)
> ),
> TP_fast_assign(
> + __assign_str(dev_name);
> __entry->bRequestType = ctrl->bRequestType;
> __entry->bRequest = ctrl->bRequest;
> __entry->wValue = le16_to_cpu(ctrl->wValue);
> __entry->wIndex = le16_to_cpu(ctrl->wIndex);
> __entry->wLength = le16_to_cpu(ctrl->wLength);
> ),
> - TP_printk("%s", usb_decode_ctrl(__get_buf(DWC3_MSG_MAX), DWC3_MSG_MAX,
> + TP_printk("%s: %s", __get_str(dev_name), usb_decode_ctrl(__get_buf(DWC3_MSG_MAX),
> + DWC3_MSG_MAX,
> __entry->bRequestType,
> __entry->bRequest, __entry->wValue,
> __entry->wIndex, __entry->wLength)
> @@ -94,14 +102,15 @@ DECLARE_EVENT_CLASS(dwc3_log_ctrl,
> );
>
> DEFINE_EVENT(dwc3_log_ctrl, dwc3_ctrl_req,
> - TP_PROTO(struct usb_ctrlrequest *ctrl),
> - TP_ARGS(ctrl)
> + TP_PROTO(struct dwc3 *dwc, struct usb_ctrlrequest *ctrl),
> + TP_ARGS(dwc, ctrl)
> );
>
> DECLARE_EVENT_CLASS(dwc3_log_request,
> TP_PROTO(struct dwc3_request *req),
> TP_ARGS(req),
> TP_STRUCT__entry(
> + __string(dev_name, dev_name(req->dep->dwc->dev))
> __string(name, req->dep->name)
> __field(struct dwc3_request *, req)
> __field(unsigned int, actual)
> @@ -112,7 +121,7 @@ DECLARE_EVENT_CLASS(dwc3_log_request,
> __field(int, no_interrupt)
> ),
> TP_fast_assign(
> - __assign_str(name);
> + __assign_str(dev_name);
> __entry->req = req;
> __entry->actual = req->request.actual;
> __entry->length = req->request.length;
> @@ -121,8 +130,10 @@ DECLARE_EVENT_CLASS(dwc3_log_request,
> __entry->short_not_ok = req->request.short_not_ok;
> __entry->no_interrupt = req->request.no_interrupt;
> ),
> - TP_printk("%s: req %p length %u/%u %s%s%s ==> %d",
> - __get_str(name), __entry->req, __entry->actual, __entry->length,
> + TP_printk("%s: %s: req %p length %u/%u %s%s%s ==> %d",
> + __get_str(dev_name),
> + __get_str(name), __entry->req,
> + __entry->actual, __entry->length,
> __entry->zero ? "Z" : "z",
> __entry->short_not_ok ? "S" : "s",
> __entry->no_interrupt ? "i" : "I",
> @@ -156,28 +167,30 @@ DEFINE_EVENT(dwc3_log_request, dwc3_gadget_giveback,
> );
>
> DECLARE_EVENT_CLASS(dwc3_log_generic_cmd,
> - TP_PROTO(unsigned int cmd, u32 param, int status),
> - TP_ARGS(cmd, param, status),
> + TP_PROTO(struct dwc3 *dwc, unsigned int cmd, u32 param, int status),
> + TP_ARGS(dwc, cmd, param, status),
> TP_STRUCT__entry(
> + __string(dev_name, dev_name(dwc->dev))
> __field(unsigned int, cmd)
> __field(u32, param)
> __field(int, status)
> ),
> TP_fast_assign(
> + __assign_str(dev_name);
> __entry->cmd = cmd;
> __entry->param = param;
> __entry->status = status;
> ),
> - TP_printk("cmd '%s' [%x] param %08x --> status: %s",
> - dwc3_gadget_generic_cmd_string(__entry->cmd),
> + TP_printk("%s: cmd '%s' [%x] param %08x --> status: %s",
> + __get_str(dev_name), dwc3_gadget_generic_cmd_string(__entry->cmd),
> __entry->cmd, __entry->param,
> dwc3_gadget_generic_cmd_status_string(__entry->status)
> )
> );
>
> DEFINE_EVENT(dwc3_log_generic_cmd, dwc3_gadget_generic_cmd,
> - TP_PROTO(unsigned int cmd, u32 param, int status),
> - TP_ARGS(cmd, param, status)
> + TP_PROTO(struct dwc3 *dwc, unsigned int cmd, u32 param, int status),
> + TP_ARGS(dwc, cmd, param, status)
> );
>
> DECLARE_EVENT_CLASS(dwc3_log_gadget_ep_cmd,
> @@ -185,6 +198,7 @@ DECLARE_EVENT_CLASS(dwc3_log_gadget_ep_cmd,
> struct dwc3_gadget_ep_cmd_params *params, int cmd_status),
> TP_ARGS(dep, cmd, params, cmd_status),
> TP_STRUCT__entry(
> + __string(dev_name, dev_name(dep->dwc->dev))
> __string(name, dep->name)
> __field(unsigned int, cmd)
> __field(u32, param0)
> @@ -193,6 +207,7 @@ DECLARE_EVENT_CLASS(dwc3_log_gadget_ep_cmd,
> __field(int, cmd_status)
> ),
> TP_fast_assign(
> + __assign_str(dev_name);
> __assign_str(name);
> __entry->cmd = cmd;
> __entry->param0 = params->param0;
> @@ -200,8 +215,9 @@ DECLARE_EVENT_CLASS(dwc3_log_gadget_ep_cmd,
> __entry->param2 = params->param2;
> __entry->cmd_status = cmd_status;
> ),
> - TP_printk("%s: cmd '%s' [%x] params %08x %08x %08x --> status: %s",
> - __get_str(name), dwc3_gadget_ep_cmd_string(__entry->cmd),
> + TP_printk("%s: %s: cmd '%s' [%x] params %08x %08x %08x --> status: %s",
> + __get_str(dev_name), __get_str(name),
> + dwc3_gadget_ep_cmd_string(__entry->cmd),
> __entry->cmd, __entry->param0,
> __entry->param1, __entry->param2,
> dwc3_ep_cmd_status_string(__entry->cmd_status)
> @@ -218,6 +234,7 @@ DECLARE_EVENT_CLASS(dwc3_log_trb,
> TP_PROTO(struct dwc3_ep *dep, struct dwc3_trb *trb),
> TP_ARGS(dep, trb),
> TP_STRUCT__entry(
> + __string(dev_name, dev_name(dep->dwc->dev))
> __string(name, dep->name)
> __field(struct dwc3_trb *, trb)
> __field(u32, bpl)
> @@ -229,6 +246,7 @@ DECLARE_EVENT_CLASS(dwc3_log_trb,
> __field(u32, dequeue)
> ),
> TP_fast_assign(
> + __assign_str(dev_name);
> __assign_str(name);
> __entry->trb = trb;
> __entry->bpl = trb->bpl;
> @@ -239,8 +257,8 @@ DECLARE_EVENT_CLASS(dwc3_log_trb,
> __entry->enqueue = dep->trb_enqueue;
> __entry->dequeue = dep->trb_dequeue;
> ),
> - TP_printk("%s: trb %p (E%d:D%d) buf %08x%08x size %s%d ctrl %08x sofn %08x (%c%c%c%c:%c%c:%s)",
> - __get_str(name), __entry->trb, __entry->enqueue,
> + TP_printk("%s: %s: trb %p (E%d:D%d) buf %08x%08x size %s%d ctrl %08x sofn %08x (%c%c%c%c:%c%c:%s)",
> + __get_str(dev_name), __get_str(name), __entry->trb, __entry->enqueue,
> __entry->dequeue, __entry->bph, __entry->bpl,
> ({char *s;
> int pcm = ((__entry->size >> 24) & 3) + 1;
> @@ -290,6 +308,7 @@ DECLARE_EVENT_CLASS(dwc3_log_ep,
> TP_PROTO(struct dwc3_ep *dep),
> TP_ARGS(dep),
> TP_STRUCT__entry(
> + __string(dev_name, dev_name(dep->dwc->dev))
> __string(name, dep->name)
> __field(unsigned int, maxpacket)
> __field(unsigned int, maxpacket_limit)
> @@ -301,6 +320,7 @@ DECLARE_EVENT_CLASS(dwc3_log_ep,
> __field(u8, trb_dequeue)
> ),
> TP_fast_assign(
> + __assign_str(dev_name);
> __assign_str(name);
> __entry->maxpacket = dep->endpoint.maxpacket;
> __entry->maxpacket_limit = dep->endpoint.maxpacket_limit;
> @@ -311,8 +331,8 @@ DECLARE_EVENT_CLASS(dwc3_log_ep,
> __entry->trb_enqueue = dep->trb_enqueue;
> __entry->trb_dequeue = dep->trb_dequeue;
> ),
> - TP_printk("%s: mps %d/%d streams %d burst %d ring %d/%d flags %c:%c%c%c%c:%c",
> - __get_str(name), __entry->maxpacket,
> + TP_printk("%s: %s: mps %d/%d streams %d burst %d ring %d/%d flags %c:%c%c%c%c:%c",
> + __get_str(dev_name), __get_str(name), __entry->maxpacket,
> __entry->maxpacket_limit, __entry->max_streams,
> __entry->maxburst, __entry->trb_enqueue,
> __entry->trb_dequeue,
> --
> 2.25.1
>
Powered by blists - more mailing lists