From: Jim Cromie <jim.cromie@gmail.com>
ddebug_trace() currently issues a single printk:console event.
Replace that event by adding include/trace/events/dyndbg.h,
which defines 2 new trace-events: dyndbg:prdbg & dyndbg:devdbg.
These events get the _ddebug descriptor, so they can access the whole
callsite record: file, line, function, flags. This allows the
addition of a dynamic prefix later.
So ddebug_trace() gets 2 new args: the descriptor and the device.
And its callers: ddebug_printk(), ddebug_dev_printk() upgrade their
flags param to pass the descriptor itself, and thus also the flags.
Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
MAINTAINERS | 1 +
include/trace/events/dyndbg.h | 74 +++++++++++++++++++++++++++++++++++
lib/dynamic_debug.c | 73 +++++++++++++++++-----------------
3 files changed, 112 insertions(+), 36 deletions(-)
create mode 100644 include/trace/events/dyndbg.h
diff --git a/MAINTAINERS b/MAINTAINERS
index dd5de540ec0b..fd02dc86f1fd 100644
--- a/MAINTAINERS
+++ b/MAINTAINERS
@@ -7320,6 +7320,7 @@ M: Jason Baron <jbaron@akamai.com>
M: Jim Cromie <jim.cromie@gmail.com>
S: Maintained
F: include/linux/dynamic_debug.h
+F: include/trace/events/dyndbg.h
F: lib/dynamic_debug.c
F: lib/test_dynamic_debug.c
diff --git a/include/trace/events/dyndbg.h b/include/trace/events/dyndbg.h
new file mode 100644
index 000000000000..ccc5bcb070f9
--- /dev/null
+++ b/include/trace/events/dyndbg.h
@@ -0,0 +1,74 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM dyndbg
+
+#if !defined(_TRACE_DYNDBG_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_DYNDBG_H
+
+#include <linux/tracepoint.h>
+
+/* capture pr_debug() callsite descriptor and message */
+TRACE_EVENT(prdbg,
+ TP_PROTO(const struct _ddebug *desc, const char *text, size_t len),
+
+ TP_ARGS(desc, text, len),
+
+ TP_STRUCT__entry(
+ __field(const struct _ddebug *, desc)
+ __dynamic_array(char, msg, len + 1)
+ ),
+
+ TP_fast_assign(
+ __entry->desc = desc;
+ /*
+ * Each trace entry is printed in a new line.
+ * If the msg finishes with '\n', cut it off
+ * to avoid blank lines in the trace.
+ */
+ if (len > 0 && (text[len - 1] == '\n'))
+ len -= 1;
+
+ memcpy(__get_str(msg), text, len);
+ __get_str(msg)[len] = 0;
+ ),
+
+ TP_printk("%s.%s %s", __entry->desc->modname,
+ __entry->desc->function, __get_str(msg))
+);
+
+/* capture dev_dbg() callsite descriptor, device, and message */
+TRACE_EVENT(devdbg,
+ TP_PROTO(const struct _ddebug *desc, const struct device *dev,
+ const char *text, size_t len),
+
+ TP_ARGS(desc, dev, text, len),
+
+ TP_STRUCT__entry(
+ __field(const struct _ddebug *, desc)
+ __field(const struct device *, dev)
+ __dynamic_array(char, msg, len + 1)
+ ),
+
+ TP_fast_assign(
+ __entry->desc = desc;
+ __entry->dev = (struct device *) dev;
+ /*
+ * Each trace entry is printed in a new line.
+ * If the msg finishes with '\n', cut it off
+ * to avoid blank lines in the trace.
+ */
+ if (len > 0 && (text[len - 1] == '\n'))
+ len -= 1;
+
+ memcpy(__get_str(msg), text, len);
+ __get_str(msg)[len] = 0;
+ ),
+
+ TP_printk("%s.%s %s", __entry->desc->modname,
+ __entry->desc->function, __get_str(msg))
+);
+
+#endif /* _TRACE_DYNDBG_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 016f33c20251..1ed3c4f16f69 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -36,7 +36,9 @@
#include <linux/sched.h>
#include <linux/device.h>
#include <linux/netdevice.h>
-#include <trace/events/printk.h>
+
+#define CREATE_TRACE_POINTS
+#include <trace/events/dyndbg.h>
#include <rdma/ib_verbs.h>
@@ -878,7 +880,9 @@ struct ddebug_trace_bufs {
static DEFINE_PER_CPU(struct ddebug_trace_bufs, ddebug_trace_bufs);
static DEFINE_PER_CPU(int, ddebug_trace_reserve);
-static void ddebug_trace(const char *fmt, va_list args)
+__printf(3, 0)
+static void ddebug_trace(struct _ddebug *desc, const struct device *dev,
+ const char *fmt, va_list args)
{
struct ddebug_trace_buf *buf;
int bufidx;
@@ -897,7 +901,11 @@ static void ddebug_trace(const char *fmt, va_list args)
buf = this_cpu_ptr(ddebug_trace_bufs.bufs) + bufidx;
len = vscnprintf(buf->buf, sizeof(buf->buf), fmt, args);
- trace_console(buf->buf, len);
+
+ if (!dev)
+ trace_prdbg(desc, buf->buf, len);
+ else
+ trace_devdbg(desc, dev, buf->buf, len);
out:
/* As above. */
@@ -907,9 +915,9 @@ static void ddebug_trace(const char *fmt, va_list args)
}
__printf(2, 3)
-static void ddebug_printk(unsigned int flags, const char *fmt, ...)
+static void ddebug_printk(struct _ddebug *desc, const char *fmt, ...)
{
- if (flags & _DPRINTK_FLAGS_TRACE) {
+ if (desc->flags & _DPRINTK_FLAGS_TRACE) {
va_list args;
va_start(args, fmt);
@@ -917,11 +925,11 @@ static void ddebug_printk(unsigned int flags, const char *fmt, ...)
* All callers include the KERN_DEBUG prefix to keep the
* vprintk case simple; strip it out for tracing.
*/
- ddebug_trace(fmt + strlen(KERN_DEBUG), args);
+ ddebug_trace(desc, NULL, fmt + strlen(KERN_DEBUG), args);
va_end(args);
}
- if (flags & _DPRINTK_FLAGS_PRINTK) {
+ if (desc->flags & _DPRINTK_FLAGS_PRINTK) {
va_list args;
va_start(args, fmt);
@@ -931,19 +939,19 @@ static void ddebug_printk(unsigned int flags, const char *fmt, ...)
}
__printf(3, 4)
-static void ddebug_dev_printk(unsigned int flags, const struct device *dev,
+static void ddebug_dev_printk(struct _ddebug *desc, const struct device *dev,
const char *fmt, ...)
{
- if (flags & _DPRINTK_FLAGS_TRACE) {
+ if (desc->flags & _DPRINTK_FLAGS_TRACE) {
va_list args;
va_start(args, fmt);
- ddebug_trace(fmt, args);
+ ddebug_trace(desc, dev, fmt, args);
va_end(args);
}
- if (flags & _DPRINTK_FLAGS_PRINTK) {
+ if (desc->flags & _DPRINTK_FLAGS_PRINTK) {
va_list args;
va_start(args, fmt);
@@ -966,7 +974,7 @@ void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
vaf.fmt = fmt;
vaf.va = &args;
- ddebug_printk(descriptor->flags, KERN_DEBUG "%s%pV",
+ ddebug_printk(descriptor, KERN_DEBUG "%s%pV",
dynamic_emit_prefix(descriptor, buf), &vaf);
va_end(args);
@@ -977,7 +985,6 @@ 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);
@@ -987,15 +994,14 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
vaf.fmt = fmt;
vaf.va = &args;
- flags = descriptor->flags;
if (!dev) {
- ddebug_printk(flags, KERN_DEBUG "(NULL device *): %pV",
- &vaf);
+ ddebug_printk(descriptor, KERN_DEBUG "(NULL device *): %pV",
+ &vaf);
} else {
char buf[PREFIX_SIZE] = "";
- ddebug_dev_printk(flags, dev, "%s%s %s: %pV",
+ ddebug_dev_printk(descriptor, dev, "%s%s %s: %pV",
dynamic_emit_prefix(descriptor, buf),
dev_driver_string(dev), dev_name(dev),
&vaf);
@@ -1011,7 +1017,6 @@ 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);
@@ -1021,24 +1026,22 @@ 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] = "";
- ddebug_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);
+ ddebug_dev_printk(descriptor, 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) {
- ddebug_printk(flags, KERN_DEBUG "%s%s: %pV",
- netdev_name(dev), netdev_reg_state(dev), &vaf);
+ ddebug_dev_printk(descriptor, &dev->dev, KERN_DEBUG "%s%s: %pV",
+ netdev_name(dev), netdev_reg_state(dev), &vaf);
} else {
- ddebug_printk(flags, KERN_DEBUG "(NULL net_device): %pV",
- &vaf);
+ ddebug_printk(descriptor, KERN_DEBUG "(NULL net_device): %pV", &vaf);
}
va_end(args);
@@ -1054,18 +1057,16 @@ 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 = &args;
- flags = descriptor->flags;
if (ibdev && ibdev->dev.parent) {
char buf[PREFIX_SIZE] = "";
- ddebug_dev_printk(flags, ibdev->dev.parent,
+ ddebug_dev_printk(descriptor, ibdev->dev.parent,
"%s%s %s %s: %pV",
dynamic_emit_prefix(descriptor, buf),
dev_driver_string(ibdev->dev.parent),
@@ -1073,10 +1074,10 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
dev_name(&ibdev->dev),
&vaf);
} else if (ibdev) {
- ddebug_printk(flags, KERN_DEBUG "%s: %pV",
- dev_name(&ibdev->dev), &vaf);
+ ddebug_dev_printk(descriptor, &ibdev->dev, KERN_DEBUG "%s: %pV",
+ dev_name(&ibdev->dev), &vaf);
} else {
- ddebug_printk(flags, KERN_DEBUG "(NULL ip_device): %pV", &vaf);
+ ddebug_printk(descriptor, KERN_DEBUG "(NULL ip_device): %pV", &vaf);
}
va_end(args);
--
2.42.0.869.gea05f2083d-googOn Fri, 3 Nov 2023 14:10:03 +0100
Łukasz Bartosik <lb@semihalf.com> wrote:
> +/* capture pr_debug() callsite descriptor and message */
> +TRACE_EVENT(prdbg,
> + TP_PROTO(const struct _ddebug *desc, const char *text, size_t len),
> +
> + TP_ARGS(desc, text, len),
> +
> + TP_STRUCT__entry(
> + __field(const struct _ddebug *, desc)
> + __dynamic_array(char, msg, len + 1)
> + ),
> +
> + TP_fast_assign(
> + __entry->desc = desc;
> + /*
> + * Each trace entry is printed in a new line.
> + * If the msg finishes with '\n', cut it off
> + * to avoid blank lines in the trace.
> + */
> + if (len > 0 && (text[len - 1] == '\n'))
> + len -= 1;
> +
> + memcpy(__get_str(msg), text, len);
> + __get_str(msg)[len] = 0;
> + ),
> +
> + TP_printk("%s.%s %s", __entry->desc->modname,
> + __entry->desc->function, __get_str(msg))
> +);
> +
That TP_printk() is dangerous. How do you know __entry->desc still exists
when reading the buffer?
Is the struct _ddebug permanent? Can it be freed? If so, the above can
easily cause a crash.
-- Steve
wt., 7 lis 2023 o 00:55 Steven Rostedt <rostedt@goodmis.org> napisał(a):
>
> On Fri, 3 Nov 2023 14:10:03 +0100
> Łukasz Bartosik <lb@semihalf.com> wrote:
>
> > +/* capture pr_debug() callsite descriptor and message */
> > +TRACE_EVENT(prdbg,
> > + TP_PROTO(const struct _ddebug *desc, const char *text, size_t len),
> > +
> > + TP_ARGS(desc, text, len),
> > +
> > + TP_STRUCT__entry(
> > + __field(const struct _ddebug *, desc)
> > + __dynamic_array(char, msg, len + 1)
> > + ),
> > +
> > + TP_fast_assign(
> > + __entry->desc = desc;
> > + /*
> > + * Each trace entry is printed in a new line.
> > + * If the msg finishes with '\n', cut it off
> > + * to avoid blank lines in the trace.
> > + */
> > + if (len > 0 && (text[len - 1] == '\n'))
> > + len -= 1;
> > +
> > + memcpy(__get_str(msg), text, len);
> > + __get_str(msg)[len] = 0;
> > + ),
> > +
>
>
> > + TP_printk("%s.%s %s", __entry->desc->modname,
> > + __entry->desc->function, __get_str(msg))
> > +);
> > +
>
> That TP_printk() is dangerous. How do you know __entry->desc still exists
> when reading the buffer?
>
> Is the struct _ddebug permanent? Can it be freed? If so, the above can
> easily cause a crash.
>
I assume that we're talking here about the scenario where TP prdbg is
called and before TP_printk runs _ddebug pointer
becomes invalid, is that correct ? If so then I believe this also
applied to __dynamic_pr_debug and other dyndbg functions because there
is also potential for _ddebug pointer to become invalid (in case of
rrmod) before a function dereferences it.
Would it be acceptable to increase reference count of a module and
hold it until at least one callsite in that module is enabled ?
This would ensure that passed pointer to a _ddebug struct is valid.
> -- Steve
On Fri, Nov 10, 2023 at 7:51 AM Łukasz Bartosik <lb@semihalf.com> wrote:
>
> wt., 7 lis 2023 o 00:55 Steven Rostedt <rostedt@goodmis.org> napisał(a):
> >
> > On Fri, 3 Nov 2023 14:10:03 +0100
> > Łukasz Bartosik <lb@semihalf.com> wrote:
> >
> > > +/* capture pr_debug() callsite descriptor and message */
> > > +TRACE_EVENT(prdbg,
> > > + TP_PROTO(const struct _ddebug *desc, const char *text, size_t len),
> > > +
> > > + TP_ARGS(desc, text, len),
> > > +
> > > + TP_STRUCT__entry(
> > > + __field(const struct _ddebug *, desc)
> > > + __dynamic_array(char, msg, len + 1)
> > > + ),
> > > +
> > > + TP_fast_assign(
> > > + __entry->desc = desc;
> > > + /*
> > > + * Each trace entry is printed in a new line.
> > > + * If the msg finishes with '\n', cut it off
> > > + * to avoid blank lines in the trace.
> > > + */
> > > + if (len > 0 && (text[len - 1] == '\n'))
> > > + len -= 1;
> > > +
> > > + memcpy(__get_str(msg), text, len);
> > > + __get_str(msg)[len] = 0;
> > > + ),
> > > +
> >
> >
> > > + TP_printk("%s.%s %s", __entry->desc->modname,
> > > + __entry->desc->function, __get_str(msg))
> > > +);
> > > +
> >
> > That TP_printk() is dangerous. How do you know __entry->desc still exists
> > when reading the buffer?
> >
> > Is the struct _ddebug permanent? Can it be freed? If so, the above can
> > easily cause a crash.
> >
>
> I assume that we're talking here about the scenario where TP prdbg is
> called and before TP_printk runs _ddebug pointer
> becomes invalid, is that correct ? If so then I believe this also
> applied to __dynamic_pr_debug and other dyndbg functions because there
> is also potential for _ddebug pointer to become invalid (in case of
> rrmod) before a function dereferences it.
>
> Would it be acceptable to increase reference count of a module and
> hold it until at least one callsite in that module is enabled ?
> This would ensure that passed pointer to a _ddebug struct is valid.
>
Im not understanding you, but I dont think its on-point -
a loadable module might write lots to trace-log, and each trace-entry
would have the descriptor address, with which it could deref and print 3 fields.
Then rmmod happens, all the module mem is freed, and reused for someth9ing else.
then someone cats trace, and the descriptor addrs are used to render
the tracelog.
BOOM.
> > -- Steve
pt., 10 lis 2023 o 20:20 <jim.cromie@gmail.com> napisał(a):
>
> On Fri, Nov 10, 2023 at 7:51 AM Łukasz Bartosik <lb@semihalf.com> wrote:
> >
> > wt., 7 lis 2023 o 00:55 Steven Rostedt <rostedt@goodmis.org> napisał(a):
> > >
> > > On Fri, 3 Nov 2023 14:10:03 +0100
> > > Łukasz Bartosik <lb@semihalf.com> wrote:
> > >
> > > > +/* capture pr_debug() callsite descriptor and message */
> > > > +TRACE_EVENT(prdbg,
> > > > + TP_PROTO(const struct _ddebug *desc, const char *text, size_t len),
> > > > +
> > > > + TP_ARGS(desc, text, len),
> > > > +
> > > > + TP_STRUCT__entry(
> > > > + __field(const struct _ddebug *, desc)
> > > > + __dynamic_array(char, msg, len + 1)
> > > > + ),
> > > > +
> > > > + TP_fast_assign(
> > > > + __entry->desc = desc;
> > > > + /*
> > > > + * Each trace entry is printed in a new line.
> > > > + * If the msg finishes with '\n', cut it off
> > > > + * to avoid blank lines in the trace.
> > > > + */
> > > > + if (len > 0 && (text[len - 1] == '\n'))
> > > > + len -= 1;
> > > > +
> > > > + memcpy(__get_str(msg), text, len);
> > > > + __get_str(msg)[len] = 0;
> > > > + ),
> > > > +
> > >
> > >
> > > > + TP_printk("%s.%s %s", __entry->desc->modname,
> > > > + __entry->desc->function, __get_str(msg))
> > > > +);
> > > > +
> > >
> > > That TP_printk() is dangerous. How do you know __entry->desc still exists
> > > when reading the buffer?
> > >
> > > Is the struct _ddebug permanent? Can it be freed? If so, the above can
> > > easily cause a crash.
> > >
> >
> > I assume that we're talking here about the scenario where TP prdbg is
> > called and before TP_printk runs _ddebug pointer
> > becomes invalid, is that correct ? If so then I believe this also
> > applied to __dynamic_pr_debug and other dyndbg functions because there
> > is also potential for _ddebug pointer to become invalid (in case of
> > rrmod) before a function dereferences it.
> >
> > Would it be acceptable to increase reference count of a module and
> > hold it until at least one callsite in that module is enabled ?
> > This would ensure that passed pointer to a _ddebug struct is valid.
> >
>
> Im not understanding you, but I dont think its on-point -
>
> a loadable module might write lots to trace-log, and each trace-entry
> would have the descriptor address, with which it could deref and print 3 fields.
> Then rmmod happens, all the module mem is freed, and reused for someth9ing else.
>
> then someone cats trace, and the descriptor addrs are used to render
> the tracelog.
> BOOM.
>
Jim, thanks for educating me on this one. I completely missed the fact
that TP_printk is delayed until, for example as you mentioned cat is
run on a trace.
I'll remove passing of _ddebug ptr to trace_prdbg and trace_devdbg
functions. Probably also passing of dev ptr can removed from
trace_devdbg.
>
>
> > > -- Steve
On Fri, Nov 3, 2023 at 7:10 AM Łukasz Bartosik <lb@semihalf.com> wrote:
>
> From: Jim Cromie <jim.cromie@gmail.com>
>
> ddebug_trace() currently issues a single printk:console event.
> Replace that event by adding include/trace/events/dyndbg.h,
> which defines 2 new trace-events: dyndbg:prdbg & dyndbg:devdbg.
>
> These events get the _ddebug descriptor, so they can access the whole
> callsite record: file, line, function, flags. This allows the
> addition of a dynamic prefix later.
>
> So ddebug_trace() gets 2 new args: the descriptor and the device.
> And its callers: ddebug_printk(), ddebug_dev_printk() upgrade their
> flags param to pass the descriptor itself, and thus also the flags.
>
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
let me add:
I have doubts about adding the descriptor to the trace record.
For loadable modules in particular, those descriptors will go away at rmmod.
I added it thinking it would support filtering by callsite info.
Its not entirely clear whether it adds any utility, now or potentially.
During dev/hacking, I saw UNSAFE_<mumble> while TP_printk-ing the records,
while banging on it with various hammers (modprobe cycling probably)
maybe on rmmod, they could be "cached" (or pointers poisoned)
allowing their use until then (and maybe afterwards)
> ---
> MAINTAINERS | 1 +
> include/trace/events/dyndbg.h | 74 +++++++++++++++++++++++++++++++++++
> lib/dynamic_debug.c | 73 +++++++++++++++++-----------------
> 3 files changed, 112 insertions(+), 36 deletions(-)
> create mode 100644 include/trace/events/dyndbg.h
>
> diff --git a/MAINTAINERS b/MAINTAINERS
> index dd5de540ec0b..fd02dc86f1fd 100644
> --- a/MAINTAINERS
> +++ b/MAINTAINERS
> @@ -7320,6 +7320,7 @@ M: Jason Baron <jbaron@akamai.com>
> M: Jim Cromie <jim.cromie@gmail.com>
> S: Maintained
> F: include/linux/dynamic_debug.h
> +F: include/trace/events/dyndbg.h
> F: lib/dynamic_debug.c
> F: lib/test_dynamic_debug.c
>
> diff --git a/include/trace/events/dyndbg.h b/include/trace/events/dyndbg.h
> new file mode 100644
> index 000000000000..ccc5bcb070f9
> --- /dev/null
> +++ b/include/trace/events/dyndbg.h
> @@ -0,0 +1,74 @@
> +/* SPDX-License-Identifier: GPL-2.0 */
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM dyndbg
> +
> +#if !defined(_TRACE_DYNDBG_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_DYNDBG_H
> +
> +#include <linux/tracepoint.h>
> +
> +/* capture pr_debug() callsite descriptor and message */
> +TRACE_EVENT(prdbg,
> + TP_PROTO(const struct _ddebug *desc, const char *text, size_t len),
> +
> + TP_ARGS(desc, text, len),
> +
> + TP_STRUCT__entry(
> + __field(const struct _ddebug *, desc)
> + __dynamic_array(char, msg, len + 1)
> + ),
> +
> + TP_fast_assign(
> + __entry->desc = desc;
> + /*
> + * Each trace entry is printed in a new line.
> + * If the msg finishes with '\n', cut it off
> + * to avoid blank lines in the trace.
> + */
> + if (len > 0 && (text[len - 1] == '\n'))
> + len -= 1;
> +
> + memcpy(__get_str(msg), text, len);
> + __get_str(msg)[len] = 0;
> + ),
> +
> + TP_printk("%s.%s %s", __entry->desc->modname,
> + __entry->desc->function, __get_str(msg))
> +);
> +
> +/* capture dev_dbg() callsite descriptor, device, and message */
> +TRACE_EVENT(devdbg,
> + TP_PROTO(const struct _ddebug *desc, const struct device *dev,
> + const char *text, size_t len),
> +
> + TP_ARGS(desc, dev, text, len),
> +
> + TP_STRUCT__entry(
> + __field(const struct _ddebug *, desc)
> + __field(const struct device *, dev)
> + __dynamic_array(char, msg, len + 1)
> + ),
> +
> + TP_fast_assign(
> + __entry->desc = desc;
> + __entry->dev = (struct device *) dev;
> + /*
> + * Each trace entry is printed in a new line.
> + * If the msg finishes with '\n', cut it off
> + * to avoid blank lines in the trace.
> + */
> + if (len > 0 && (text[len - 1] == '\n'))
> + len -= 1;
> +
> + memcpy(__get_str(msg), text, len);
> + __get_str(msg)[len] = 0;
> + ),
> +
> + TP_printk("%s.%s %s", __entry->desc->modname,
> + __entry->desc->function, __get_str(msg))
> +);
> +
> +#endif /* _TRACE_DYNDBG_H */
> +
> +/* This part must be outside protection */
> +#include <trace/define_trace.h>
> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> index 016f33c20251..1ed3c4f16f69 100644
> --- a/lib/dynamic_debug.c
> +++ b/lib/dynamic_debug.c
> @@ -36,7 +36,9 @@
> #include <linux/sched.h>
> #include <linux/device.h>
> #include <linux/netdevice.h>
> -#include <trace/events/printk.h>
> +
> +#define CREATE_TRACE_POINTS
> +#include <trace/events/dyndbg.h>
>
> #include <rdma/ib_verbs.h>
>
> @@ -878,7 +880,9 @@ struct ddebug_trace_bufs {
> static DEFINE_PER_CPU(struct ddebug_trace_bufs, ddebug_trace_bufs);
> static DEFINE_PER_CPU(int, ddebug_trace_reserve);
>
> -static void ddebug_trace(const char *fmt, va_list args)
> +__printf(3, 0)
> +static void ddebug_trace(struct _ddebug *desc, const struct device *dev,
> + const char *fmt, va_list args)
> {
> struct ddebug_trace_buf *buf;
> int bufidx;
> @@ -897,7 +901,11 @@ static void ddebug_trace(const char *fmt, va_list args)
> buf = this_cpu_ptr(ddebug_trace_bufs.bufs) + bufidx;
>
> len = vscnprintf(buf->buf, sizeof(buf->buf), fmt, args);
> - trace_console(buf->buf, len);
> +
> + if (!dev)
> + trace_prdbg(desc, buf->buf, len);
> + else
> + trace_devdbg(desc, dev, buf->buf, len);
>
> out:
> /* As above. */
> @@ -907,9 +915,9 @@ static void ddebug_trace(const char *fmt, va_list args)
> }
>
> __printf(2, 3)
> -static void ddebug_printk(unsigned int flags, const char *fmt, ...)
> +static void ddebug_printk(struct _ddebug *desc, const char *fmt, ...)
> {
> - if (flags & _DPRINTK_FLAGS_TRACE) {
> + if (desc->flags & _DPRINTK_FLAGS_TRACE) {
> va_list args;
>
> va_start(args, fmt);
> @@ -917,11 +925,11 @@ static void ddebug_printk(unsigned int flags, const char *fmt, ...)
> * All callers include the KERN_DEBUG prefix to keep the
> * vprintk case simple; strip it out for tracing.
> */
> - ddebug_trace(fmt + strlen(KERN_DEBUG), args);
> + ddebug_trace(desc, NULL, fmt + strlen(KERN_DEBUG), args);
> va_end(args);
> }
>
> - if (flags & _DPRINTK_FLAGS_PRINTK) {
> + if (desc->flags & _DPRINTK_FLAGS_PRINTK) {
> va_list args;
>
> va_start(args, fmt);
> @@ -931,19 +939,19 @@ static void ddebug_printk(unsigned int flags, const char *fmt, ...)
> }
>
> __printf(3, 4)
> -static void ddebug_dev_printk(unsigned int flags, const struct device *dev,
> +static void ddebug_dev_printk(struct _ddebug *desc, const struct device *dev,
> const char *fmt, ...)
> {
>
> - if (flags & _DPRINTK_FLAGS_TRACE) {
> + if (desc->flags & _DPRINTK_FLAGS_TRACE) {
> va_list args;
>
> va_start(args, fmt);
> - ddebug_trace(fmt, args);
> + ddebug_trace(desc, dev, fmt, args);
> va_end(args);
> }
>
> - if (flags & _DPRINTK_FLAGS_PRINTK) {
> + if (desc->flags & _DPRINTK_FLAGS_PRINTK) {
> va_list args;
>
> va_start(args, fmt);
> @@ -966,7 +974,7 @@ void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
> vaf.fmt = fmt;
> vaf.va = &args;
>
> - ddebug_printk(descriptor->flags, KERN_DEBUG "%s%pV",
> + ddebug_printk(descriptor, KERN_DEBUG "%s%pV",
> dynamic_emit_prefix(descriptor, buf), &vaf);
>
> va_end(args);
> @@ -977,7 +985,6 @@ 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);
> @@ -987,15 +994,14 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
>
> vaf.fmt = fmt;
> vaf.va = &args;
> - flags = descriptor->flags;
>
> if (!dev) {
> - ddebug_printk(flags, KERN_DEBUG "(NULL device *): %pV",
> - &vaf);
> + ddebug_printk(descriptor, KERN_DEBUG "(NULL device *): %pV",
> + &vaf);
> } else {
> char buf[PREFIX_SIZE] = "";
>
> - ddebug_dev_printk(flags, dev, "%s%s %s: %pV",
> + ddebug_dev_printk(descriptor, dev, "%s%s %s: %pV",
> dynamic_emit_prefix(descriptor, buf),
> dev_driver_string(dev), dev_name(dev),
> &vaf);
> @@ -1011,7 +1017,6 @@ 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);
> @@ -1021,24 +1026,22 @@ 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] = "";
>
> - ddebug_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);
> + ddebug_dev_printk(descriptor, 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) {
> - ddebug_printk(flags, KERN_DEBUG "%s%s: %pV",
> - netdev_name(dev), netdev_reg_state(dev), &vaf);
> + ddebug_dev_printk(descriptor, &dev->dev, KERN_DEBUG "%s%s: %pV",
> + netdev_name(dev), netdev_reg_state(dev), &vaf);
> } else {
> - ddebug_printk(flags, KERN_DEBUG "(NULL net_device): %pV",
> - &vaf);
> + ddebug_printk(descriptor, KERN_DEBUG "(NULL net_device): %pV", &vaf);
> }
>
> va_end(args);
> @@ -1054,18 +1057,16 @@ 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 = &args;
> - flags = descriptor->flags;
>
> if (ibdev && ibdev->dev.parent) {
> char buf[PREFIX_SIZE] = "";
>
> - ddebug_dev_printk(flags, ibdev->dev.parent,
> + ddebug_dev_printk(descriptor, ibdev->dev.parent,
> "%s%s %s %s: %pV",
> dynamic_emit_prefix(descriptor, buf),
> dev_driver_string(ibdev->dev.parent),
> @@ -1073,10 +1074,10 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
> dev_name(&ibdev->dev),
> &vaf);
> } else if (ibdev) {
> - ddebug_printk(flags, KERN_DEBUG "%s: %pV",
> - dev_name(&ibdev->dev), &vaf);
> + ddebug_dev_printk(descriptor, &ibdev->dev, KERN_DEBUG "%s: %pV",
> + dev_name(&ibdev->dev), &vaf);
> } else {
> - ddebug_printk(flags, KERN_DEBUG "(NULL ip_device): %pV", &vaf);
> + ddebug_printk(descriptor, KERN_DEBUG "(NULL ip_device): %pV", &vaf);
> }
>
> va_end(args);
> --
> 2.42.0.869.gea05f2083d-goog
>
© 2016 - 2025 Red Hat, Inc.