hi Jason, Steve, Greg, DRM-folks,
This patchset plumbs debug streams, from dynamic-debug, and from
drm.debug, into tracefs. Enabling traffic is done on both source &
destination:
# enable at source
echo module usbcore +T > /proc/dynamic_debug/control
# enable events into tracefs
echo 1 > /sys/kernel/tracing/events/dyndbg/enable
# enable at source
echo 0x03 > /sys/module/drm/parameters/debug
# enable events into tracefs
echo 1 > /sys/kernel/tracing/events/drm/enable
This allows selectivity at the sources, and in principle, filtering at
tracefs (which is unaddressed, except for arg-passthru).
Here is v11, it differs subsantially from v10:
A: All tracefs action is via 4 new trace-events:
from dyndbg:
pr_debug() sends trace_prdbg()
dev_dbg() sends trace_devdbg()
both preserve args unchanged
similarly from drm:
drm_dev_dbg() -> trace_drm_devdbg()
drm_dbg() -> trace_drm_dbg()
again, args are captured unchanged.
for some reason 3 other drm_vblank* events showed up, I dont know why.
These 4 events (not counting vblank) all capture the args unchanged;
ISTM full exposure of available info is best for filtering/triggering
purposes.
B: dynamic-debug gets proper .class_id, and query support (dyndbg:)
so that this is legal input:
echo module drm class 3 +T > /proc/dynamic_debug/control
v10 used "format drm:core:", which worked, but required addition of
category string prefixes, and possible user-facing-changes issues.
New field is uint:4, big enough to fit DRMs enum drm_debug_category
(once it has been condensed). The name is .class_id, distinct from but
related to DRMs "category".
This also includes _CLS name & arg extensions of the Factory macros
that implement dyndbgs jump-label/NOOP optimizations.
C: integration of dyndbg into drm.debug (drm_print:)
The purpose here (and originally) is to avoid drm_debug_enabled()
runtime costs, and to put a more flexible substrate underneath the
sysfs bitmap api. Ive made it CONFIG dependent, since each _ddebug is
56 bytes, and i915 & amdgpu have ~1700 & ~3800 callsites respectively,
of which 127 & ~2k are plain pr_debugs.
1. We shrink enum drm_debug_category to fit in 4 bits, at nominal
cost of BIT(category) at runtime, which dyndbg will avoid anyway.
2. Add the trace_drm_*dbg() events
3. insert macro indirection, and use it to wrap drm_*dbg()s in
dyndbg's _no_desc_ Factory macro.
4. add __drm_debug_enabled (optimized to true) to use behind jumplabel.
5. use _CLS extension of _no_desc_ Factory macro
this makes cls available to initialize _ddebug.class_id
6. alter drm_*dbg, replacing category with struct _ddebug *desc.
desc.class_id is category
desc.flags allows selection of PRINTK or TRACE or both
7. propagate struct _ddebug *desc thru trace_drm_*dbg()
make all of _ddebug available for filtering
8. add sysfs bitmap to dyndbg, use it to implement drm.debug
D: The "flight-recorder" special instance was unneeded, and is gone:
this handles it generically:
mkdir instances/flightrec
echo 1 > instances/flightrec/events/drm/enable
echo module autopilot +T >/proc/dynamic_debug/control
v10 is here:
https://lore.kernel.org/lkml/[email protected]/
patches 1-3 are from:
https://lore.kernel.org/lkml/[email protected]/
this patchset addresses goals of:
https://patchwork.freedesktop.org/series/78133/
https://lore.kernel.org/lkml/3706af20bc64a320ff8f3ff8950738b988f4bdf5.1636452784.git.quic_saipraka@quicinc.com/
Jim Cromie (19):
1st 3 are basically direct from <[email protected]>
execpt I dropped his printk:dyndbg event:
dyndbg: add _DPRINTK_FLAGS_ENABLED
dyndbg: add _DPRINTK_FLAGS_TRACE
dyndbg: add write-to-tracefs code
add 2 events, and record args (could be squashed)
dyndbg: add trace-events for pr_debug, dev_dbg
dyndbg: add desc, dev fields to event record
add field, selection mechanisms, and CLS extensions to Factory macros
dyndbg: add class_id to callsites
make category fit in .class_id:
drm_print: condense enum drm_debug_category
repeat trace event addition:
drm_print: add trace_drm_dbg, trace_drm_devdbg events
kconfig+Make-flag:
drm_print: add CONFIG_DRM_USE_DYNDBG
macro indirection:
drm_print: interpose drm_dev_dbg, __drm_dbg with forwarding macros
add >control entries for ~4660 drm.debug callsites:
drm_print: wrap drm_dev_dbg in _dynamic_func_call_no_desc
drm_print: wrap drm_dbg in _dynamic_func_call_no_desc
prep:
drm_print: refine drm_debug_enabled for dyndbg+jump-label
drive-by:
drm_print: prefer bare printk KERN_DEBUG on generic fn
get .class_id initialized at compile.
drm_print: use _dynamic_func_call_no_desc_cls
need this to selectively trace/print:
drm_print: add struct _ddebug desc to drm_dbg, drm_dev_dbg
propagate arg upgrade of HEAD~1 into trace-events:
drm_print: add struct _ddebug *desc to trace-drm-*() params
add and use sysfs bitmap support:
dyndbg: add DEFINE_DYNAMIC_DEBUG_CLASSBITS macro and callbacks
drm_print: use DEFINE_DYNAMIC_DEBUG_CLASSBITS for drm.debug
.../admin-guide/dynamic-debug-howto.rst | 12 +
drivers/gpu/drm/Kconfig | 12 +
drivers/gpu/drm/drm_print.c | 66 +++--
include/drm/drm_print.h | 80 +++--
include/linux/dynamic_debug.h | 101 ++++++-
include/trace/events/drm.h | 68 +++++
include/trace/events/dyndbg.h | 74 +++++
lib/dynamic_debug.c | 273 +++++++++++++++---
8 files changed, 601 insertions(+), 85 deletions(-)
create mode 100644 include/trace/events/drm.h
create mode 100644 include/trace/events/dyndbg.h
--
2.33.1
Distinguish the condition: _DPRINTK_FLAGS_ENABLED from the bit:
_DPRINTK_FLAGS_PRINT, in preparation to add _DPRINTK_FLAGS_TRACE next.
Also add a 'K' to get _DPRINTK_FLAGS_PRINTK, to insure is not used
elsewhere with a stale meaning.
CC: [email protected]
Signed-off-by: Jim Cromie <[email protected]>
---
include/linux/dynamic_debug.h | 10 ++++++----
lib/dynamic_debug.c | 8 ++++----
2 files changed, 10 insertions(+), 8 deletions(-)
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index dce631e678dd..257a7bcbbe36 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,10 @@ struct _ddebug {
(_DPRINTK_FLAGS_INCL_MODNAME | _DPRINTK_FLAGS_INCL_FUNCNAME |\
_DPRINTK_FLAGS_INCL_LINENO | _DPRINTK_FLAGS_INCL_TID)
+#define _DPRINTK_FLAGS_ENABLED _DPRINTK_FLAGS_PRINTK
+
#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 +122,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_ENABLED)
#else
#define DYNAMIC_DEBUG_BRANCH(descriptor) \
- unlikely(descriptor.flags & _DPRINTK_FLAGS_PRINT)
+ unlikely(descriptor.flags & _DPRINTK_FLAGS_ENABLED)
#endif
#endif /* CONFIG_JUMP_LABEL */
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index dd7f56af9aed..78a2912976c1 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -86,7 +86,7 @@ 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' },
@@ -210,10 +210,10 @@ 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_ENABLED) {
+ if (!(modifiers->flags & _DPRINTK_FLAGS_ENABLED))
static_branch_disable(&dp->key.dd_key_true);
- } else if (modifiers->flags & _DPRINTK_FLAGS_PRINT)
+ } else if (modifiers->flags & _DPRINTK_FLAGS_ENABLED)
static_branch_enable(&dp->key.dd_key_true);
#endif
dp->flags = newflags;
--
2.33.1
add new flag, and OR it into _DPRINTK_FLAGS_ENABLED definition
CC: [email protected]
Signed-off-by: Jim Cromie <[email protected]>
---
include/linux/dynamic_debug.h | 4 +++-
1 file changed, 3 insertions(+), 1 deletion(-)
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index 257a7bcbbe36..e0c2d7c0938b 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -37,7 +37,9 @@ struct _ddebug {
(_DPRINTK_FLAGS_INCL_MODNAME | _DPRINTK_FLAGS_INCL_FUNCNAME |\
_DPRINTK_FLAGS_INCL_LINENO | _DPRINTK_FLAGS_INCL_TID)
-#define _DPRINTK_FLAGS_ENABLED _DPRINTK_FLAGS_PRINTK
+#define _DPRINTK_FLAGS_TRACE (1<<5)
+#define _DPRINTK_FLAGS_ENABLED (_DPRINTK_FLAGS_PRINTK | \
+ _DPRINTK_FLAGS_TRACE)
#if defined DEBUG
#define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINTK
--
2.33.1
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/[email protected]/
.. 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.
CC: [email protected]
Signed-off-by: Jim Cromie <[email protected]>
---
.../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
index a89cfa083155..3c8f104a143f 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.
+ T enables callsite to issue a dyndbg:* trace-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/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 78a2912976c1..3fd035cd4653 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>
@@ -87,6 +88,7 @@ static inline const char *trim_prefix(const char *path)
static struct { unsigned flag:8; char opt_char; } opt_array[] = {
{ _DPRINTK_FLAGS_PRINTK, 'p' },
+ { _DPRINTK_FLAGS_TRACE, 'T' },
{ _DPRINTK_FLAGS_INCL_MODNAME, 'm' },
{ _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' },
{ _DPRINTK_FLAGS_INCL_LINENO, 'l' },
@@ -628,6 +630,96 @@ static inline char *dynamic_emit_prefix(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_console(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);
+ }
+}
+
void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
{
va_list args;
@@ -642,7 +734,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 +745,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 +755,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 +779,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 +789,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);
@@ -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 = &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%s: %pV",
+ dev_name(&ibdev->dev), &vaf);
} else {
- printk(KERN_DEBUG "(NULL ib_device): %pV", &vaf);
+ dynamic_printk(flags, KERN_DEBUG "(NULL ip_device): %pV",
+ &vaf);
}
- va_end(args);
+va_end(args);
}
EXPORT_SYMBOL(__dynamic_ibdev_dbg);
--
2.33.1
commit:HEAD~1 added pr_debug(), dev_dbg() params to the new events,
but didn't actually capture the params. Do that now; add the other
TP_* parts: __fields, fast-assign, and printk elements for the
desccriptor and device params.
The message capture part is copied from printk:console, it gets the
whole message, including dyndbg's prefixing: the dev_name() etc, the
optional module:function:line decorations, and the trailing newline
(which is trimmed).
dyndbg->trace-events must be enabled on both sides:
in tracefs: echo 1 > /sys/kernel/tracing/events/dyndbg/enable
in dyndbg: echo module drm +T > /proc/dynamic_debug/control
This is good; it gives 2 orthogonal cuts at trace traffic, dyndbg can
enable callsites indvidually, tracefs can (in principle) filter and
trigger on the incoming event stream.
ATM, TP_print adds "__entry->desc->{modname,function}", which is
redundant with +Tmf enabled callsites.
RFC
Perhaps the whole decorations/prefix should be excluded from the event
capture ? Vincent's skip-past-KERN_DEBUG trick could be extended to
skip part or all of the prefix, and leave the "decorating" of events
solely to TP_printk. Whats the right separation of concerns ?
NB: __entry->desc is a pointer into kernel .data, a pretty stable
reference, at least while the kernel is running.
Signed-off-by: Jim Cromie <[email protected]>
---
include/trace/events/dyndbg.h | 13 ++++++++++---
1 file changed, 10 insertions(+), 3 deletions(-)
diff --git a/include/trace/events/dyndbg.h b/include/trace/events/dyndbg.h
index 82620b10e968..2ac296cb451c 100644
--- a/include/trace/events/dyndbg.h
+++ b/include/trace/events/dyndbg.h
@@ -14,10 +14,12 @@ TRACE_EVENT(prdbg,
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
@@ -30,8 +32,8 @@ TRACE_EVENT(prdbg,
__get_str(msg)[len] = 0;
),
- TP_printk("%s", __get_str(msg))
-
+ TP_printk("%s.%s %s", __entry->desc->modname,
+ __entry->desc->function, __get_str(msg))
);
/* capture dev_dbg() callsite descriptor, device, and message */
@@ -42,10 +44,14 @@ TRACE_EVENT(devdbg,
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
@@ -58,7 +64,8 @@ TRACE_EVENT(devdbg,
__get_str(msg)[len] = 0;
),
- TP_printk("%s", __get_str(msg))
+ TP_printk("%s.%s %s", __entry->desc->modname,
+ __entry->desc->function, __get_str(msg))
);
#endif /* _TRACE_DYNDBG_H */
--
2.33.1
In commit HEAD~1, pr_debug temporarily issued a printk:console event.
Replace that use with 2 new events:
bash-5.1# ls events/dyndbg/
devdbg enable filter prdbg
..called from pr_debug(), dev_dbg() respectively for dyndbg builds.
This links the old pr_debug API to tracefs, via dyndbg, allowing
pr_debug()s etc to add just a little more user-context to the
trace-logs, and then at users option, less syslog.
The 2 trace_* calls accept their caller's args respectively, keeping
the available info w/o alteration; ISTM this is the best basis to add
filtering later.
1- struct _ddebug *descriptor, giving tracefs all of dyndbg's info.
2- struct device *dev, for trace_devdbg(), if !!dev
To pass the descriptor into the trace_*() calls, the callchain up to
__dynamic_{pr_debug,{dev,netdev,ibdev}_dbg} are altered to provide it.
The 2nd event also gets the struct device *dev if !!dev, otherwise a
trace_prdbg() is issued, since we have an event for that, and don't
need to waste the trace-buffer space.
Signed-off-by: Jim Cromie <[email protected]>
---
include/trace/events/dyndbg.h | 67 +++++++++++++++++++++++++++++++++++
lib/dynamic_debug.c | 53 ++++++++++++++-------------
2 files changed, 96 insertions(+), 24 deletions(-)
create mode 100644 include/trace/events/dyndbg.h
diff --git a/include/trace/events/dyndbg.h b/include/trace/events/dyndbg.h
new file mode 100644
index 000000000000..82620b10e968
--- /dev/null
+++ b/include/trace/events/dyndbg.h
@@ -0,0 +1,67 @@
+/* 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(
+ __dynamic_array(char, msg, len + 1)
+ ),
+
+ TP_fast_assign(
+ /*
+ * 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", __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(
+ __dynamic_array(char, msg, len + 1)
+ ),
+
+ TP_fast_assign(
+ /*
+ * 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", __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 3fd035cd4653..2efdc4f1553f 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>
@@ -648,7 +650,8 @@ struct dynamic_trace_bufs {
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)
+static void dynamic_trace(struct _ddebug *desc, const struct device *dev,
+ const char *fmt, va_list args)
{
struct dynamic_trace_buf *buf;
int bufidx;
@@ -667,7 +670,11 @@ static void dynamic_trace(const char *fmt, va_list args)
buf = this_cpu_ptr(dynamic_trace_bufs.bufs) + bufidx;
len = vscnprintf(buf->buf, sizeof(buf->buf), fmt, args);
- trace_console(buf->buf, len);
+
+ if (dev == NULL)
+ trace_prdbg(desc, buf->buf, len);
+ else
+ trace_devdbg(desc, dev, buf->buf, len);
out:
/* As above. */
@@ -676,9 +683,9 @@ static void dynamic_trace(const char *fmt, va_list args)
preempt_enable_notrace();
}
-static void dynamic_printk(unsigned int flags, const char *fmt, ...)
+static void dynamic_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);
@@ -686,11 +693,11 @@ static void dynamic_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.
*/
- dynamic_trace(fmt + strlen(KERN_DEBUG), args);
+ dynamic_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);
@@ -699,19 +706,19 @@ static void dynamic_printk(unsigned int flags, const char *fmt, ...)
}
}
-static void dynamic_dev_printk(unsigned int flags, const struct device *dev,
+static void dynamic_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);
- dynamic_trace(fmt, args);
+ dynamic_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);
@@ -734,7 +741,7 @@ void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
vaf.fmt = fmt;
vaf.va = &args;
- dynamic_printk(descriptor->flags, KERN_DEBUG "%s%pV",
+ dynamic_printk(descriptor, KERN_DEBUG "%s%pV",
dynamic_emit_prefix(descriptor, buf), &vaf);
va_end(args);
@@ -745,7 +752,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);
@@ -755,15 +761,14 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
vaf.fmt = fmt;
vaf.va = &args;
- flags = descriptor->flags;
if (!dev) {
- dynamic_printk(flags, KERN_DEBUG "(NULL device *): %pV",
+ dynamic_printk(descriptor, KERN_DEBUG "(NULL device *): %pV",
&vaf);
} else {
char buf[PREFIX_SIZE] = "";
- dynamic_dev_printk(flags, dev, "%s%s %s: %pV",
+ dynamic_dev_printk(descriptor, dev, "%s%s %s: %pV",
dynamic_emit_prefix(descriptor, buf),
dev_driver_string(dev), dev_name(dev),
&vaf);
@@ -794,7 +799,7 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor,
if (dev && dev->dev.parent) {
char buf[PREFIX_SIZE] = "";
- dynamic_dev_printk(flags, dev->dev.parent,
+ dynamic_dev_printk(descriptor, dev->dev.parent,
"%s%s %s %s%s: %pV",
dynamic_emit_prefix(descriptor, buf),
dev_driver_string(dev->dev.parent),
@@ -802,10 +807,10 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor,
netdev_name(dev), netdev_reg_state(dev),
&vaf);
} else if (dev) {
- dynamic_printk(flags, KERN_DEBUG "%s%s: %pV",
- netdev_name(dev), netdev_reg_state(dev), &vaf);
+ dynamic_dev_printk(descriptor, &dev->dev, KERN_DEBUG "%s%s: %pV",
+ netdev_name(dev), netdev_reg_state(dev), &vaf);
} else {
- dynamic_printk(flags, KERN_DEBUG "(NULL net_device): %pV",
+ dynamic_printk(descriptor, KERN_DEBUG "(NULL net_device): %pV",
&vaf);
}
@@ -833,7 +838,7 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
if (ibdev && ibdev->dev.parent) {
char buf[PREFIX_SIZE] = "";
- dynamic_dev_printk(flags, ibdev->dev.parent,
+ dynamic_dev_printk(descriptor, ibdev->dev.parent,
"%s%s %s %s: %pV",
dynamic_emit_prefix(descriptor, buf),
dev_driver_string(ibdev->dev.parent),
@@ -841,10 +846,10 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
dev_name(&ibdev->dev),
&vaf);
} else if (ibdev) {
- dynamic_printk(flags, KERN_DEBUG "%s%s: %pV",
- dev_name(&ibdev->dev), &vaf);
+ dynamic_dev_printk(descriptor, &ibdev->dev, KERN_DEBUG "%s%s: %pV",
+ dev_name(&ibdev->dev), &vaf);
} else {
- dynamic_printk(flags, KERN_DEBUG "(NULL ip_device): %pV",
+ dynamic_printk(descriptor, KERN_DEBUG "(NULL ip_device): %pV",
&vaf);
}
--
2.33.1
DRM defines/uses a 10 enum drm_debug_category to create exclusive
classes of debug messages. To support this directly in dynamic-debug,
add the following:
- struct _ddebug.class_id 4 bits is enough for drm_debug_category
and the query support:
- struct _ddebug_query.class_id
- ddebug_change - looks for "class" keyword
- parse_class - accepts uint: 1-15, sets query->class_id
- vpr_info_dq - displays new field
- ddebug_proc_show - append column with "cls:%d"
With this patch, the following cmd is accepted w/o error:
#> echo module drm class 2 +p > /proc/dynamic_debug/control
It currently does nothing, since no pr_debug callsites can yet be
initialized with class_id != 0.
Note that this is specifically an error:
#> echo module drm class 0 +p > /proc/dynamic_debug/control
parse_class() prohibits this, we reserve "class 0" as a non-category.
This means that all good inputs are true, and 0 is special.
NOTES:
Patch extends DEFINE_DYNAMIC_DEBUG_METADATA() with a _CLS suffix, and
a new cls param, and re-adds old name using extended name. Then,
repeats those mods up through the Factory macros that use the
METADATA* .data constructors, so as to actually supply the category
into the initializer.
CC: Rasmus Villemoes <[email protected]>
Signed-off-by: Jim Cromie <[email protected]>
---
.../admin-guide/dynamic-debug-howto.rst | 11 +++++
include/linux/dynamic_debug.h | 41 +++++++++++++------
lib/dynamic_debug.c | 30 ++++++++++++--
3 files changed, 67 insertions(+), 15 deletions(-)
diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst
index 3c8f104a143f..7e1322660b10 100644
--- a/Documentation/admin-guide/dynamic-debug-howto.rst
+++ b/Documentation/admin-guide/dynamic-debug-howto.rst
@@ -35,6 +35,7 @@ Dynamic debug has even more useful features:
- line number (including ranges of line numbers)
- module name
- format string
+ - class number:1-15
* Provides a debugfs control file: ``<debugfs>/dynamic_debug/control``
which can be read to display the complete list of known debug
@@ -143,6 +144,7 @@ against. Possible keywords are:::
'module' string |
'format' string |
'line' line-range
+ 'class' integer:[1-15]
line-range ::= lineno |
'-'lineno |
@@ -217,6 +219,15 @@ line
line -1605 // the 1605 lines from line 1 to line 1605
line 1600- // all lines from line 1600 to the end of the file
+class
+ This expects a single integer, in range: 1-15.
+ Using this specification constrains to exact class_id matches.
+ This is intended for DRM.debug enumerated categories, plus 1.
+ class_id = 0 is reserved, returns an error currently.
+
+ This differs from the others primarily in that it is not displayed
+ in the control file currently, add later as an extra column.
+
The flags specification comprises a change operation followed
by one or more flag characters. The change operation is one
of the characters::
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index e0c2d7c0938b..e9483cd9ac1c 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -20,6 +20,7 @@ struct _ddebug {
const char *function;
const char *filename;
const char *format;
+ unsigned int class_id:4;
unsigned int lineno:18;
/*
* The flags field controls the behaviour at the callsite.
@@ -91,7 +92,7 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
const struct ib_device *ibdev,
const char *fmt, ...);
-#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \
+#define DEFINE_DYNAMIC_DEBUG_METADATA_CLS(name, cls, fmt) \
static struct _ddebug __aligned(8) \
__section("__dyndbg") name = { \
.modname = KBUILD_MODNAME, \
@@ -100,9 +101,13 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
.format = (fmt), \
.lineno = __LINE__, \
.flags = _DPRINTK_FLAGS_DEFAULT, \
+ .class_id = cls, \
_DPRINTK_KEY_INIT \
}
+#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \
+ DEFINE_DYNAMIC_DEBUG_METADATA_CLS(name, 0, fmt)
+
#ifdef CONFIG_JUMP_LABEL
#ifdef DEBUG
@@ -132,17 +137,21 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
#endif /* CONFIG_JUMP_LABEL */
-#define __dynamic_func_call(id, fmt, func, ...) do { \
- DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt); \
- if (DYNAMIC_DEBUG_BRANCH(id)) \
- func(&id, ##__VA_ARGS__); \
+#define __dynamic_func_call_cls(id, cls, fmt, func, ...) do { \
+ DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \
+ if (DYNAMIC_DEBUG_BRANCH(id)) \
+ func(&id, ##__VA_ARGS__); \
} while (0)
+#define __dynamic_func_call(id, fmt, func, ...) \
+ __dynamic_func_call_cls(id, 0, fmt, func, ##__VA_ARGS__)
-#define __dynamic_func_call_no_desc(id, fmt, func, ...) do { \
- DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt); \
- if (DYNAMIC_DEBUG_BRANCH(id)) \
- func(__VA_ARGS__); \
+#define __dynamic_func_call_no_desc_cls(id, cls, fmt, func, ...) do { \
+ DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \
+ if (DYNAMIC_DEBUG_BRANCH(id)) \
+ func(__VA_ARGS__); \
} while (0)
+#define __dynamic_func_call_no_desc(id, fmt, func, ...) \
+ __dynamic_func_call_no_desc_cls(id, 0, fmt, func, ##__VA_ARGS__)
/*
* "Factory macro" for generating a call to func, guarded by a
@@ -152,15 +161,23 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
* the varargs. Note that fmt is repeated in invocations of this
* macro.
*/
+#define _dynamic_func_call_cls(cls, fmt, func, ...) \
+ __dynamic_func_call_cls(__UNIQUE_ID(ddebug), cls, fmt, func, ##__VA_ARGS__)
#define _dynamic_func_call(fmt, func, ...) \
- __dynamic_func_call(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__)
+ __dynamic_func_call_cls(__UNIQUE_ID(ddebug), 0, fmt, func, ##__VA_ARGS__)
+
/*
* A variant that does the same, except that the descriptor is not
* passed as the first argument to the function; it is only called
* with precisely the macro's varargs.
*/
-#define _dynamic_func_call_no_desc(fmt, func, ...) \
- __dynamic_func_call_no_desc(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__)
+#define _dynamic_func_call_no_desc_cls(fmt, eCat, func, ...) \
+ __dynamic_func_call_no_desc_cls(__UNIQUE_ID(ddebug), eCat, \
+ fmt, func, ##__VA_ARGS__)
+
+#define _dynamic_func_call_no_desc(fmt, func, ...) \
+ __dynamic_func_call_no_desc_cls(__UNIQUE_ID(ddebug), 0, \
+ fmt, func, ##__VA_ARGS__)
#define dynamic_pr_debug(fmt, ...) \
_dynamic_func_call(fmt, __dynamic_pr_debug, \
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 2efdc4f1553f..419d4664e724 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -58,6 +58,7 @@ struct ddebug_query {
const char *function;
const char *format;
unsigned int first_lineno, last_lineno;
+ unsigned int class_id;
};
struct ddebug_iter {
@@ -138,13 +139,13 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
fmtlen--;
}
- v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u\n",
+ v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u class=%u\n",
msg,
query->function ?: "",
query->filename ?: "",
query->module ?: "",
fmtlen, query->format ?: "",
- query->first_lineno, query->last_lineno);
+ query->first_lineno, query->last_lineno, query->class_id);
}
/*
@@ -174,6 +175,10 @@ static int ddebug_change(const struct ddebug_query *query,
for (i = 0; i < dt->num_ddebugs; i++) {
struct _ddebug *dp = &dt->ddebugs[i];
+ /* match against the class_id, if > 0 */
+ if (query->class_id && query->class_id != dp->class_id)
+ continue;
+
/* match against the source filename */
if (query->filename &&
!match_wildcard(query->filename, dp->filename) &&
@@ -310,6 +315,22 @@ static inline int parse_lineno(const char *str, unsigned int *val)
}
return 0;
}
+/*
+ * class_id is 0-15. 0 is default, is nonsense in active search
+ */
+static inline int parse_class(struct ddebug_query *query, const char *str)
+{
+ int rc;
+ unsigned int val;
+
+ rc = kstrtouint(str, 10, &val);
+ if (rc < 0 || !val || val > 15) {
+ pr_err("expecting class:[1-15], not %s\n", str);
+ return -EINVAL;
+ }
+ query->class_id = val;
+ return 0;
+}
static int parse_linerange(struct ddebug_query *query, const char *first)
{
@@ -424,6 +445,9 @@ static int ddebug_parse_query(char *words[], int nwords,
} else if (!strcmp(keyword, "line")) {
if (parse_linerange(query, arg))
return -EINVAL;
+ } else if (!strcmp(keyword, "class")) {
+ if (parse_class(query, arg))
+ return -EINVAL;
} else {
pr_err("unknown keyword \"%s\"\n", keyword);
return -EINVAL;
@@ -1007,7 +1031,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
iter->table->mod_name, dp->function,
ddebug_describe_flags(dp->flags, &flags));
seq_escape(m, dp->format, "\t\r\n\"");
- seq_puts(m, "\"\n");
+ seq_printf(m, "\" cls:%u\n", dp->class_id);
return 0;
}
--
2.33.1
enum drm_debug_category has 10 hardcoded values, which could be
"simplified" as sequential BIT(x)s. But lets take it one step
further, removing the explicit initializations (other than starting at
1), and move the BIT() operation into drm_debug_enabled().
This gives us a more compact representation (4 bits), without loss of
info; all DRM.debug api calls pass an enum parameter (and not a bit-OR
of them), and the bitmask-iness of the enum's values is merely a
micro-optimization to avoid doing BIT(category) at runtime. I doubt
the extra bit-shift would be measurable here.
And the 4-bit representation means it fits into struct
_ddebug.class_id (commit:HEAD~1), setting up for further integration.
The enum starts at 1, which respects the "reservation" of 0 as a
special case; it is a non-category, and shouldn't get treated like one.
Signed-off-by: Jim Cromie <[email protected]>
---
include/drm/drm_print.h | 22 +++++++++++-----------
1 file changed, 11 insertions(+), 11 deletions(-)
diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
index 22fabdeed297..b4355bfd7888 100644
--- a/include/drm/drm_print.h
+++ b/include/drm/drm_print.h
@@ -279,49 +279,49 @@ enum drm_debug_category {
* @DRM_UT_CORE: Used in the generic drm code: drm_ioctl.c, drm_mm.c,
* drm_memory.c, ...
*/
- DRM_UT_CORE = 0x01,
+ DRM_UT_CORE = 1,
/**
* @DRM_UT_DRIVER: Used in the vendor specific part of the driver: i915,
* radeon, ... macro.
*/
- DRM_UT_DRIVER = 0x02,
+ DRM_UT_DRIVER,
/**
* @DRM_UT_KMS: Used in the modesetting code.
*/
- DRM_UT_KMS = 0x04,
+ DRM_UT_KMS,
/**
* @DRM_UT_PRIME: Used in the prime code.
*/
- DRM_UT_PRIME = 0x08,
+ DRM_UT_PRIME,
/**
* @DRM_UT_ATOMIC: Used in the atomic code.
*/
- DRM_UT_ATOMIC = 0x10,
+ DRM_UT_ATOMIC,
/**
* @DRM_UT_VBL: Used for verbose debug message in the vblank code.
*/
- DRM_UT_VBL = 0x20,
+ DRM_UT_VBL,
/**
* @DRM_UT_STATE: Used for verbose atomic state debugging.
*/
- DRM_UT_STATE = 0x40,
+ DRM_UT_STATE,
/**
* @DRM_UT_LEASE: Used in the lease code.
*/
- DRM_UT_LEASE = 0x80,
+ DRM_UT_LEASE,
/**
* @DRM_UT_DP: Used in the DP code.
*/
- DRM_UT_DP = 0x100,
+ DRM_UT_DP,
/**
* @DRM_UT_DRMRES: Used in the drm managed resources code.
*/
- DRM_UT_DRMRES = 0x200,
+ DRM_UT_DRMRES
};
static inline bool drm_debug_enabled(enum drm_debug_category category)
{
- return unlikely(__drm_debug & category);
+ return unlikely(__drm_debug & BIT(category));
}
/*
--
2.33.1
__drm_debug() and __drm_dev_dbg() currently printk to syslog. These 2
underlay the vast bulk of DRM.debug api calls; they are a significant
source of debugging info, and could add useful context to debug traces.
Wire them to emit 2 new trace_*() events: drm_prdbg and drm_devdbg.
These events keep the args of those 2 callers:
- int/enum category, va_format *vaf
- struct device *dev, int/enum category, va_format *vaf
ISTM best to reflect args thru w/o altering; it is simple, least
surprising, and preserves info for possible filtering/selecting
events.
NOTES:
trace_*() additions are strictly redundant with printks to syslog, not
properly placed to reduce overall work.
Reuses trim-trailing-newline trick on vnsprintf
TLDR: The event called by __drm_dev_dbg() depends upon !!dev; theres
little value to storing a null in the trace. Yes, one could know that
devdbg was called with a null, but is that worthwhile ? And if you
really needed to know the call (not available from control-file
format) the file:line gets you there.
Signed-off-by: Jim Cromie <[email protected]>
---
drivers/gpu/drm/drm_print.c | 13 +++++--
include/trace/events/drm.h | 68 +++++++++++++++++++++++++++++++++++++
2 files changed, 78 insertions(+), 3 deletions(-)
create mode 100644 include/trace/events/drm.h
diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
index f783d4963d4b..cfcb89ffd89d 100644
--- a/drivers/gpu/drm/drm_print.c
+++ b/drivers/gpu/drm/drm_print.c
@@ -36,6 +36,9 @@
#include <drm/drm_drv.h>
#include <drm/drm_print.h>
+#define CREATE_TRACE_POINTS
+#include <trace/events/drm.h>
+
/*
* __drm_debug: Enable debug output.
* Bitmask of DRM_UT_x. See include/drm/drm_print.h for details.
@@ -269,13 +272,15 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
vaf.fmt = format;
vaf.va = &args;
- if (dev)
+ if (dev) {
dev_printk(KERN_DEBUG, dev, "[" DRM_NAME ":%ps] %pV",
__builtin_return_address(0), &vaf);
- else
+ trace_drm_devdbg(dev, category, &vaf);
+ } else {
printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV",
__builtin_return_address(0), &vaf);
-
+ trace_drm_debug(category, &vaf);
+ }
va_end(args);
}
EXPORT_SYMBOL(drm_dev_dbg);
@@ -295,6 +300,8 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...)
printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV",
__builtin_return_address(0), &vaf);
+ trace_drm_debug(category, &vaf);
+
va_end(args);
}
EXPORT_SYMBOL(__drm_dbg);
diff --git a/include/trace/events/drm.h b/include/trace/events/drm.h
new file mode 100644
index 000000000000..944aedaf6aa6
--- /dev/null
+++ b/include/trace/events/drm.h
@@ -0,0 +1,68 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM drm
+
+#if !defined(_TRACE_DRM_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_DRM_H
+
+#include <linux/tracepoint.h>
+
+/* drm_debug() was called, pass its args */
+TRACE_EVENT(drm_debug,
+ TP_PROTO(int drm_debug_category, struct va_format *vaf),
+
+ TP_ARGS(drm_debug_category, vaf),
+
+ TP_STRUCT__entry(
+ __field(int, drm_debug_category)
+ __dynamic_array(char, msg, 256)
+ ),
+
+ TP_fast_assign(
+ int len;
+
+ __entry->drm_debug_category = drm_debug_category;
+ vsnprintf(__get_str(msg), 256, vaf->fmt, *vaf->va);
+
+ len = strlen(__get_str(msg));
+ if ((len > 0) && (__get_str(msg)[len-1] == '\n'))
+ len -= 1;
+ __get_str(msg)[len] = 0;
+ ),
+
+ TP_printk("%s", __get_str(msg))
+);
+
+/* drm_devdbg() was called, pass its args, preserving order */
+TRACE_EVENT(drm_devdbg,
+ TP_PROTO(const struct device *dev, int drm_debug_category, struct va_format *vaf),
+
+ TP_ARGS(dev, drm_debug_category, vaf),
+
+ TP_STRUCT__entry(
+ __field(const struct device*, dev)
+ __field(int, drm_debug_category)
+ __dynamic_array(char, msg, 256)
+ ),
+
+ TP_fast_assign(
+ int len;
+
+ __entry->drm_debug_category = drm_debug_category;
+ __entry->dev = dev;
+ vsnprintf(__get_str(msg), 256, vaf->fmt, *vaf->va);
+
+ len = strlen(__get_str(msg));
+ if ((len > 0) && (__get_str(msg)[len-1] == '\n'))
+ len -= 1;
+ __get_str(msg)[len] = 0;
+ ),
+
+ TP_printk("cat:%d, %s %s", __entry->drm_debug_category,
+ dev_name(__entry->dev), __get_str(msg))
+);
+
+#endif /* _TRACE_DRM_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
--
2.33.1
DRM.debug API is used thousands of times in drivers/gpu/drm/*; when
these are implemented using dynamic-debug, DYNAMIC_DEBUG_METADATA adds
a struct _ddebug (56 bytes) per site.
Since i915 will have ~2k callsites, and amdgpu ~4k, the memory costs
are substantial, and thus made configurable.
For a baseline:
bash-5.1# drms_load
[ 10.923093] dyndbg: 1 debug prints in module drm
[ 10.928345] ACPI: bus type drm_connector registered
[ 11.034012] dyndbg: 2 debug prints in module ttm
[ 11.038188] dyndbg: 8 debug prints in module video
[ 11.551064] dyndbg: 127 debug prints in module i915
[ 11.617106] AMD-Vi: AMD IOMMUv2 functionality not available on this system - This is not a bug.
[ 12.084856] dyndbg: 2196 debug prints in module amdgpu
[ 12.099040] [drm] amdgpu kernel modesetting enabled.
[ 12.099790] amdgpu: CRAT table not found
[ 12.100523] amdgpu: Virtual CRAT table created for CPU
[ 12.100901] amdgpu: Topology: Add CPU node
[ 12.165382] dyndbg: 3 debug prints in module wmi
[ 12.356424] dyndbg: 3 debug prints in module nouveau
i915/gvt has pr_debugs that show up here
amdgpu has many pr_debugs from macro expansions
Signed-off-by: Jim Cromie <[email protected]>
fixup-mk
---
drivers/gpu/drm/Kconfig | 12 ++++++++++++
drivers/gpu/drm/Makefile | 2 ++
2 files changed, 14 insertions(+)
diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
index 0039df26854b..4e7b865c3441 100644
--- a/drivers/gpu/drm/Kconfig
+++ b/drivers/gpu/drm/Kconfig
@@ -62,6 +62,18 @@ config DRM_DEBUG_MM
If in doubt, say "N".
+config DRM_USE_DYNAMIC_DEBUG
+ bool "use dynamic debug to implement drm.debug"
+ default y
+ depends on DRM
+ depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
+ depends on JUMP_LABEL
+ help
+ Use dynamic-debug to avoid drm_debug_enabled() runtime overheads.
+ Due to callsite counts in DRM drivers (~4k in amdgpu) and 56
+ bytes per callsite, the .data costs can be substantial, and
+ are therefore configurable.
+
config DRM_DEBUG_SELFTEST
tristate "kselftests for DRM"
depends on DRM
diff --git a/drivers/gpu/drm/Makefile b/drivers/gpu/drm/Makefile
index 0dff40bb863c..60f4d7bc27eb 100644
--- a/drivers/gpu/drm/Makefile
+++ b/drivers/gpu/drm/Makefile
@@ -3,6 +3,8 @@
# Makefile for the drm device driver. This driver provides support for the
# Direct Rendering Infrastructure (DRI) in XFree86 4.1.0 and higher.
+CFLAGS-$(CONFIG_DRM_USE_DYNAMIC_DEBUG) += -DDYNAMIC_DEBUG_MODULE
+
drm-y := drm_aperture.o drm_auth.o drm_cache.o \
drm_file.o drm_gem.o drm_ioctl.o drm_irq.o \
drm_drv.o \
--
2.33.1
drm_dev_dbg() & _drm_dbg() sit below the categorized layer of the DRM
debug API, and thus implement most of it. These are good places to
insert dynamic-debug jump-label mechanics, allowing DRM to avoid the
runtime cost of drm_debug_enabled().
Set up for this by changing the func names by adding '__' prefixes,
and define forwarding macros to the new names.
no functional changes.
memory cost baseline: (unchanged)
bash-5.1# drms_load
[ 9.220389] dyndbg: 1 debug prints in module drm
[ 9.224426] ACPI: bus type drm_connector registered
[ 9.302192] dyndbg: 2 debug prints in module ttm
[ 9.305033] dyndbg: 8 debug prints in module video
[ 9.627563] dyndbg: 127 debug prints in module i915
[ 9.721505] AMD-Vi: AMD IOMMUv2 functionality not available on this system - This is not a bug.
[ 10.091345] dyndbg: 2196 debug prints in module amdgpu
[ 10.106589] [drm] amdgpu kernel modesetting enabled.
[ 10.107270] amdgpu: CRAT table not found
[ 10.107926] amdgpu: Virtual CRAT table created for CPU
[ 10.108398] amdgpu: Topology: Add CPU node
[ 10.168507] dyndbg: 3 debug prints in module wmi
[ 10.329587] dyndbg: 3 debug prints in module nouveau
Signed-off-by: Jim Cromie <[email protected]>
---
drivers/gpu/drm/drm_print.c | 10 +++++-----
include/drm/drm_print.h | 9 +++++++--
2 files changed, 12 insertions(+), 7 deletions(-)
diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
index cfcb89ffd89d..5dd6713c14f2 100644
--- a/drivers/gpu/drm/drm_print.c
+++ b/drivers/gpu/drm/drm_print.c
@@ -259,8 +259,8 @@ void drm_dev_printk(const struct device *dev, const char *level,
}
EXPORT_SYMBOL(drm_dev_printk);
-void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
- const char *format, ...)
+void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
+ const char *format, ...)
{
struct va_format vaf;
va_list args;
@@ -283,9 +283,9 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
}
va_end(args);
}
-EXPORT_SYMBOL(drm_dev_dbg);
+EXPORT_SYMBOL(__drm_dev_dbg);
-void __drm_dbg(enum drm_debug_category category, const char *format, ...)
+void ___drm_dbg(enum drm_debug_category category, const char *format, ...)
{
struct va_format vaf;
va_list args;
@@ -304,7 +304,7 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...)
va_end(args);
}
-EXPORT_SYMBOL(__drm_dbg);
+EXPORT_SYMBOL(___drm_dbg);
void __drm_err(const char *format, ...)
{
diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
index b4355bfd7888..f8fa5af11310 100644
--- a/include/drm/drm_print.h
+++ b/include/drm/drm_print.h
@@ -334,7 +334,7 @@ __printf(3, 4)
void drm_dev_printk(const struct device *dev, const char *level,
const char *format, ...);
__printf(3, 4)
-void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
+void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
const char *format, ...);
/**
@@ -383,6 +383,9 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
} \
})
+#define drm_dev_dbg(dev, eCat, fmt, ...) \
+ __drm_dev_dbg(dev, eCat, fmt, ##__VA_ARGS__)
+
/**
* DRM_DEV_DEBUG() - Debug output for generic drm code
*
@@ -484,10 +487,12 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
*/
__printf(2, 3)
-void __drm_dbg(enum drm_debug_category category, const char *format, ...);
+void ___drm_dbg(enum drm_debug_category category, const char *format, ...);
__printf(1, 2)
void __drm_err(const char *format, ...);
+#define __drm_dbg(fmt, ...) ___drm_dbg(fmt, ##__VA_ARGS__)
+
/* Macros to make printk easier */
#define _DRM_PRINTK(once, level, fmt, ...) \
--
2.33.1
Upgrade the current use of _dynamic_func_call_no_desc(), adding the
suffix and the category arg. The arg has been available via the
macros implementing the drm.debug api, but dyndbg lacked a simple way
to represent it and use it until recently.
Signed-off-by: Jim Cromie <[email protected]>
---
include/drm/drm_print.h | 11 ++++++-----
1 file changed, 6 insertions(+), 5 deletions(-)
diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
index 8d6b74270c50..0c704610c770 100644
--- a/include/drm/drm_print.h
+++ b/include/drm/drm_print.h
@@ -31,6 +31,7 @@
#include <linux/seq_file.h>
#include <linux/device.h>
#include <linux/debugfs.h>
+#include <linux/dynamic_debug.h>
#include <drm/drm.h>
@@ -414,8 +415,8 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
__drm_dev_dbg(dev, eCat, fmt, ##__VA_ARGS__)
#else
#define drm_dev_dbg(dev, eCat, fmt, ...) \
- _dynamic_func_call_no_desc(fmt, __drm_dev_dbg, \
- dev, eCat, fmt, ##__VA_ARGS__)
+ _dynamic_func_call_no_desc_cls(fmt, eCat, __drm_dev_dbg, \
+ dev, eCat, fmt, ##__VA_ARGS__)
#endif
/**
@@ -524,11 +525,11 @@ __printf(1, 2)
void __drm_err(const char *format, ...);
#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
-#define __drm_dbg(fmt, ...) ___drm_dbg(fmt, ##__VA_ARGS__)
+#define __drm_dbg(fmt, ...) ___drm_dbg(NULL, fmt, ##__VA_ARGS__)
#else
#define __drm_dbg(eCat, fmt, ...) \
- _dynamic_func_call_no_desc(fmt, ___drm_dbg, \
- eCat, fmt, ##__VA_ARGS__)
+ _dynamic_func_call_no_desc_cls(fmt, eCat, ___drm_dbg, \
+ eCat, fmt, ##__VA_ARGS__)
#endif
/* Macros to make printk easier */
--
2.33.1
Replace trace-drm-*()s category param with struct _ddebug *desc; it
has .classid field, which is the category.
This brings the events closer in line with those added for dyndbg; at
least the 1st param, and possibly the struct device (tb-checked).
There are still differences in the tail of the prototypes; vaf vs
text + len, which probably breaks CLASS sharing.
Signed-off-by: Jim Cromie <[email protected]>
---
drivers/gpu/drm/drm_print.c | 6 +++---
include/trace/events/drm.h | 36 ++++++++++++++++++------------------
2 files changed, 21 insertions(+), 21 deletions(-)
diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
index 8c33302212fc..0a15a4ec5ead 100644
--- a/drivers/gpu/drm/drm_print.c
+++ b/drivers/gpu/drm/drm_print.c
@@ -278,14 +278,14 @@ void __drm_dev_dbg(struct _ddebug *desc, const struct device *dev,
__builtin_return_address(0), &vaf);
if (desc->flags & _DPRINTK_FLAGS_TRACE)
- trace_drm_devdbg(dev, category, &vaf);
+ trace_drm_devdbg(dev, desc, &vaf);
} else {
if (desc->flags & _DPRINTK_FLAGS_PRINTK)
printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV",
__builtin_return_address(0), &vaf);
if (desc->flags & _DPRINTK_FLAGS_TRACE)
- trace_drm_debug(category, &vaf);
+ trace_drm_debug(desc, &vaf);
}
va_end(args);
}
@@ -306,7 +306,7 @@ void ___drm_dbg(struct _ddebug *desc, enum drm_debug_category category, const ch
printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV",
__builtin_return_address(0), &vaf);
- trace_drm_debug(category, &vaf);
+ trace_drm_debug(desc, &vaf);
va_end(args);
}
diff --git a/include/trace/events/drm.h b/include/trace/events/drm.h
index 944aedaf6aa6..bfe1fff923d8 100644
--- a/include/trace/events/drm.h
+++ b/include/trace/events/drm.h
@@ -9,25 +9,25 @@
/* drm_debug() was called, pass its args */
TRACE_EVENT(drm_debug,
- TP_PROTO(int drm_debug_category, struct va_format *vaf),
+ TP_PROTO(struct _ddebug *desc, struct va_format *vaf),
- TP_ARGS(drm_debug_category, vaf),
+ TP_ARGS(desc, vaf),
TP_STRUCT__entry(
- __field(int, drm_debug_category)
+ __field(struct _ddebug *, desc)
__dynamic_array(char, msg, 256)
),
TP_fast_assign(
int len;
+ char *p = __get_str(msg);
- __entry->drm_debug_category = drm_debug_category;
- vsnprintf(__get_str(msg), 256, vaf->fmt, *vaf->va);
+ __entry->desc = desc;
+ len = vsnprintf(p, 256, vaf->fmt, *vaf->va);
- len = strlen(__get_str(msg));
- if ((len > 0) && (__get_str(msg)[len-1] == '\n'))
+ if ((len > 0) && (len < 256) && p[len-1] == '\n')
len -= 1;
- __get_str(msg)[len] = 0;
+ p[len] = 0;
),
TP_printk("%s", __get_str(msg))
@@ -35,30 +35,30 @@ TRACE_EVENT(drm_debug,
/* drm_devdbg() was called, pass its args, preserving order */
TRACE_EVENT(drm_devdbg,
- TP_PROTO(const struct device *dev, int drm_debug_category, struct va_format *vaf),
+ TP_PROTO(const struct device *dev, struct _ddebug *desc, struct va_format *vaf),
- TP_ARGS(dev, drm_debug_category, vaf),
+ TP_ARGS(dev, desc, vaf),
TP_STRUCT__entry(
- __field(const struct device*, dev)
- __field(int, drm_debug_category)
+ __field(const struct device *, dev)
+ __field(struct _ddebug *, desc)
__dynamic_array(char, msg, 256)
),
TP_fast_assign(
int len;
+ char *p = __get_str(msg);
- __entry->drm_debug_category = drm_debug_category;
+ __entry->desc = desc;
__entry->dev = dev;
- vsnprintf(__get_str(msg), 256, vaf->fmt, *vaf->va);
+ len = vsnprintf(p, 256, vaf->fmt, *vaf->va);
- len = strlen(__get_str(msg));
- if ((len > 0) && (__get_str(msg)[len-1] == '\n'))
+ if ((len > 0) && (len < 256) && p[len-1] == '\n')
len -= 1;
- __get_str(msg)[len] = 0;
+ p[len] = 0;
),
- TP_printk("cat:%d, %s %s", __entry->drm_debug_category,
+ TP_printk("cat:%d, %s %s", __entry->desc->class_id,
dev_name(__entry->dev), __get_str(msg))
);
--
2.33.1
DEFINE_DYNAMIC_DEBUG_CLASSBITS(fsname, var, bitmap_desc, classes..)
allows users to create a drm.debug style (bitmap) sysfs interface, to
control sets of pr_debug's according to their .class_id's
1st, due to a recent commit, this already works:
echo "module drm class 1 +p ; module drm class 3 +p" >control
With the macro, this is basically equivalent:
# this also turns off all other classes.
echo 0x05 > /sys/module/drm/parameters/debug
To use:
DEFINE_DYNAMIC_DEBUG_CLASSBITS(debug, __drm_debug,
"drm.debug - bits => categories:",
/* vector of uint:4 symbols, ala enum drm_debug_category */
DRM_UT_CORE,
DRM_UT_DRIVER,
DRM_UT_KMS ... );
To support the macro, the patch includes:
- int param_set_dyndbg_classbits()
- int param_get_dyndbg_classbits()
- struct kernel_param_ops param_ops_dyndbg_classbits
Following the model of kernel/params.c STANDARD_PARAM_DEFS, these are
non-static and exported.
get/set use an augmented kernel_param; the arg refs a new struct
dyndbg_bitmap_param containing:
A- the vector of classes (drm.debug "categories") being controlled
For CONFIG_DRM_USE_DYNDBG=y, enum drm_debug_category is initialized
into (struct _ddebug).class_id, so its already available to select on.
B- a pointer to the user module's ulong holding the bits/state.
By sharing bit-state in __drm_debug, we coordinate with existing code
that still uses drm_debug_enabled(), so they work unchanged.
NOTES:
param_set_dyndbg_classbits() compares new vs old bits, and only
updates each class on changes. This maximally preserves the
underlying state, which may have been customized via later `echo $cmd
>control`. So if a user really wants to know that all prdbgs are set
precisely, they must pre-clear then set.
Signed-off-by: Jim Cromie <[email protected]>
---
include/linux/dynamic_debug.h | 45 ++++++++++++++++++++-
lib/dynamic_debug.c | 75 +++++++++++++++++++++++++++++++++++
2 files changed, 119 insertions(+), 1 deletion(-)
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index e9483cd9ac1c..318ac44a0d4a 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -20,7 +20,9 @@ struct _ddebug {
const char *function;
const char *filename;
const char *format;
- unsigned int class_id:4;
+#define CLS_BITS 4
+#define DD_MAX_CLASSES (1 << CLS_BITS)
+ unsigned int class_id:CLS_BITS;
unsigned int lineno:18;
/*
* The flags field controls the behaviour at the callsite.
@@ -202,6 +204,10 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
KERN_DEBUG, prefix_str, prefix_type, \
rowsize, groupsize, buf, len, ascii)
+struct kernel_param;
+int param_set_dyndbg_classbits(const char *instr, const struct kernel_param *kp);
+int param_get_dyndbg_classbits(char *buffer, const struct kernel_param *kp);
+
#else /* !CONFIG_DYNAMIC_DEBUG_CORE */
#include <linux/string.h>
@@ -248,6 +254,43 @@ static inline int dynamic_debug_exec_queries(const char *query, const char *modn
return 0;
}
+struct kernel_param;
+static inline int param_set_dyndbg_classbits(const char *instr, const struct kernel_param *kp)
+{ return 0; }
+static inline int param_get_dyndbg_classbits(char *buffer, const struct kernel_param *kp)
+{ return 0; }
+
#endif /* !CONFIG_DYNAMIC_DEBUG_CORE */
+struct dyndbg_classbits_param {
+ unsigned long *bits; /* ref to shared state */
+ const int classes[]; /* indexed by bitpos */
+};
+
+#if defined(CONFIG_DYNAMIC_DEBUG) || defined(CONFIG_DYNAMIC_DEBUG_CORE)
+/**
+ * DEFINE_DYNAMIC_DEBUG_CLASSBITS() - bitmap control of classed pr_debugs
+ * @sysname: sysfs-node name
+ * @_var: C-identifier holding bit-vector (Bits 0-15 are usable)
+ * @desc: string summarizing the controls provided
+ * @classes: vector of callsite.class_id's (uint:4, 0 is reserved)
+ *
+ * This macro implements a DRM.debug API style bitmap, mapping bits
+ * 0-15 to classes of prdbg's, as initialized in their .class_id fields.
+ */
+#define DEFINE_DYNAMIC_DEBUG_CLASSBITS(fsname, _var, desc, ...) \
+ MODULE_PARM_DESC(fsname, desc); \
+ static struct dyndbg_classbits_param ddcats_##_var = { \
+ .bits = &(_var), .classes = { __VA_ARGS__, 0 } }; \
+ module_param_cb(fsname, ¶m_ops_dyndbg_classbits, &ddcats_##_var, 0644)
+
+extern const struct kernel_param_ops param_ops_dyndbg_classbits;
+
+#else /* no dyndbg configured, throw error on macro use */
+
+#define DEFINE_DYNAMIC_DEBUG_CLASSBITS(fsname, var, bitmap_desc, ...) \
+ BUILD_BUG_ON_MSG(1, "CONFIG_DYNAMIC_DEBUG|_CORE && -DDYNAMIC_DEBUG_MODULE needed to use this macro: " #fsname #var)
+
+#endif
+
#endif
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 419d4664e724..40ca7973a0f8 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -610,6 +610,81 @@ int dynamic_debug_exec_queries(const char *query, const char *modname)
}
EXPORT_SYMBOL_GPL(dynamic_debug_exec_queries);
+#ifdef CONFIG_MODULES
+#define KP_MOD_NAME kp->mod->name
+#else
+#define KP_MOD_NAME NULL /* wildcard */
+#endif
+#define FMT_QUERY_SIZE 128 /* typically need <40 */
+/**
+ * param_set_dyndbg_classbits - bits => categories >control setter
+ * @instr: string echo>d to sysfs
+ * @kp: kp->arg has state: bits, map
+ *
+ * Enable/disable prdbgs by their "category", as specified in the
+ * DEFINE_DYNAMIC_DEBUG_BITGRPS.classbits argument.
+ *
+ * Returns: 0 or <0 if error.
+ */
+int param_set_dyndbg_classbits(const char *instr, const struct kernel_param *kp)
+{
+ unsigned long inbits;
+ int rc, i, matches = 0, totct = 0;
+ char query[FMT_QUERY_SIZE];
+ const struct dyndbg_classbits_param *dcp = kp->arg;
+
+ if (dcp) {
+ pr_err("set_dyndbg_classbits: no bits=>queries map\n");
+ return -EINVAL;
+ }
+ rc = kstrtoul(instr, 0, &inbits);
+ if (rc) {
+ pr_err("set_dyndbg_classbits: expecting unsigned int\n");
+ return rc;
+ }
+ vpr_info("set_dyndbg_classbits: new 0x%lx old 0x%lx\n", inbits, *dcp->bits);
+
+ for (i = 0; i < DD_MAX_CLASSES && dcp->classes[i]; i++) {
+ if (test_bit(i, &inbits) == test_bit(i, dcp->bits))
+ continue;
+ snprintf(query, FMT_QUERY_SIZE, "class %d %cT", dcp->classes[i],
+ test_bit(i, &inbits) ? '+' : '-');
+
+ matches = ddebug_exec_queries(query, KP_MOD_NAME);
+
+ v2pr_info("bit-%d: %d matches on class:%u\n", i,
+ matches, dcp->classes[i]);
+ totct += matches;
+ }
+ *dcp->bits = inbits;
+ vpr_info("total matches: %d\n", totct);
+ return 0;
+}
+EXPORT_SYMBOL(param_set_dyndbg_classbits);
+
+/**
+ * param_get_dyndbg_classbits - classbits reader
+ * @buffer: string description of controlled bits -> classes
+ * @kp: kp->arg has state: bits, map
+ *
+ * Reads last written bits, underlying prdbg state may have changed since.
+ * Returns: #chars written or <0 on error
+ */
+int param_get_dyndbg_classbits(char *buffer, const struct kernel_param *kp)
+{
+ const struct dyndbg_classbits_param *p = kp->arg;
+ unsigned long val = *p->bits;
+
+ return scnprintf(buffer, PAGE_SIZE, "0x%lx\n", val);
+}
+EXPORT_SYMBOL(param_get_dyndbg_classbits);
+
+const struct kernel_param_ops param_ops_dyndbg_classbits = {
+ .set = param_set_dyndbg_classbits,
+ .get = param_get_dyndbg_classbits,
+};
+EXPORT_SYMBOL(param_ops_dyndbg_classbits);
+
#define PREFIX_SIZE 64
static int remaining(int wrote)
--
2.33.1
if CONFIG_DRM_USE_DYNDBG=y, use new macro to create the sysfs bitmap
to control drm.debug callsites.
DEFINE_DYNAMIC_DEBUG_CLASSBITS( debug, __drm_debug,
"drm.debug - control summary",
/* inline vector of dyndbg.class_id (uint:4, 0 is reserved) */
DRM_UT_CORE,
DRM_UT_DRIVER,
DRM_UT_KMS,
DRM_UT_PRIME,
DRM_UT_ATOMIC,
DRM_UT_VBL,
DRM_UT_STATE,
DRM_UT_LEASE,
DRM_UT_DP,
DRM_UT_DRMRES );
NOTES:
dyndbg.class_id is uint:4, values 1-15 are valid. 0 is reserved
primarily for non-classified callsites (aka: prdbgs), and is thus
available to mark the end of the vector (and is added by the macro).
RFC: how to fold this in, with multiple macro expansion ?
Signed-off-by: Jim Cromie <[email protected]>
---
drivers/gpu/drm/drm_print.c | 20 ++++++++++++++++++--
include/drm/drm_print.h | 2 +-
2 files changed, 19 insertions(+), 3 deletions(-)
diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
index 0a15a4ec5ead..0de562e5306a 100644
--- a/drivers/gpu/drm/drm_print.c
+++ b/drivers/gpu/drm/drm_print.c
@@ -41,7 +41,7 @@
* __drm_debug: Enable debug output.
* Bitmask of DRM_UT_x. See include/drm/drm_print.h for details.
*/
-unsigned int __drm_debug;
+unsigned long __drm_debug;
EXPORT_SYMBOL(__drm_debug);
MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n"
@@ -53,7 +53,23 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat
"\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n"
"\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n"
"\t\tBit 8 (0x100) will enable DP messages (displayport code)");
-module_param_named(debug, __drm_debug, int, 0600);
+
+#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
+module_param_named(debug, __drm_debug, ulong, 0600);
+#else
+DEFINE_DYNAMIC_DEBUG_CLASSBITS(debug, __drm_debug,
+ "enable drm.debug categories - 1 bit per category",
+ DRM_UT_CORE,
+ DRM_UT_DRIVER,
+ DRM_UT_KMS,
+ DRM_UT_PRIME,
+ DRM_UT_ATOMIC,
+ DRM_UT_VBL,
+ DRM_UT_STATE,
+ DRM_UT_LEASE,
+ DRM_UT_DP,
+ DRM_UT_DRMRES);
+#endif
void __drm_puts_coredump(struct drm_printer *p, const char *str)
{
diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
index 6d43b81a0ee4..ebed5ba2dc24 100644
--- a/include/drm/drm_print.h
+++ b/include/drm/drm_print.h
@@ -36,7 +36,7 @@
#include <drm/drm.h>
/* Do *not* use outside of drm_print.[ch]! */
-extern unsigned int __drm_debug;
+extern unsigned long __drm_debug;
/**
* DOC: print
--
2.33.1
drm_print.c calls pr_debug() just once, from __drm_printfn_debug(),
which is a generic/service fn. The callsite is compile-time enabled
by DEBUG in both DYNAMIC_DEBUG=y/n builds.
For dyndbg builds, reverting this callsite back to bare printk is
correcting a few anti-features:
1- callsite is generic, serves multiple drm users.
its hardwired on currently
could accidentally: #> echo -p > /proc/dynamic_debug/control
2- optional "decorations" by dyndbg are unhelpful/misleading
they describe only the generic site, not end users
IOW, 1,2 are unhelpful at best, and possibly confusing.
reverting yields a nominal data and text shrink:
text data bss dec hex filename
462583 36604 54592 553779 87333 /lib/modules/5.16.0-rc4-lm1-00008-ged3eac8ceeea/kernel/drivers/gpu/drm/drm.ko
462515 36532 54592 553639 872a7 /lib/modules/5.16.0-rc4-lm1-00009-g6ce0b88d2539-dirty/kernel/drivers/gpu/drm/drm.ko
NB: this was noticed using _drm_debug_enabled(), added earlier.
Signed-off-by: Jim Cromie <[email protected]>
---
drivers/gpu/drm/drm_print.c | 5 ++---
1 file changed, 2 insertions(+), 3 deletions(-)
diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
index aab29dd6cad1..b911f949af5b 100644
--- a/drivers/gpu/drm/drm_print.c
+++ b/drivers/gpu/drm/drm_print.c
@@ -23,8 +23,6 @@
* Rob Clark <[email protected]>
*/
-#define DEBUG /* for pr_debug() */
-
#include <linux/stdarg.h>
#include <linux/io.h>
@@ -165,7 +163,8 @@ EXPORT_SYMBOL(__drm_printfn_info);
void __drm_printfn_debug(struct drm_printer *p, struct va_format *vaf)
{
- pr_debug("%s %pV", p->prefix, vaf);
+ /* pr_debug callsite decorations are unhelpful here */
+ printk(KERN_DEBUG "%s %pV", p->prefix, vaf);
}
EXPORT_SYMBOL(__drm_printfn_debug);
--
2.33.1
Change __drm_dbg() macro to be CONFIG_DRM_USE_DYNAMIC_DEBUG dependent:
N- keep straight mapping to exported ___drm_dbg()
Y- wrap ___drm_dbg() inside _dynamic_func_call_no_desc()
This patch places ~1/2 of drm.debug API messages behind dyndbg's
JUMP_LABEL/NOOP optimization.
The CONFIG_DRM_USE_DYNAMIC_DEBUG dependence is due to the .data
footprint cost of per-callsite control; 56 bytes/site * ~2k,3k
callsites (for i915, amdgpu), which is significant enough to make
optional.
bash-5.1# drms_load
[ 7.489844] dyndbg: 239 debug prints in module drm
[ 7.494010] ACPI: bus type drm_connector registered
[ 7.546076] dyndbg: 81 debug prints in module drm_kms_helper
[ 7.555723] dyndbg: 2 debug prints in module ttm
[ 7.558920] dyndbg: 8 debug prints in module video
[ 8.074699] dyndbg: 431 debug prints in module i915
[ 8.158682] AMD-Vi: AMD IOMMUv2 functionality not available on this system - This is not a bug.
[ 8.574456] dyndbg: 3817 debug prints in module amdgpu
[ 8.589962] [drm] amdgpu kernel modesetting enabled.
[ 8.590548] amdgpu: CRAT table not found
[ 8.590998] amdgpu: Virtual CRAT table created for CPU
[ 8.591634] amdgpu: Topology: Add CPU node
[ 8.636446] dyndbg: 3 debug prints in module wmi
[ 8.768667] dyndbg: 24 debug prints in module nouveau
Signed-off-by: Jim Cromie <[email protected]>
---
include/drm/drm_print.h | 34 +++++++++++++++++++++++++++++++++-
1 file changed, 33 insertions(+), 1 deletion(-)
diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
index 1eef315a0a65..8d6b74270c50 100644
--- a/include/drm/drm_print.h
+++ b/include/drm/drm_print.h
@@ -319,10 +319,36 @@ enum drm_debug_category {
DRM_UT_DRMRES
};
+/*
+ * 3 name flavors of drm_debug_enabled:
+ * drm_debug_enabled - public/legacy, always checks bits
+ * _drm_debug_enabled - instrumented to observe call-rates, est overheads.
+ * __drm_debug_enabled - privileged - knows jump-label state, can short-circuit
+ */
static inline bool drm_debug_enabled(enum drm_debug_category category)
{
return unlikely(__drm_debug & BIT(category));
}
+/*
+ * Wrap fn in macro, so that the pr_debug sees the actual caller, not
+ * the inline fn. Using this name creates a callsite entry / control
+ * point in /proc/dynamic_debug/control.
+ */
+#define _drm_debug_enabled(category) \
+ ({ \
+ pr_debug("todo: maybe avoid via dyndbg\n"); \
+ drm_debug_enabled(category); \
+ })
+#if defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
+/*
+ * dyndbg is wrapping the drm.debug API, so as to avoid the runtime
+ * bit-test overheads of drm_debug_enabled() in those api calls.
+ * In this case, executed callsites are known enabled, so true.
+ */
+#define __drm_debug_enabled(category) true
+#else
+#define __drm_debug_enabled(category) drm_debug_enabled(category)
+#endif
/*
* struct device based logging
@@ -497,7 +523,13 @@ void ___drm_dbg(enum drm_debug_category category, const char *format, ...);
__printf(1, 2)
void __drm_err(const char *format, ...);
+#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
#define __drm_dbg(fmt, ...) ___drm_dbg(fmt, ##__VA_ARGS__)
+#else
+#define __drm_dbg(eCat, fmt, ...) \
+ _dynamic_func_call_no_desc(fmt, ___drm_dbg, \
+ eCat, fmt, ##__VA_ARGS__)
+#endif
/* Macros to make printk easier */
@@ -569,7 +601,7 @@ void __drm_err(const char *format, ...);
static DEFINE_RATELIMIT_STATE(rs_, DEFAULT_RATELIMIT_INTERVAL, DEFAULT_RATELIMIT_BURST);\
const struct drm_device *drm_ = (drm); \
\
- if (drm_debug_enabled(DRM_UT_ ## category) && __ratelimit(&rs_)) \
+ if (__drm_debug_enabled(DRM_UT_ ## category) && __ratelimit(&rs_)) \
drm_dev_printk(drm_ ? drm_->dev : NULL, KERN_DEBUG, fmt, ## __VA_ARGS__); \
})
--
2.33.1
In order to use dynamic-debug's jump-label optimization in drm-debug,
its clarifying to refine drm_debug_enabled into 3 uses:
1. drm_debug_enabled - legacy, public
2. __drm_debug_enabled - optimized for dyndbg jump-label enablement.
3. _drm_debug_enabled - pr_debug instrumented, observable
1. The legacy version always checks the bits.
2. is privileged, for use by __drm_dbg(), __drm_dev_dbg(), which do an
early return unless the category is enabled (free of call/NOOP side
effects). For dyndbg builds, debug callsites are selectively
"pre-enabled", so __drm_debug_enabled() short-circuits to true there.
Remaining callers of 1 may be able to use 2, case by case.
3. is 1st wrapped in a macro, with a pr_debug, which reports each
usage in /proc/dynamic_debug/control, making it observable in the
logs. The macro lets the pr_debug see the real caller, not the inline
function.
When plugged into 1, it identified ~10 remaining callers of the
function, leading to the follow-on cleanup patch, and would allow
activating the pr_debugs, estimating the callrate, and the potential
savings by using the wrapper macro.
It is unused ATM, but it fills out the picture.
Signed-off-by: Jim Cromie <[email protected]>
---
drivers/gpu/drm/drm_print.c | 4 ++--
1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
index 5dd6713c14f2..aab29dd6cad1 100644
--- a/drivers/gpu/drm/drm_print.c
+++ b/drivers/gpu/drm/drm_print.c
@@ -265,7 +265,7 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
struct va_format vaf;
va_list args;
- if (!drm_debug_enabled(category))
+ if (!__drm_debug_enabled(category))
return;
va_start(args, format);
@@ -290,7 +290,7 @@ void ___drm_dbg(enum drm_debug_category category, const char *format, ...)
struct va_format vaf;
va_list args;
- if (!drm_debug_enabled(category))
+ if (!__drm_debug_enabled(category))
return;
va_start(args, format);
--
2.33.1
make drm_dev_dbg() macro CONFIG_DRM_USE_DYNAMIC_DEBUG dependent:
=N direct forwarding: drm_dev_dbg -> __drm_dev_dbg()
=Y wrap __drm_dev_dbg in _dynamic_func_call_no_desc().
This adds the metadata which creates a /proc/dynamic_debug/control
entry for each callsite, and exposes it for selective enablement.
NB: include header in header so wrapper is available
proof of function:
bash-5.1# grep 'ring test' /proc/dynamic_debug/control
drivers/gpu/drm/amd/amdgpu/amdgpu_ring.c:453 [amdgpu]amdgpu_ring_test_helper =xf "ring test on %s succeeded\012"
less
452 else
453 DRM_DEV_DEBUG(adev->dev, "ring test on %s succeeded\n",
454 ring->name);
drivers/gpu/drm/amd/amdgpu/amdgpu_ring.c lines 417-454/458 byte 12536/12575 100% (press RETURN)
new prdbg callsite counts:
bash-5.1# drms_load
[ 20.533990] dyndbg: 1 debug prints in module drm
[ 20.535637] ACPI: bus type drm_connector registered
[ 20.624951] dyndbg: 2 debug prints in module ttm
[ 20.627853] dyndbg: 8 debug prints in module video
[ 20.922442] dyndbg: 127 debug prints in module i915
[ 20.984159] AMD-Vi: AMD IOMMUv2 functionality not available on this system - This is not a bug.
[ 21.310216] dyndbg: 2196 debug prints in module amdgpu
[ 21.324537] [drm] amdgpu kernel modesetting enabled.
[ 21.325092] amdgpu: CRAT table not found
[ 21.325512] amdgpu: Virtual CRAT table created for CPU
[ 21.326009] amdgpu: Topology: Add CPU node
[ 21.401137] dyndbg: 3 debug prints in module wmi
[ 21.532540] dyndbg: 3 debug prints in module nouveau
Signed-off-by: Jim Cromie <[email protected]>
---
include/drm/drm_print.h | 6 ++++++
1 file changed, 6 insertions(+)
diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
index f8fa5af11310..1eef315a0a65 100644
--- a/include/drm/drm_print.h
+++ b/include/drm/drm_print.h
@@ -383,8 +383,14 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
} \
})
+#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
#define drm_dev_dbg(dev, eCat, fmt, ...) \
__drm_dev_dbg(dev, eCat, fmt, ##__VA_ARGS__)
+#else
+#define drm_dev_dbg(dev, eCat, fmt, ...) \
+ _dynamic_func_call_no_desc(fmt, __drm_dev_dbg, \
+ dev, eCat, fmt, ##__VA_ARGS__)
+#endif
/**
* DRM_DEV_DEBUG() - Debug output for generic drm code
--
2.33.1
A recent commit adding trace-events to drm noted:
trace_*() additions are strictly redundant with printks to syslog,
not properly placed to reduce overall work.
That was because it didn't have the struct _ddebug *descriptor, whose
.flags specify TRACE and PRINTK actions on a controlled callsite. So
it could only duplicate the stream (from the enabled callsites).
To issue TRACE, PRINTK selectively:
- add struct _ddebug * param to prototypes and functions:
___drm_dbg(), __drm_dev_dbg()
add "struct _ddebug;" to name the ptr-type, to silence warning.
- adjust the forwarding macros: drm_dbg, drm_dev_dbg
to provide a descriptor, or NULL.
basically this is dropping the _no_desc_,
ie using _dynamic_func_call_cls(), since the callee can now accept it.
- add if (desc->flags ...) TRACE / PRINTK actions.
Signed-off-by: Jim Cromie <[email protected]>
---
drivers/gpu/drm/drm_print.c | 25 ++++++++++++++++---------
include/drm/drm_print.h | 20 ++++++++++----------
2 files changed, 26 insertions(+), 19 deletions(-)
diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
index b911f949af5b..8c33302212fc 100644
--- a/drivers/gpu/drm/drm_print.c
+++ b/drivers/gpu/drm/drm_print.c
@@ -258,8 +258,8 @@ void drm_dev_printk(const struct device *dev, const char *level,
}
EXPORT_SYMBOL(drm_dev_printk);
-void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
- const char *format, ...)
+void __drm_dev_dbg(struct _ddebug *desc, const struct device *dev,
+ enum drm_debug_category category, const char *format, ...)
{
struct va_format vaf;
va_list args;
@@ -267,24 +267,31 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
if (!__drm_debug_enabled(category))
return;
+ /* we know we are printing for either syslog, tracefs, or both */
va_start(args, format);
vaf.fmt = format;
vaf.va = &args;
if (dev) {
- dev_printk(KERN_DEBUG, dev, "[" DRM_NAME ":%ps] %pV",
- __builtin_return_address(0), &vaf);
- trace_drm_devdbg(dev, category, &vaf);
+ if (desc->flags & _DPRINTK_FLAGS_PRINTK)
+ dev_printk(KERN_DEBUG, dev, "[" DRM_NAME ":%ps] %pV",
+ __builtin_return_address(0), &vaf);
+
+ if (desc->flags & _DPRINTK_FLAGS_TRACE)
+ trace_drm_devdbg(dev, category, &vaf);
} else {
- printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV",
- __builtin_return_address(0), &vaf);
- trace_drm_debug(category, &vaf);
+ if (desc->flags & _DPRINTK_FLAGS_PRINTK)
+ printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV",
+ __builtin_return_address(0), &vaf);
+
+ if (desc->flags & _DPRINTK_FLAGS_TRACE)
+ trace_drm_debug(category, &vaf);
}
va_end(args);
}
EXPORT_SYMBOL(__drm_dev_dbg);
-void ___drm_dbg(enum drm_debug_category category, const char *format, ...)
+void ___drm_dbg(struct _ddebug *desc, enum drm_debug_category category, const char *format, ...)
{
struct va_format vaf;
va_list args;
diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
index 0c704610c770..6d43b81a0ee4 100644
--- a/include/drm/drm_print.h
+++ b/include/drm/drm_print.h
@@ -360,9 +360,9 @@ static inline bool drm_debug_enabled(enum drm_debug_category category)
__printf(3, 4)
void drm_dev_printk(const struct device *dev, const char *level,
const char *format, ...);
-__printf(3, 4)
-void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
- const char *format, ...);
+__printf(4, 5)
+void __drm_dev_dbg(struct _ddebug *desc, const struct device *dev,
+ enum drm_debug_category category, const char *format, ...);
/**
* DRM_DEV_ERROR() - Error output.
@@ -412,11 +412,11 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
#define drm_dev_dbg(dev, eCat, fmt, ...) \
- __drm_dev_dbg(dev, eCat, fmt, ##__VA_ARGS__)
+ __drm_dev_dbg(NULL, dev, eCat, fmt, ##__VA_ARGS__)
#else
#define drm_dev_dbg(dev, eCat, fmt, ...) \
- _dynamic_func_call_no_desc_cls(fmt, eCat, __drm_dev_dbg, \
- dev, eCat, fmt, ##__VA_ARGS__)
+ _dynamic_func_call_cls(eCat, fmt, __drm_dev_dbg, \
+ dev, eCat, fmt, ##__VA_ARGS__)
#endif
/**
@@ -519,8 +519,8 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
* Prefer drm_device based logging over device or prink based logging.
*/
-__printf(2, 3)
-void ___drm_dbg(enum drm_debug_category category, const char *format, ...);
+__printf(3, 4)
+void ___drm_dbg(struct _ddebug *desc, enum drm_debug_category category, const char *format, ...);
__printf(1, 2)
void __drm_err(const char *format, ...);
@@ -528,8 +528,8 @@ void __drm_err(const char *format, ...);
#define __drm_dbg(fmt, ...) ___drm_dbg(NULL, fmt, ##__VA_ARGS__)
#else
#define __drm_dbg(eCat, fmt, ...) \
- _dynamic_func_call_no_desc_cls(fmt, eCat, ___drm_dbg, \
- eCat, fmt, ##__VA_ARGS__)
+ _dynamic_func_call_cls(eCat, fmt, ___drm_dbg, \
+ eCat, fmt, ##__VA_ARGS__)
#endif
/* Macros to make printk easier */
--
2.33.1
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/[email protected]/
>
> .. 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: [email protected]
> Signed-off-by: Jim Cromie <[email protected]>
> ---
> .../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 = &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%s: %pV",
> + dev_name(&ibdev->dev), &vaf);
> } else {
> - printk(KERN_DEBUG "(NULL ib_device): %pV", &vaf);
> + dynamic_printk(flags, KERN_DEBUG "(NULL ip_device): %pV",
> + &vaf);
> }
>
> - va_end(args);
> +va_end(args);
This looks like an unintentional whitespace change?
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(&dp->key.dd_key_true);
> - } else if (modifiers->flags & _DPRINTK_FLAGS_PRINT)
> + } else if (modifiers->flags & _DPRINTK_FLAGS_ENABLED)
> static_branch_enable(&dp->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/[email protected]/?
| 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(&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
On Fri, Jan 14, 2022 at 4:57 AM Vincent Whitchurch
<[email protected]> wrote:
>
> 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(&dp->key.dd_key_true);
> > - } else if (modifiers->flags & _DPRINTK_FLAGS_PRINT)
> > + } else if (modifiers->flags & _DPRINTK_FLAGS_ENABLED)
> > static_branch_enable(&dp->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/[email protected]/?
>
Yes, thanks for noticing. I missed that detail.
Apriori, I dont know why bit-and of bit-or'd flags doesnt cover it,
but I will take a careful look.
> | 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(&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
On Fri, Jan 14, 2022 at 4:46 AM Vincent Whitchurch
<[email protected]> wrote:
>
> On Fri, Jan 07, 2022 at 06:29:26AM +0100, Jim Cromie wrote:
> >
> > 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/[email protected]/
> >
> > .. 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?
>
good catch, thanks.
Ive just dropped the example, it seemed the simplest fix.
It seemed proper to commit your code as pristine as practical,
so that subsequent mistakes receive the blame.
and Ive fixed the spurious whitespace change you noted.