From: Vincent Whitchurch <vincent.whitchurch@axis.com> To: "jim.cromie@gmail.com" <jim.cromie@gmail.com> Cc: Steven Rostedt <rostedt@goodmis.org>, Jason Baron <jbaron@akamai.com>, Greg KH <gregkh@linuxfoundation.org>, "robdclark@gmail.com" <robdclark@gmail.com>, Sean Paul <sean@poorly.run>, Daniel Vetter <daniel.vetter@ffwll.ch>, Sean Paul <seanpaul@chromium.org>, "lyude@redhat.com" <lyude@redhat.com>, LKML <linux-kernel@vger.kernel.org>, "mathieu.desnoyers@efficios.com" <mathieu.desnoyers@efficios.com>, dri-devel <dri-devel@lists.freedesktop.org>, amd-gfx mailing list <amd-gfx@lists.freedesktop.org>, "intel-gvt-dev@lists.freedesktop.org" <intel-gvt-dev@lists.freedesktop.org>, Intel Graphics Development <intel-gfx@lists.freedesktop.org>, "quic_saipraka@quicinc.com" <quic_saipraka@quicinc.com>, Will Deacon <will@kernel.org>, Catalin Marinas <catalin.marinas@arm.com>, "quic_psodagud@quicinc.com" <quic_psodagud@quicinc.com>, "maz@kernel.org" <maz@kernel.org>, Arnd Bergmann <arnd@arndb.de>, Linux ARM <linux-arm-kernel@lists.infradead.org>, "linux-arm-msm@vger.kernel.org" <linux-arm-msm@vger.kernel.org>, Ingo Molnar <mingo@redhat.com> Subject: Re: [PATCH v10 08/10] dyndbg: add print-to-tracefs, selftest with it - RFC Date: Thu, 9 Dec 2021 16:09:10 +0100 [thread overview] Message-ID: <20211209150910.GA23668@axis.com> (raw) In-Reply-To: <CAJfuBxxnuXAR7Jgn74MNQC7MLRc0xcDLw1cCidUJ9Xyar+O_2g@mail.gmail.com> On Wed, Dec 08, 2021 at 06:16:10AM +0100, jim.cromie@gmail.com wrote: > are you planning to dust this patchset off and resubmit it ? > > Ive been playing with it and learning ftrace (decade+ late), > I found your boot-line example very helpful as 1st steps > (still havent even tried the filtering) > > > with these adjustments (voiced partly to test my understanding) > I would support it, and rework my patchset to use it. > > - change flag to -e, good mnemonics for event/trace-event > T is good too, but uppercase, no need to go there. Any flag name works for me. > - include/trace/events/dyndbg.h - separate file, not mixed with print.h > dyndbg class, so trace_event=dyndbg:* > > - 1 event type per pr_debug, dev_dbg, netdev_dbg ? ibdev_dbg ? > with the extra args: descriptor that Steven wanted, > probably also struct <|net|ib>dev For my use cases I don't see much value in having separate events for the different debug functions, but since all of them can be easily enabled (dyndbg:*, as you noted), that works for me too. > If youre too busy for a while, I'd eventually take a (slow) run at it. You're welcome to have a go. I think you've already rebased the patchset, but here's a diff top of v5.16-rc4 for reference. I noticed a bug inside the CONFIG_JUMP_LABEL handling (also present in the last version I posted) which should be fixed as part of the diff below (I've added a comment). Proper tests for this, like the ones you are adding in your patchset, would certainly be a good idea. Thanks. 8<------------- diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst index a89cfa083155..b9c4e808befc 100644 --- a/Documentation/admin-guide/dynamic-debug-howto.rst +++ b/Documentation/admin-guide/dynamic-debug-howto.rst @@ -228,6 +228,7 @@ of the characters:: The flags are:: p enables the pr_debug() callsite. + x enables trace to the printk:dyndbg event f Include the function name in the printed message l Include line number in the printed message m Include module name in the printed message diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index dce631e678dd..bc21bfb0fdc6 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -27,7 +27,7 @@ struct _ddebug { * writes commands to <debugfs>/dynamic_debug/control */ #define _DPRINTK_FLAGS_NONE 0 -#define _DPRINTK_FLAGS_PRINT (1<<0) /* printk() a message using the format */ +#define _DPRINTK_FLAGS_PRINTK (1<<0) /* printk() a message using the format */ #define _DPRINTK_FLAGS_INCL_MODNAME (1<<1) #define _DPRINTK_FLAGS_INCL_FUNCNAME (1<<2) #define _DPRINTK_FLAGS_INCL_LINENO (1<<3) @@ -37,8 +37,11 @@ struct _ddebug { (_DPRINTK_FLAGS_INCL_MODNAME | _DPRINTK_FLAGS_INCL_FUNCNAME |\ _DPRINTK_FLAGS_INCL_LINENO | _DPRINTK_FLAGS_INCL_TID) +#define _DPRINTK_FLAGS_TRACE (1<<5) +#define _DPRINTK_FLAGS_ENABLE (_DPRINTK_FLAGS_PRINTK | \ + _DPRINTK_FLAGS_TRACE) #if defined DEBUG -#define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINT +#define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINTK #else #define _DPRINTK_FLAGS_DEFAULT 0 #endif @@ -120,10 +123,10 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, #ifdef DEBUG #define DYNAMIC_DEBUG_BRANCH(descriptor) \ - likely(descriptor.flags & _DPRINTK_FLAGS_PRINT) + likely(descriptor.flags & _DPRINTK_FLAGS_ENABLE) #else #define DYNAMIC_DEBUG_BRANCH(descriptor) \ - unlikely(descriptor.flags & _DPRINTK_FLAGS_PRINT) + unlikely(descriptor.flags & _DPRINTK_FLAGS_ENABLE) #endif #endif /* CONFIG_JUMP_LABEL */ diff --git a/include/trace/events/printk.h b/include/trace/events/printk.h index 13d405b2fd8b..1f78bd237a91 100644 --- a/include/trace/events/printk.h +++ b/include/trace/events/printk.h @@ -7,7 +7,7 @@ #include <linux/tracepoint.h> -TRACE_EVENT(console, +DECLARE_EVENT_CLASS(printk, TP_PROTO(const char *text, size_t len), TP_ARGS(text, len), @@ -31,6 +31,16 @@ TRACE_EVENT(console, TP_printk("%s", __get_str(msg)) ); + +DEFINE_EVENT(printk, console, + TP_PROTO(const char *text, size_t len), + TP_ARGS(text, len) +); + +DEFINE_EVENT(printk, dyndbg, + TP_PROTO(const char *text, size_t len), + TP_ARGS(text, len) +); #endif /* _TRACE_PRINTK_H */ /* This part must be outside protection */ diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index dd7f56af9aed..161454fa0af8 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -36,6 +36,7 @@ #include <linux/sched.h> #include <linux/device.h> #include <linux/netdevice.h> +#include <trace/events/printk.h> #include <rdma/ib_verbs.h> @@ -86,11 +87,12 @@ static inline const char *trim_prefix(const char *path) } static struct { unsigned flag:8; char opt_char; } opt_array[] = { - { _DPRINTK_FLAGS_PRINT, 'p' }, + { _DPRINTK_FLAGS_PRINTK, 'p' }, { _DPRINTK_FLAGS_INCL_MODNAME, 'm' }, { _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' }, { _DPRINTK_FLAGS_INCL_LINENO, 'l' }, { _DPRINTK_FLAGS_INCL_TID, 't' }, + { _DPRINTK_FLAGS_TRACE, 'x' }, { _DPRINTK_FLAGS_NONE, '_' }, }; @@ -210,11 +212,23 @@ static int ddebug_change(const struct ddebug_query *query, if (newflags == dp->flags) continue; #ifdef CONFIG_JUMP_LABEL - if (dp->flags & _DPRINTK_FLAGS_PRINT) { - if (!(modifiers->flags & _DPRINTK_FLAGS_PRINT)) + if (dp->flags & _DPRINTK_FLAGS_ENABLE) { + /* + * The newflags check is to ensure that the + * static branch doesn't get disabled in step + * 3: + * + * (1) +pf + * (2) +x + * (3) -pf + */ + if (!(modifiers->flags & _DPRINTK_FLAGS_ENABLE) && + !(newflags & _DPRINTK_FLAGS_ENABLE)) { static_branch_disable(&dp->key.dd_key_true); - } else if (modifiers->flags & _DPRINTK_FLAGS_PRINT) + } + } else if (modifiers->flags & _DPRINTK_FLAGS_ENABLE) { static_branch_enable(&dp->key.dd_key_true); + } #endif dp->flags = newflags; v4pr_info("changed %s:%d [%s]%s =%s\n", @@ -621,6 +635,96 @@ static char *__dynamic_emit_prefix(const struct _ddebug *desc, char *buf) return buf; } +/* + * This code is heavily based on __ftrace_trace_stack(). + * + * Allow 4 levels of nesting: normal, softirq, irq, NMI. + */ +#define DYNAMIC_TRACE_NESTING 4 + +struct dynamic_trace_buf { + char buf[256]; +}; + +struct dynamic_trace_bufs { + struct dynamic_trace_buf bufs[DYNAMIC_TRACE_NESTING]; +}; + +static DEFINE_PER_CPU(struct dynamic_trace_bufs, dynamic_trace_bufs); +static DEFINE_PER_CPU(int, dynamic_trace_reserve); + +static void dynamic_trace(const char *fmt, va_list args) +{ + struct dynamic_trace_buf *buf; + int bufidx; + int len; + + preempt_disable_notrace(); + + bufidx = __this_cpu_inc_return(dynamic_trace_reserve) - 1; + + if (WARN_ON_ONCE(bufidx > DYNAMIC_TRACE_NESTING)) + goto out; + + /* For the same reasons as in __ftrace_trace_stack(). */ + barrier(); + + buf = this_cpu_ptr(dynamic_trace_bufs.bufs) + bufidx; + + len = vscnprintf(buf->buf, sizeof(buf->buf), fmt, args); + trace_dyndbg(buf->buf, len); + +out: + /* As above. */ + barrier(); + __this_cpu_dec(dynamic_trace_reserve); + preempt_enable_notrace(); +} + +static void dynamic_printk(unsigned int flags, const char *fmt, ...) +{ + if (flags & _DPRINTK_FLAGS_TRACE) { + va_list args; + + va_start(args, fmt); + /* + * All callers include the KERN_DEBUG prefix to keep the + * vprintk case simple; strip it out for tracing. + */ + dynamic_trace(fmt + strlen(KERN_DEBUG), args); + va_end(args); + } + + if (flags & _DPRINTK_FLAGS_PRINTK) { + va_list args; + + va_start(args, fmt); + vprintk(fmt, args); + va_end(args); + } +} + +static void dynamic_dev_printk(unsigned int flags, const struct device *dev, + const char *fmt, ...) +{ + + if (flags & _DPRINTK_FLAGS_TRACE) { + va_list args; + + va_start(args, fmt); + dynamic_trace(fmt, args); + va_end(args); + } + + if (flags & _DPRINTK_FLAGS_PRINTK) { + va_list args; + + va_start(args, fmt); + dev_vprintk_emit(LOGLEVEL_DEBUG, dev, fmt, args); + va_end(args); + } +} + static inline char *dynamic_emit_prefix(struct _ddebug *desc, char *buf) { if (unlikely(desc->flags & _DPRINTK_FLAGS_INCL_ANY)) @@ -642,7 +746,8 @@ void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...) vaf.fmt = fmt; vaf.va = &args; - printk(KERN_DEBUG "%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf); + dynamic_printk(descriptor->flags, KERN_DEBUG "%s%pV", + dynamic_emit_prefix(descriptor, buf), &vaf); va_end(args); } @@ -652,6 +757,7 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor, const struct device *dev, const char *fmt, ...) { struct va_format vaf; + unsigned int flags; va_list args; BUG_ON(!descriptor); @@ -661,16 +767,18 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor, vaf.fmt = fmt; vaf.va = &args; + flags = descriptor->flags; if (!dev) { - printk(KERN_DEBUG "(NULL device *): %pV", &vaf); + dynamic_printk(flags, KERN_DEBUG "(NULL device *): %pV", + &vaf); } else { char buf[PREFIX_SIZE] = ""; - dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV", - dynamic_emit_prefix(descriptor, buf), - dev_driver_string(dev), dev_name(dev), - &vaf); + dynamic_dev_printk(flags, dev, "%s%s %s: %pV", + dynamic_emit_prefix(descriptor, buf), + dev_driver_string(dev), dev_name(dev), + &vaf); } va_end(args); @@ -683,6 +791,7 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor, const struct net_device *dev, const char *fmt, ...) { struct va_format vaf; + unsigned int flags; va_list args; BUG_ON(!descriptor); @@ -692,22 +801,24 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor, vaf.fmt = fmt; vaf.va = &args; + flags = descriptor->flags; if (dev && dev->dev.parent) { char buf[PREFIX_SIZE] = ""; - dev_printk_emit(LOGLEVEL_DEBUG, dev->dev.parent, - "%s%s %s %s%s: %pV", - dynamic_emit_prefix(descriptor, buf), - dev_driver_string(dev->dev.parent), - dev_name(dev->dev.parent), - netdev_name(dev), netdev_reg_state(dev), - &vaf); + dynamic_dev_printk(flags, dev->dev.parent, + "%s%s %s %s%s: %pV", + dynamic_emit_prefix(descriptor, buf), + dev_driver_string(dev->dev.parent), + dev_name(dev->dev.parent), + netdev_name(dev), netdev_reg_state(dev), + &vaf); } else if (dev) { - printk(KERN_DEBUG "%s%s: %pV", netdev_name(dev), - netdev_reg_state(dev), &vaf); + dynamic_printk(flags, KERN_DEBUG "%s%s: %pV", + netdev_name(dev), netdev_reg_state(dev), &vaf); } else { - printk(KERN_DEBUG "(NULL net_device): %pV", &vaf); + dynamic_printk(flags, KERN_DEBUG "(NULL net_device): %pV", + &vaf); } va_end(args); @@ -722,27 +833,31 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, const struct ib_device *ibdev, const char *fmt, ...) { struct va_format vaf; + unsigned int flags; va_list args; va_start(args, fmt); vaf.fmt = fmt; vaf.va = &args; + flags = descriptor->flags; if (ibdev && ibdev->dev.parent) { char buf[PREFIX_SIZE] = ""; - dev_printk_emit(LOGLEVEL_DEBUG, ibdev->dev.parent, - "%s%s %s %s: %pV", - dynamic_emit_prefix(descriptor, buf), - dev_driver_string(ibdev->dev.parent), - dev_name(ibdev->dev.parent), - dev_name(&ibdev->dev), - &vaf); + dynamic_dev_printk(flags, ibdev->dev.parent, + "%s%s %s %s: %pV", + dynamic_emit_prefix(descriptor, buf), + dev_driver_string(ibdev->dev.parent), + dev_name(ibdev->dev.parent), + dev_name(&ibdev->dev), + &vaf); } else if (ibdev) { - printk(KERN_DEBUG "%s: %pV", dev_name(&ibdev->dev), &vaf); + dynamic_printk(flags, KERN_DEBUG "%s: %pV", + dev_name(&ibdev->dev), &vaf); } else { - printk(KERN_DEBUG "(NULL ib_device): %pV", &vaf); + dynamic_printk(flags, KERN_DEBUG "(NULL ib_device): %pV", + &vaf); } va_end(args);
next prev parent reply other threads:[~2021-12-09 15:09 UTC|newest] Thread overview: 30+ messages / expand[flat|nested] mbox.gz Atom feed top 2021-11-11 22:01 [PATCH v10 00/10 RESEND] use DYNAMIC_DEBUG to implement DRM.debug & DRM.trace Jim Cromie 2021-11-11 22:01 ` [PATCH v10 01/10] dyndbg: add DEFINE_DYNAMIC_DEBUG_BITGRPS macro and callbacks Jim Cromie 2021-11-11 22:01 ` [PATCH v10 02/10] drm: fix doc grammar Jim Cromie 2021-11-11 22:01 ` [PATCH v10 03/10] amdgpu: use dyndbg.BITGRPS to control existing pr_debugs Jim Cromie 2021-11-11 22:02 ` [PATCH v10 04/10] i915/gvt: trim spaces from pr_debug "gvt: core:" prefixes Jim Cromie 2021-11-11 22:02 ` [PATCH v10 05/10] i915/gvt: use dyndbg.BITGRPS for existing pr_debugs Jim Cromie 2021-11-11 22:02 ` [PATCH v10 06/10] drm_print: add choice to use dynamic debug in drm-debug Jim Cromie 2021-11-11 22:02 ` [PATCH v10 07/10] drm_print: instrument drm_debug_enabled Jim Cromie 2021-11-11 22:02 ` [PATCH v10 08/10] dyndbg: add print-to-tracefs, selftest with it - RFC Jim Cromie 2021-11-12 11:49 ` Vincent Whitchurch 2021-11-12 15:08 ` Jason Baron 2021-11-12 17:07 ` Steven Rostedt 2021-11-12 17:32 ` Jason Baron 2021-11-12 17:54 ` Steven Rostedt 2021-11-16 8:46 ` Pekka Paalanen 2021-11-18 14:29 ` Jason Baron 2021-11-18 15:24 ` Pekka Paalanen 2021-11-19 16:21 ` Jason Baron 2021-11-19 22:46 ` jim.cromie 2021-11-19 22:54 ` Steven Rostedt 2021-11-25 13:51 ` Vincent Whitchurch 2021-11-22 9:02 ` Pekka Paalanen 2021-11-22 22:42 ` jim.cromie 2021-11-23 8:45 ` Pekka Paalanen 2021-11-23 9:32 ` Simon Ser 2021-12-08 5:16 ` jim.cromie 2021-12-09 15:09 ` Vincent Whitchurch [this message] 2021-11-11 22:02 ` [PATCH v10 09/10] dyndbg: create DEFINE_DYNAMIC_DEBUG_LOG|TRACE_GROUPS Jim Cromie 2021-11-11 22:02 ` [PATCH v10 10/10] drm: use DEFINE_DYNAMIC_DEBUG_TRACE_GROUPS in 3 places Jim Cromie -- strict thread matches above, loose matches on Subject: below -- 2021-11-05 19:26 [PATCH v10 00/10] use DYNAMIC_DEBUG to implement DRM.debug & DRM.trace Jim Cromie 2021-11-05 19:26 ` [PATCH v10 08/10] dyndbg: add print-to-tracefs, selftest with it - RFC Jim Cromie
Reply instructions: You may reply publicly to this message via plain-text email using any one of the following methods: * Save the following mbox file, import it into your mail client, and reply-to-all from there: mbox Avoid top-posting and favor interleaved quoting: https://en.wikipedia.org/wiki/Posting_style#Interleaved_style * Reply using the --to, --cc, and --in-reply-to switches of git-send-email(1): git send-email \ --in-reply-to=20211209150910.GA23668@axis.com \ --to=vincent.whitchurch@axis.com \ --cc=amd-gfx@lists.freedesktop.org \ --cc=arnd@arndb.de \ --cc=catalin.marinas@arm.com \ --cc=daniel.vetter@ffwll.ch \ --cc=dri-devel@lists.freedesktop.org \ --cc=gregkh@linuxfoundation.org \ --cc=intel-gfx@lists.freedesktop.org \ --cc=intel-gvt-dev@lists.freedesktop.org \ --cc=jbaron@akamai.com \ --cc=jim.cromie@gmail.com \ --cc=linux-arm-kernel@lists.infradead.org \ --cc=linux-arm-msm@vger.kernel.org \ --cc=linux-kernel@vger.kernel.org \ --cc=lyude@redhat.com \ --cc=mathieu.desnoyers@efficios.com \ --cc=maz@kernel.org \ --cc=mingo@redhat.com \ --cc=quic_psodagud@quicinc.com \ --cc=quic_saipraka@quicinc.com \ --cc=robdclark@gmail.com \ --cc=rostedt@goodmis.org \ --cc=sean@poorly.run \ --cc=seanpaul@chromium.org \ --cc=will@kernel.org \ --subject='Re: [PATCH v10 08/10] dyndbg: add print-to-tracefs, selftest with it - RFC' \ /path/to/YOUR_REPLY https://kernel.org/pub/software/scm/git/docs/git-send-email.html * If your mail client supports setting the In-Reply-To header via mailto: links, try the mailto: link
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).