Re: [PATCH v11 03/19] dyndbg: add write-to-tracefs code
On Fri, Jan 07, 2022 at 06:29:26AM +0100, Jim Cromie wrote:
> adds: dynamic_trace()
> uses trace_console() temporarily to issue printk:console event
> uses internal-ish __ftrace_trace_stack code:
> 4-context buffer stack, barriers per Steve
>
> call it from new funcs:
> dynamic_printk() - print to both syslog/tracefs
> dynamic_dev_printk() - dev-print to both syslog/tracefs
>
> These handle both _DPRINTK_FLAGS_PRINTK and _DPRINTK_FLAGS_TRACE
> cases, allowing to vsnprintf the message once and use it for both,
> skipping past the KERN_DEBUG character for tracing.
>
> Finally, adjust the callers: __dynamic_{pr_debug,{,net,ib}dev_dbg},
> replacing printk and dev_printk with the new funcs above.
>
> The _DPRINTK_FLAGS_TRACE flag character s 'T', so the following finds
> all callsites enabled for tracing:
>
> grep -P =p?T /proc/dynamic_debug/control
>
> Enabling debug-to-tracefs is 2 steps:
>
> # event enable
> echo 1 > /sys/kernel/tracing/events/dyndbg/enable
> # callsite enable
> echo module foo +T > /proc/dynamic_debug/control
>
> This patch,~1,~2 are based upon:
>
> https://lore.kernel.org/lkml/20200825153338.17061-1-vincent.whitchu...@axis.com/
>
> .. with simplification of temporarily reusing trace_console() rather
> than adding a new printk:dyndbg event. Soon, add 2 new events
> capturing the pr_debug & dev_dbg() args.
The example above does not match the code in this patch since the
dyndbg:* events are only added in a later patch. Perhaps you could
reorder this patch stack so that you don't use trace_console() in this
patch just to replace it with the new events in the next patch?
>
> CC: vincent.whitchu...@axis.com
> Signed-off-by: Jim Cromie
> ---
> .../admin-guide/dynamic-debug-howto.rst | 1 +
> lib/dynamic_debug.c | 155 +++---
> 2 files changed, 130 insertions(+), 26 deletions(-)
>
> diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst
> b/Documentation/admin-guide/dynamic-debug-howto.rst
[...]
> @@ -723,29 +822,33 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
> {
> struct va_format vaf;
> va_list args;
> + unsigned int flags;
>
> va_start(args, fmt);
>
> vaf.fmt = fmt;
> vaf.va =
> + 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(>dev),
> - );
> + 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(>dev),
> +);
> } else if (ibdev) {
> - printk(KERN_DEBUG "%s: %pV", dev_name(>dev), );
> + dynamic_printk(flags, KERN_DEBUG "%s%s: %pV",
> +dev_name(>dev), );
> } else {
> - printk(KERN_DEBUG "(NULL ib_device): %pV", );
> + dynamic_printk(flags, KERN_DEBUG "(NULL ip_device): %pV",
> +);
> }
>
> - va_end(args);
> +va_end(args);
This looks like an unintentional whitespace change?
Re: [PATCH v11 01/19] dyndbg: add _DPRINTK_FLAGS_ENABLED
On Fri, Jan 07, 2022 at 06:29:24AM +0100, Jim Cromie wrote:
> #ifdef CONFIG_JUMP_LABEL
> - if (dp->flags & _DPRINTK_FLAGS_PRINT) {
> - if (!(modifiers->flags & _DPRINTK_FLAGS_PRINT))
> + if (dp->flags & _DPRINTK_FLAGS_ENABLED) {
> + if (!(modifiers->flags &
> _DPRINTK_FLAGS_ENABLED))
>
> static_branch_disable(>key.dd_key_true);
> - } else if (modifiers->flags & _DPRINTK_FLAGS_PRINT)
> + } else if (modifiers->flags & _DPRINTK_FLAGS_ENABLED)
> static_branch_enable(>key.dd_key_true);
> #endif
> dp->flags = newflags;
> --
> 2.33.1
>
I haven't tested it so I could be mistaken, but when
_DPRINTK_FLAGS_ENABLED gets two flags in the next patch, it looks like
this code still has the problem which I mentioned in
https://lore.kernel.org/lkml/20211209150910.ga23...@axis.com/?
| 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).
| [...]
| #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(>key.dd_key_true);
| - } else if (modifiers->flags & _DPRINTK_FLAGS_PRINT)
| + }
| + } else if (modifiers->flags & _DPRINTK_FLAGS_ENABLE) {
| static_branch_enable(>key.dd_key_true);
| + }
| #endif
Re: [PATCH v10 08/10] dyndbg: add print-to-tracefs, selftest with it - RFC
On Wed, Dec 08, 2021 at 06:16:10AM +0100, jim.cro...@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::
penables the pr_debug() callsite.
+ xenables trace to the printk:dyndbg event
fInclude the function name in the printed message
lInclude line number in the printed message
mInclude 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 /dynamic_debug/control
*/
#define _DPRINTK_FLAGS_NONE0
-#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
-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
#include
#include
+#include
#include
@@ -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' },
{
Re: [PATCH v10 08/10] dyndbg: add print-to-tracefs, selftest with it - RFC
On Fri, Nov 19, 2021 at 11:46:31PM +0100, jim.cro...@gmail.com wrote: > Vincent's code has the macro magic to define that event, which IIUC > is what makes it controllable by ftrace, and therefore acceptable in > principle to Steve. > Would there be any reason to expand his set of 2 events into dev_dbg, > pr_debug etc varieties ? > (ie any value to separating dev, !dev ?, maybe so > > Sean's code uses trace_array_printk primarily, which is EXPORTed, > which is a virtue. > > Vincents code does > +/* > + * This code is heavily based on __ftrace_trace_stack(). > + * > + * Allow 4 levels of nesting: normal, softirq, irq, NMI. > + */ > > to implement > > +static void dynamic_trace(const char *fmt, va_list args) > > Has this __ftrace_trace_stack() code been bundled into or hidden under > a supported interface ? > > would it look anything like trace_array_printk() ? > > what problem is that code solving inside dynamic-debug.c ? I'm not sure I fully understand all of your questions, but perhaps this thread with Steven's reply to the first version of my patchset will answer some of them: https://lore.kernel.org/lkml/20200723112644.7759f...@oasis.local.home/
Re: [PATCH v10 08/10] dyndbg: add print-to-tracefs, selftest with it - RFC
On Thu, Nov 11, 2021 at 03:02:04PM -0700, Jim Cromie wrote: > Sean Paul proposed, in: > https://patchwork.freedesktop.org/series/78133/ > drm/trace: Mirror DRM debug logs to tracefs > > His patchset's objective is to be able to independently steer some of > the drm.debug stream to an alternate tracing destination, by splitting > drm_debug_enabled() into syslog & trace flavors, and enabling them > separately. 2 advantages were identified: > > 1- syslog is heavyweight, tracefs is much lighter > 2- separate selection of enabled categories means less traffic > > Dynamic-Debug can do 2nd exceedingly well: > > A- all work is behind jump-label's NOOP, zero off cost. > B- exact site selectivity, precisely the useful traffic. >can tailor enabled set interactively, at shell. > > Since the tracefs interface is effective for drm (the threads suggest > so), adding that interface to dynamic-debug has real potential for > everyone including drm. > > if CONFIG_TRACING: > > Grab Sean's trace_init/cleanup code, use it to provide tracefs > available by default to all pr_debugs. This will likely need some > further per-module treatment; perhaps something reflecting hierarchy > of module,file,function,line, maybe with a tuned flattening. > > endif CONFIG_TRACING > > Add a new +T flag to enable tracing, independent of +p, and add and > use 3 macros: dyndbg_site_is_enabled/logging/tracing(), to encapsulate > the flag checks. Existing code treats T like other flags. I posted a patchset a while ago to do something very similar, but that got stalled for some reason and I unfortunately didn't follow it up: https://lore.kernel.org/lkml/20200825153338.17061-1-vincent.whitchu...@axis.com/ A key difference between that patchset and this patch (besides that small fact that I used +x instead of +T) was that my patchset allowed the dyndbg trace to be emitted to the main buffer and did not force them to be in an instance-specific buffer. That feature is quite important at least for my use case since I often use dyndbg combined with function tracing, and the latter doesn't work on non-main instances according to Documentation/trace/ftrace.rst. For example, here's a random example of a bootargs from one of my recent debugging sessions: trace_event=printk:* ftrace_filter=_mmc*,mmc*,sd*,dw_mci*,mci* ftrace=function trace_buf_size=20M dyndbg="file drivers/mmc/* +x"
