Add support for writing debug logs to trace events and trace instances.
The rationale behing this feature is to be able to redirect debug logs
(per each callsite individually) to trace to aid in debugging. Dynamic
debug has now ability to send pr_debugs to sysfs *and/or* tracefs. Since
tracefs has 2 user groups, dyndbg can write to either:
0. users of trace-events (prdbg and devdbg), in the global: tracing/trace
1. users of trace_array_printk(), writing to private trace
buffers: in tracing/instances/*
It is presumed that being able to mix existing pr_debugs into your trace,
to add "framing/context/decorations", will prove useful for both kinds
of users. If nothing else, it lets users apply trace-cmd upon klog and
trace-event activity.
Dynamic Debug can independently direct pr_debugs to both syslog and
tracefs, using the +p, +T flags respectively. This allows users to
migrate away from syslog in bites, if and as they see a reason.
Dyndbg supports 64-way steering of pr_debugs into tracefs, by labelling
the callsites. You can steer trace traffic for any number of reasons:
- create a flight-recorder buffer.
- isolate hi-rate traffic.
- simplify buffer management and overwrite guarantees.
- assemble "related" sets of prdbgs by labelling them.
- select & enable them later, with "label" keyword.
- just label some traffic as trash/uninteresting (>/dev/null?)
- 63 private buffers are supported + global
Callsites can be labelled, using the ``:<lbl_name>`` trace-label
pseudo-flag, and the following <lbl_name>. This labels the callsite
with that name, allowing its later selection and enablement using the
"label" keyword. From boot, the [#default_dest] and all callsite
labels are set to "0".
Labelling Examples:
=T:0 # enable tracing to "0"/global explicitly
=T:0. # same, dot terminates lbl_name (optional here)
=T:0.mf # same, but add "module:func:" prefix to msgs (dot required)
=T # enable tracing to site.label (0 by default)
=T:foo # set labels to foo [#ifopened]_, send them to tracing/instances/foo
=T:foo.mf # same, with "module:function:" prefix
=_:foo # clear all flags, set all labels to foo [#ifopened]_
=:foo # set labels, touch no flags, since no flags are given
=:0 # reset all labels to global trace-buf
=:0. # same (with optional dot)
Labelling is primarily for mapping into tracing, but is syntactically
separate, and is allowed independently, so the label keyword can be
used to enable to syslog, or to both.
=p:foo # enable to syslog, p ignores foo
=pT:foo # trace to instances/foo, and to syslog
The ``:0.`` default label steers output to the global trace-event buf:
ddcmd open 0 # opened by default, also sets [#default_dest]_
ddcmd =:0 # steer pr_debugs to /sys/kernel/tracing/trace
ddcmd =T # enable pr_debugs to their respective destinations
# also need to enable the events into tracefs
echo 1 > /sys/kernel/tracing/trace_on
echo 1 > /sys/kernel/tracing/events/dyndbg/enable
Or the ``:<name>.`` labels steer +T enabled callsites into
/sys/kernel/tracing/instances/<name> [#ifopened]_
ddcmd open foo # open or append to /sys/kernel/tracing/instances/foo
ddcmd =:foo # set labels explicitly
ddcmd =T # enable tracing to site.label
# needed if appending (above)
echo 1 > /sys/kernel/tracing/instances/foo/trace_on
echo 1 > /sys/kernel/tracing/instances/foo/events/dyndbg/enable
The ``open foo`` & ``close foo`` commands allow dyndbg to manage the
63 private trace-instances it can use simultaneously, so it can error
with -ENOSPC when asked for one-too-many. Otherwise, [#default_dest]
is upated accordingly.
[#ifopened] It is an error -EINVAL to set a label (=:foo) that hasn't
been previously opened.
[#already_opened] If /sys/kernel/tracing/instances/foo has already
been created separately, then dyndbg just uses it, mixing any =T:foo
labelled pr_debugs into instances/foo/trace. Otherwise dyndbg will
open the trace-instance, and enable it for you.
Dyndbg treats ``:0.`` as the name of the global trace-event buffer; it
is automatically opened, but needs to be enabled in tracefs too.
``close foo`` insures that no pr_debugs are set to :foo, then unmaps
the label from its reserved trace-id, preserving the trace buffer for
trace-cmd etc. Otherwise the command returns -EBUSY.
Usage examples
Open "usb" trace instance in <debugfs>/tracing/instances/ by issuing
the command:
localhost ~ # echo "open usb" >
<debugfs>/dynamic_debug/control
The open "usb" also sets default destination to the "usb" instance.
To enable writing usbcore module debug logs to the "usb" trace instance
opened above a user can issue the command:
localhost ~ # echo "module usbcore =T:usb" >
<debugfs>/dynamic_debug/control
When trace destination is followed by another flag the next flag has to
be preeceded with ".", for example
localhost ~ # echo "module usbcore =T:usb.l" >
<debugfs>/dynamic_debug/control
To simplify processing trace destination can be omitted and in such
a case the default destination will be used, for example the command
localhost ~ # echo "module usbcore =Tl" >
<debugfs>/dynamic_debug/control
will use default trace destination "usb".
To label all thubderbolt module callsites with the "usb" trace instance
name a user can issue the command
localhost ~ # echo "module thunderbolt =:usb" >
<debugfs>/dynamic_debug/control
To enable all "usb" labelled callsites a user can issue the command:
localhost ~ # echo "label usb =T" >
<debugfs>/dynamic_debug/control
When "usb" instance is not used anymore by any of the callsites
a user can close it by issuing the command:
localhost ~ # echo "close usb" >
<debugfs>/dynamic_debug/control
and then to delete it at a later convenient time after inspecting
the captured debug logs with:
localhost ~ # rmdir <debugfs>/tracing/instances/usb
To enable writing usbcore module debug logs to trace dyndbg:prdbg and
dyndbg:devdbg events user can issue the command:
localhost ~ # echo "module usbcore =T:0" >
<debugfs>/dynamic_debug/control
Then dyndbg trace events can be for example captured with the command:
localhost ~ # trace-cmd start -e dyndbg
or
localhost ~ # trace-cmd start -e prdbg,devdbg
The captured debug logs can displayed with the command:
localhost ~ # trace-cmd show
All currently opened trace instances can be shown with the command:
localhost ~ # trace-cmd stat
For full description of the feature and more examples please see
the updated documentation in Documentation/admin-guide/dynamic-debug-howto.rst
Changes:
V4 -> V3
- fix typos in the cover letter decrased -> decreased, make -> makes,
- allow "T:foo." with the trailing dot,
- update the cover-letter to include trace-cmd stat which can be used to show currently opened trace instances,
- change commit subject "dyndbg: add processing of T(race) flag argument" to "dyndbg: handle +T:buf_name.flags grammar",
- squash commit "dyndbg: add skip_spaces_and_coma()" with commit "dyndbg: treat comma as a token separator"
and update function name skip_spaces_and_coma -> skip_spaces_and_comma,
- add dyndbg_selftest.sh script which includes test cases for the verification of dynamic debug functionality (especially addtion of trace support),
- refactor test_private_trace_2, test_private_trace_3 and test_private_trace_4 tests,
- add cleanup function to tests suite which prepares environment for tests execution,
- update handling of trace destination so that it can be provided in the form of "T:t_name" or ":t_name", the former
sets trace destination and enables output to it, the latter sets only trace destination for future use,
- update "add support for default trace destination" to set default trace destination on last sucessfull open command,
- update default trace destination on reopen of already trace instance or on "open 0",
- preserve callsites' trace destinations which differs from '0' for later use with 'label' keyword,
- add static prefix to skip_spaces_and_comma(),
- modify the continue-looping behavior of ddebug_exec_queries to stop processing next queries in a multi command string
when trace open or close command fails,
- add test which verifies default trace destination feature,
- add test which verifies different combinations of flags and trace destination,
- rename cycle_tests_problem() to cycle_not_best_practices(),
- commit "dyndbg: treat comma as a token separator", clarify that it adds new format and still continues to support existing one,
- update check_match_ct() function to enclose pattern to match with spaces, this is required because some matching was too relaxed,
apart from it if -r is passed as $3 then pattern to match is used as is without enclosing it with spaces,
- modify the behavior of the command "ddcmd =:foo" in the commit "dyndbg: update "ddcmd =:foo" behavior" to set (only) the foo label and preserve the flags,
update test_flags test,
- do not display trace destination in /proc/dynamic_debug/control if it is set to default "0" (commit "dyndbg: don't show "0" as it is default"),
V3 -> V2
- squash "dyndbg: export _print_hex_dump" with "dyndbg: add support for hex_dump output to trace",
- squash "dyndbg: tweak pr_info format s/trace dest/trace_dest/" with "dyndbg: add processing of T(race) flag argument",
- squash "dyndbg: change +T:name_terminator to dot" with "dyndbg: add processing of T(race) flag argument",
- fix setting default trace destination,
- decrease use count when callsite is being disabled as a part of module removal,
- fix parsing of T flag argument,
- update __get_str_strip_nl macro per Steve's comment,
- drop commit "dyndbg: move lock,unlock into ddebug_change, drop goto" and add comment explaining why ddebug_parse_flags
and ddebug_change have to be run in critical section,
- add "depends on TRACING" for "DYNAMIC_DEBUG",
- update DYNAMIC_DEBUG_BRANCH macro which is used when CONFIG_JUMP_LABEL is not set,
- change structure name ddebug_trace_inst to dd_private_tracebuf,
- change structure name ddebug_trace to dd_tracebuf_tbl_info,
- rename is_ddebug_cmd to is_dd_trace_cmd,
- rename validate_tr_name to dd_good_trace_name,
- rename handle_tr_opend_cmd to handle_trace_opend_cmd and handle_tr_close_cmd to handle_trace_close_cmd,
- refactor ddebug_parse_cmd,
- add pr_err when trace_array_get_by_name or trace_array_init_printk fails in trace_array_init_printk,
- add static prefix to show_T_args,
- rename TRACE_DST_MAX to TRACE_DST_LAST and change its value to 64, reserve index 0 for trace events in dd_tracebuf_tbl_info (index 0 will be wasted),
- add "#: " prefix to "Default trace destination" and "Opened trace instances" and print all opened trace instances on the same line,
V2->V1
Major rework after receiving feedback in
https://lore.kernel.org/all/[email protected]/
This includes among other things:
- addittion of open/close commands,
- use names instead of numbers for trace destinations,
- change prdbg and devdbg trace events to strip newline
on the slow path (read side),
- change prdbg and devdbg trace events to stores actual values
instead of pointers because if a pointer becomes invalid then
the TP_printk call will cause a crash,
- add support for default trace destination.
V1
Major rework after receiving feedback in
https://lore.kernel.org/all/[email protected]/
Jim Cromie (22):
dyndbg: add _DPRINTK_FLAGS_ENABLED
dyndbg: add _DPRINTK_FLAGS_TRACE
dyndbg: add write events to tracefs code
dyndbg: add 2 trace-events: prdbg, devdbg
tracefs: add __get_str_strip_nl
dyndbg: use __get_str_strip_nl in prdbg and devdbg
dyndbg: repack _ddebug structure
dyndbg: add label keyword handling
dyndbg: fix old BUG_ON in >control parser
dyndbg: treat comma as a token separator
dyndbg: split multi-query strings with %
dyndbg: reduce verbose/debug clutter
dyndbg: display the bad flag-val in parse-flags err msg
dyndbg: report err in ddebug_parse_flags when read_args fails
dyndbg: warn if no flags are given
dyndbg-test: add tools/testing/selftests/dynamic_debug/*
dyndbg-test: fixup search-trace-name help
dyndbg-test: test_private_trace_mixed_class - parameterize modname
dyndbg-test: add test for label keyword
docs/dyndbg: update examples \012 to \n
docs/dyndbg: explain new delimiters: comma, percent
docs/dyndbg: explain debug-to-tracefs (=T:label.flags)
Łukasz Bartosik (17):
dyndbg: move flags field to a new structure
dyndbg: add trace destination field to _ddebug
dyndbg: add open and close commands for trace
dyndbg: don't close trace instance when in use
dyndbg: handle [+T]:buf_name.flags grammar
dyndbg: add support for default trace destination
dyndbg: update default trace destination on reopen
dyndbg: update selection of trace destination
dyndbg: write debug logs to trace instance
dyndbg: add support for hex_dump output to trace
dyndbg: don't process queries when trace cmd fails
dyndbg: update "ddcmd =:foo" behavior
dyndbg: don't show default trace destination "0"
dyndbg-test: refactor test_private_trace_* tests
dyndbg-test: setup environment for tests execution
dyndbg-test: add test which verifies flags and dst
dyndbg-test: add test which verifies default dst
.../admin-guide/dynamic-debug-howto.rst | 370 ++++++-
MAINTAINERS | 2 +
include/linux/dynamic_debug.h | 57 +-
include/trace/events/dyndbg.h | 54 +
include/trace/stages/stage3_trace_output.h | 13 +
lib/Kconfig.debug | 2 +
lib/dynamic_debug.c | 829 +++++++++++++--
.../testing/selftests/dynamic_debug/Makefile | 9 +
tools/testing/selftests/dynamic_debug/config | 1 +
.../dynamic_debug/dyndbg_selftest.sh | 959 ++++++++++++++++++
10 files changed, 2142 insertions(+), 154 deletions(-)
create mode 100644 include/trace/events/dyndbg.h
create mode 100644 tools/testing/selftests/dynamic_debug/Makefile
create mode 100644 tools/testing/selftests/dynamic_debug/config
create mode 100755 tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
Distinguish the condition: _DPRINTK_FLAGS_ENABLED from the bit:
_DPRINTK_FLAGS_PRINT, and re-define former in terms of latter, in
preparation to add a 2nd bit: _DPRINTK_FLAGS_TRACE
Update JUMP_LABEL code block to check _DPRINTK_FLAGS_ENABLED symbol.
Also add a 'K' to get new symbol _DPRINTK_FLAGS_PRINTK, in order to
break any stale uses.
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 4fcbf4d4fd0a..7be791af7cf1 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -32,7 +32,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)
@@ -44,8 +44,10 @@ struct _ddebug {
_DPRINTK_FLAGS_INCL_LINENO | _DPRINTK_FLAGS_INCL_TID |\
_DPRINTK_FLAGS_INCL_SOURCENAME)
+#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
@@ -199,10 +201,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 6fba6423cc10..ee0cb37153ef 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -89,7 +89,7 @@ static inline const char *trim_prefix(const char *path)
}
static const 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_SOURCENAME, 's' },
@@ -247,10 +247,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 (!(newflags & _DPRINTK_FLAGS_PRINT))
+ if (dp->flags & _DPRINTK_FLAGS_ENABLED) {
+ if (!(newflags & _DPRINTK_FLAGS_ENABLED))
static_branch_disable(&dp->key.dd_key_true);
- } else if (newflags & _DPRINTK_FLAGS_PRINT) {
+ } else if (newflags & _DPRINTK_FLAGS_ENABLED) {
static_branch_enable(&dp->key.dd_key_true);
}
#endif
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
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 | 5 +++--
1 file changed, 3 insertions(+), 2 deletions(-)
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index 7be791af7cf1..497130816e9c 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -33,6 +33,9 @@ struct _ddebug {
*/
#define _DPRINTK_FLAGS_NONE 0
#define _DPRINTK_FLAGS_PRINTK (1 << 0) /* printk() a message using the format */
+#define _DPRINTK_FLAGS_TRACE (1 << 6)
+#define _DPRINTK_FLAGS_ENABLED (_DPRINTK_FLAGS_PRINTK | _DPRINTK_FLAGS_TRACE)
+
#define _DPRINTK_FLAGS_INCL_MODNAME (1<<1)
#define _DPRINTK_FLAGS_INCL_FUNCNAME (1<<2)
#define _DPRINTK_FLAGS_INCL_LINENO (1<<3)
@@ -44,8 +47,6 @@ struct _ddebug {
_DPRINTK_FLAGS_INCL_LINENO | _DPRINTK_FLAGS_INCL_TID |\
_DPRINTK_FLAGS_INCL_SOURCENAME)
-#define _DPRINTK_FLAGS_ENABLED _DPRINTK_FLAGS_PRINTK
-
#if defined DEBUG
#define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINTK
#else
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
adds: ddebug_trace()
uses trace_console() temporarily to issue printk:console event
uses internal-ish __ftrace_trace_stack code:
4-context buffer stack, barriers per Steve Rostedt
call it from new funcs:
ddebug_printk() - print to both syslog/tracefs
ddebug_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: __ddebug_{pr_debug,{,net,ib}dev_dbg},
replacing printk and dev_printk with the new funcs above.
The _DPRINTK_FLAGS_TRACE flag character is 'T', so the following finds
all callsites enabled for tracing:
grep -P =p?T /proc/dynamic_debug/control
This patch,~1,~2 are basically copies of [1] with a few differences:
- s/dynamic_/ddebug_/ on Vincent's additions
- __printf attrs on the _printk funcs
- reuses trace_console() event, not adding a new "printk:dyndbg" event.
next patch replaces this with 2 new events
[1] https://lore.kernel.org/lkml/[email protected]
CC: [email protected]
Signed-off-by: Jim Cromie <[email protected]>
---
.../admin-guide/dynamic-debug-howto.rst | 5 +-
lib/dynamic_debug.c | 156 +++++++++++++++---
2 files changed, 133 insertions(+), 28 deletions(-)
diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst
index 0e9b48daf690..90449a04946e 100644
--- a/Documentation/admin-guide/dynamic-debug-howto.rst
+++ b/Documentation/admin-guide/dynamic-debug-howto.rst
@@ -209,8 +209,9 @@ of the characters::
The flags are::
- p enables the pr_debug() callsite.
- _ enables no flags.
+ p callsite prints to syslog
+ T callsite issues a dyndbg:* trace-event
+ _ enables no flags
Decorator flags add to the message-prefix, in order:
t Include thread ID, or <intr>
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index ee0cb37153ef..016f33c20251 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>
@@ -90,6 +91,7 @@ static inline const char *trim_prefix(const char *path)
static const 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_SOURCENAME, 's' },
@@ -858,6 +860,98 @@ 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 ddebug_trace_buf {
+ char buf[256];
+};
+
+struct ddebug_trace_bufs {
+ struct ddebug_trace_buf bufs[DYNAMIC_TRACE_NESTING];
+};
+
+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)
+{
+ struct ddebug_trace_buf *buf;
+ int bufidx;
+ int len;
+
+ preempt_disable_notrace();
+
+ bufidx = __this_cpu_inc_return(ddebug_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(ddebug_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(ddebug_trace_reserve);
+ preempt_enable_notrace();
+}
+
+__printf(2, 3)
+static void ddebug_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.
+ */
+ ddebug_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);
+ }
+}
+
+__printf(3, 4)
+static void ddebug_dev_printk(unsigned int flags, const struct device *dev,
+ const char *fmt, ...)
+{
+
+ if (flags & _DPRINTK_FLAGS_TRACE) {
+ va_list args;
+
+ va_start(args, fmt);
+ ddebug_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;
@@ -872,16 +966,18 @@ 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);
+ ddebug_printk(descriptor->flags, KERN_DEBUG "%s%pV",
+ dynamic_emit_prefix(descriptor, buf), &vaf);
va_end(args);
}
EXPORT_SYMBOL(__dynamic_pr_debug);
void __dynamic_dev_dbg(struct _ddebug *descriptor,
- const struct device *dev, const char *fmt, ...)
+ const struct device *dev, const char *fmt, ...)
{
struct va_format vaf;
+ unsigned int flags;
va_list args;
BUG_ON(!descriptor);
@@ -891,16 +987,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);
+ ddebug_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);
+ ddebug_dev_printk(flags, dev, "%s%s %s: %pV",
+ dynamic_emit_prefix(descriptor, buf),
+ dev_driver_string(dev), dev_name(dev),
+ &vaf);
}
va_end(args);
@@ -913,6 +1011,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);
@@ -922,22 +1021,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);
+ 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);
} else if (dev) {
- printk(KERN_DEBUG "%s%s: %pV", netdev_name(dev),
- netdev_reg_state(dev), &vaf);
+ ddebug_printk(flags, KERN_DEBUG "%s%s: %pV",
+ netdev_name(dev), netdev_reg_state(dev), &vaf);
} else {
- printk(KERN_DEBUG "(NULL net_device): %pV", &vaf);
+ ddebug_printk(flags, KERN_DEBUG "(NULL net_device): %pV",
+ &vaf);
}
va_end(args);
@@ -953,26 +1054,29 @@ 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);
+ ddebug_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);
+ ddebug_printk(flags, KERN_DEBUG "%s: %pV",
+ dev_name(&ibdev->dev), &vaf);
} else {
- printk(KERN_DEBUG "(NULL ib_device): %pV", &vaf);
+ ddebug_printk(flags, KERN_DEBUG "(NULL ip_device): %pV", &vaf);
}
va_end(args);
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
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 save a debug message and use its length for
processing. They also accept the _ddebug descriptor and dev
structure so they can be used to access the whole callsite
record in the future: 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 <[email protected]>
Co-developed-by: Łukasz Bartosik <[email protected]>
Signed-off-by: Łukasz Bartosik <[email protected]>
---
MAINTAINERS | 1 +
include/trace/events/dyndbg.h | 63 ++++++++++++++++++++++++++++++
lib/dynamic_debug.c | 73 ++++++++++++++++++-----------------
3 files changed, 101 insertions(+), 36 deletions(-)
create mode 100644 include/trace/events/dyndbg.h
diff --git a/MAINTAINERS b/MAINTAINERS
index 960512bec428..b584a8468fb9 100644
--- a/MAINTAINERS
+++ b/MAINTAINERS
@@ -7456,6 +7456,7 @@ M: Jason Baron <[email protected]>
M: Jim Cromie <[email protected]>
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..647c30206a7d
--- /dev/null
+++ b/include/trace/events/dyndbg.h
@@ -0,0 +1,63 @@
+/* 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>
+
+/*
+ * template for dynamic debug events
+ * captures debug log message and uses its length, it also
+ * accepts _ddebug and dev structures for future extensions
+ */
+DECLARE_EVENT_CLASS(dyndbg_template,
+
+ TP_PROTO(const struct _ddebug *desc, const struct device *dev,
+ const char *msg, size_t len),
+
+ TP_ARGS(desc, dev, msg, len),
+
+ TP_STRUCT__entry(
+ __dynamic_array(char, s, 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 && (msg[len-1] == '\n'))
+ len -= 1;
+
+ memcpy(__get_str(s), msg, len);
+ __get_str(s)[len] = 0;
+ ),
+
+ TP_printk("%s", __get_str(s))
+);
+
+/* captures pr_debug() callsites */
+DEFINE_EVENT(dyndbg_template, prdbg,
+
+ TP_PROTO(const struct _ddebug *desc, const struct device *dev,
+ const char *msg, size_t len),
+
+ TP_ARGS(desc, dev, msg, len)
+);
+
+/* captures dev_dbg() callsites */
+DEFINE_EVENT(dyndbg_template, devdbg,
+
+ TP_PROTO(const struct _ddebug *desc, const struct device *dev,
+ const char *msg, size_t len),
+
+ TP_ARGS(desc, dev, msg, len)
+);
+
+#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..fcc7c5631b53 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, NULL, 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.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
This variant of __get_str() removes the trailing newline. It is for
use by printk/debug-ish events which already have a trailing newline.
It is here to support [1] which taught dyndbg to send pr_debug() msgs
to tracefs, via -T flag. It "reused" the include/trace/events/printk.h
console event, which does the following:
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 && (msg[len-1] == '\n'))
len -= 1;
memcpy(__get_str(s), msg, len);
__get_str(s)[len] = 0;
),
We can avoid trimming the last \n during write into the tracebuf, by
instead stripping it when reading the tracebuf. So do that.
[1] https://lore.kernel.org/lkml/[email protected]
Cc: <[email protected]>
Cc: Vincent Whitchurch <[email protected]>
Cc: <[email protected]>
Cc: <[email protected]>
Cc: <[email protected]>
Cc: <[email protected]>
Cc: Simon Ser <[email protected]>
Cc: Sean Paul <[email protected]>
Signed-off-by: Jim Cromie <[email protected]>
Co-developed-by: Łukasz Bartosik <[email protected]>
Signed-off-by: Łukasz Bartosik <[email protected]>
---
include/trace/stages/stage3_trace_output.h | 13 +++++++++++++
1 file changed, 13 insertions(+)
diff --git a/include/trace/stages/stage3_trace_output.h b/include/trace/stages/stage3_trace_output.h
index c1fb1355d309..283533a17e62 100644
--- a/include/trace/stages/stage3_trace_output.h
+++ b/include/trace/stages/stage3_trace_output.h
@@ -19,6 +19,19 @@
#undef __get_str
#define __get_str(field) ((char *)__get_dynamic_array(field))
+#undef __get_str_strip_nl
+#define __get_str_strip_nl(field) \
+ ({ \
+ char *s = trace_seq_buffer_ptr(p); \
+ size_t len; \
+ trace_seq_printf(p, "%s", __get_str(field)); \
+ trace_seq_putc(p, '\0'); \
+ len = strlen(s); \
+ if (len && s[len-1] == '\n') \
+ s[len-1] = '\0'; \
+ s; \
+ })
+
#undef __get_rel_dynamic_array
#define __get_rel_dynamic_array(field) \
((void *)__entry + \
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
Recently added dyndbg events: prdbg, devdbg have code to strip the
trailing newline, if it's there. Instead of removing the newline
in TP_fast_assign use __get_str_strip_nl macro in TP_printk. Advantage
of such an approach is that the removal is done on the read side (slow
path). The change removes also passing of debug message length to prdbg
and devdbg events.
This use is slightly premature/overkill, since some pr_debugs do not
have the expected trailing newline. While those lacks are arguably
bugs, this doesn't fix them.
Signed-off-by: Jim Cromie <[email protected]>
Co-developed-by: Łukasz Bartosik <[email protected]>
Signed-off-by: Łukasz Bartosik <[email protected]>
---
include/trace/events/dyndbg.h | 27 +++++++++------------------
lib/dynamic_debug.c | 7 +++----
2 files changed, 12 insertions(+), 22 deletions(-)
diff --git a/include/trace/events/dyndbg.h b/include/trace/events/dyndbg.h
index 647c30206a7d..ffd21480cd9d 100644
--- a/include/trace/events/dyndbg.h
+++ b/include/trace/events/dyndbg.h
@@ -15,46 +15,37 @@
DECLARE_EVENT_CLASS(dyndbg_template,
TP_PROTO(const struct _ddebug *desc, const struct device *dev,
- const char *msg, size_t len),
+ const char *msg),
- TP_ARGS(desc, dev, msg, len),
+ TP_ARGS(desc, dev, msg),
TP_STRUCT__entry(
- __dynamic_array(char, s, len+1)
+ __string(s, msg)
),
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 && (msg[len-1] == '\n'))
- len -= 1;
-
- memcpy(__get_str(s), msg, len);
- __get_str(s)[len] = 0;
+ __assign_str(s, msg);
),
- TP_printk("%s", __get_str(s))
+ TP_printk("%s", __get_str_strip_nl(s))
);
/* captures pr_debug() callsites */
DEFINE_EVENT(dyndbg_template, prdbg,
TP_PROTO(const struct _ddebug *desc, const struct device *dev,
- const char *msg, size_t len),
+ const char *msg),
- TP_ARGS(desc, dev, msg, len)
+ TP_ARGS(desc, dev, msg)
);
/* captures dev_dbg() callsites */
DEFINE_EVENT(dyndbg_template, devdbg,
TP_PROTO(const struct _ddebug *desc, const struct device *dev,
- const char *msg, size_t len),
+ const char *msg),
- TP_ARGS(desc, dev, msg, len)
+ TP_ARGS(desc, dev, msg)
);
#endif /* _TRACE_DYNDBG_H */
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index fcc7c5631b53..9682277f3909 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -886,7 +886,6 @@ static void ddebug_trace(struct _ddebug *desc, const struct device *dev,
{
struct ddebug_trace_buf *buf;
int bufidx;
- int len;
preempt_disable_notrace();
@@ -900,12 +899,12 @@ static void ddebug_trace(struct _ddebug *desc, const struct device *dev,
buf = this_cpu_ptr(ddebug_trace_bufs.bufs) + bufidx;
- len = vscnprintf(buf->buf, sizeof(buf->buf), fmt, args);
+ vscnprintf(buf->buf, sizeof(buf->buf), fmt, args);
if (!dev)
- trace_prdbg(desc, NULL, buf->buf, len);
+ trace_prdbg(desc, NULL, buf->buf);
else
- trace_devdbg(desc, dev, buf->buf, len);
+ trace_devdbg(desc, dev, buf->buf);
out:
/* As above. */
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
Move the JUMP_LABEL to the top of the struct, since they're both
align(8) and this closes a pahole (unfortunately trading for padding,
but still).
Signed-off-by: Jim Cromie <[email protected]>
---
include/linux/dynamic_debug.h | 12 ++++++------
1 file changed, 6 insertions(+), 6 deletions(-)
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index 497130816e9c..b9237e4ecd1b 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -14,6 +14,12 @@
* the special section is treated as an array of these.
*/
struct _ddebug {
+#ifdef CONFIG_JUMP_LABEL
+ union {
+ struct static_key_true dd_key_true;
+ struct static_key_false dd_key_false;
+ } key;
+#endif
/*
* These fields are used to drive the user interface
* for selecting and displaying debug callsites.
@@ -53,12 +59,6 @@ struct _ddebug {
#define _DPRINTK_FLAGS_DEFAULT 0
#endif
unsigned int flags:8;
-#ifdef CONFIG_JUMP_LABEL
- union {
- struct static_key_true dd_key_true;
- struct static_key_false dd_key_false;
- } key;
-#endif
} __attribute__((aligned(8)));
enum class_map_type {
--
2.43.0.687.g38aa6559b0-goog
Add a new structure ctrl and place it in 4 padding bytes
of _ddebug struct. Move flags field to the ctrl struct
and create setter and getter for the flags field. Add unused
fields to explicitly emphasise size of each bitfield.
This step prepares for addition of a trace_dst field.
Layout of _ddebug struct after addition of ctrl is:
struct _ddebug {
union {
struct static_key_true dd_key_true; /* 0 16 */
struct static_key_false dd_key_false; /* 0 16 */
} key; /* 0 16 */
const char * modname; /* 16 8 */
const char * function; /* 24 8 */
const char * filename; /* 32 8 */
const char * format; /* 40 8 */
unsigned int lineno:18; /* 48: 0 4 */
unsigned int class_id:6; /* 48:18 4 */
unsigned int unused:8; /* 48:24 4 */
struct dd_ctrl ctrl; /* 52 4 */
/* size: 56, cachelines: 1, members: 9 */
/* last cacheline: 56 bytes */
} __attribute__((__aligned__(8)));
Signed-off-by: Łukasz Bartosik <[email protected]>
---
include/linux/dynamic_debug.h | 13 +++++++----
lib/dynamic_debug.c | 44 ++++++++++++++++++++++-------------
2 files changed, 37 insertions(+), 20 deletions(-)
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index b9237e4ecd1b..a551b2967cb8 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -32,6 +32,8 @@ struct _ddebug {
#define CLS_BITS 6
unsigned int class_id:CLS_BITS;
#define _DPRINTK_CLASS_DFLT ((1 << CLS_BITS) - 1)
+ unsigned int unused:8;
+
/*
* The flags field controls the behaviour at the callsite.
* The bits here are changed dynamically when the user
@@ -58,7 +60,10 @@ struct _ddebug {
#else
#define _DPRINTK_FLAGS_DEFAULT 0
#endif
- unsigned int flags:8;
+ struct {
+ unsigned int flags:8;
+ unsigned unused:24;
+ } ctrl;
} __attribute__((aligned(8)));
enum class_map_type {
@@ -171,7 +176,7 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
.filename = __FILE__, \
.format = (fmt), \
.lineno = __LINE__, \
- .flags = _DPRINTK_FLAGS_DEFAULT, \
+ .ctrl = { .flags = _DPRINTK_FLAGS_DEFAULT }, \
.class_id = cls, \
_DPRINTK_KEY_INIT \
}; \
@@ -202,10 +207,10 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
#ifdef DEBUG
#define DYNAMIC_DEBUG_BRANCH(descriptor) \
- likely(descriptor.flags & _DPRINTK_FLAGS_ENABLED)
+ likely(descriptor.ctrl.flags & _DPRINTK_FLAGS_ENABLED)
#else
#define DYNAMIC_DEBUG_BRANCH(descriptor) \
- unlikely(descriptor.flags & _DPRINTK_FLAGS_ENABLED)
+ unlikely(descriptor.ctrl.flags & _DPRINTK_FLAGS_ENABLED)
#endif
#endif /* CONFIG_JUMP_LABEL */
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 9682277f3909..f47cb76e0e3d 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -80,6 +80,16 @@ module_param(verbose, int, 0644);
MODULE_PARM_DESC(verbose, " dynamic_debug/control processing "
"( 0 = off (default), 1 = module add/rm, 2 = >control summary, 3 = parsing, 4 = per-site changes)");
+static inline unsigned int get_flags(const struct _ddebug *desc)
+{
+ return desc->ctrl.flags;
+}
+
+static inline void set_flags(struct _ddebug *desc, unsigned int val)
+{
+ desc->ctrl.flags = val;
+}
+
/* Return the path relative to source root */
static inline const char *trim_prefix(const char *path)
{
@@ -247,11 +257,11 @@ static int ddebug_change(const struct ddebug_query *query,
nfound++;
- newflags = (dp->flags & modifiers->mask) | modifiers->flags;
- if (newflags == dp->flags)
+ newflags = (get_flags(dp) & modifiers->mask) | modifiers->flags;
+ if (newflags == get_flags(dp))
continue;
#ifdef CONFIG_JUMP_LABEL
- if (dp->flags & _DPRINTK_FLAGS_ENABLED) {
+ if (get_flags(dp) & _DPRINTK_FLAGS_ENABLED) {
if (!(newflags & _DPRINTK_FLAGS_ENABLED))
static_branch_disable(&dp->key.dd_key_true);
} else if (newflags & _DPRINTK_FLAGS_ENABLED) {
@@ -261,9 +271,9 @@ static int ddebug_change(const struct ddebug_query *query,
v4pr_info("changed %s:%d [%s]%s %s => %s\n",
trim_prefix(dp->filename), dp->lineno,
dt->mod_name, dp->function,
- ddebug_describe_flags(dp->flags, &fbuf),
+ ddebug_describe_flags(get_flags(dp), &fbuf),
ddebug_describe_flags(newflags, &nbuf));
- dp->flags = newflags;
+ set_flags(dp, newflags);
}
}
mutex_unlock(&ddebug_lock);
@@ -824,10 +834,11 @@ static int remaining(int wrote)
static char *__dynamic_emit_prefix(const struct _ddebug *desc, char *buf)
{
+ unsigned int flags = get_flags(desc);
int pos_after_tid;
int pos = 0;
- if (desc->flags & _DPRINTK_FLAGS_INCL_TID) {
+ if (flags & _DPRINTK_FLAGS_INCL_TID) {
if (in_interrupt())
pos += snprintf(buf + pos, remaining(pos), "<intr> ");
else
@@ -835,16 +846,16 @@ static char *__dynamic_emit_prefix(const struct _ddebug *desc, char *buf)
task_pid_vnr(current));
}
pos_after_tid = pos;
- if (desc->flags & _DPRINTK_FLAGS_INCL_MODNAME)
+ if (flags & _DPRINTK_FLAGS_INCL_MODNAME)
pos += snprintf(buf + pos, remaining(pos), "%s:",
desc->modname);
- if (desc->flags & _DPRINTK_FLAGS_INCL_FUNCNAME)
+ if (flags & _DPRINTK_FLAGS_INCL_FUNCNAME)
pos += snprintf(buf + pos, remaining(pos), "%s:",
desc->function);
- if (desc->flags & _DPRINTK_FLAGS_INCL_SOURCENAME)
+ if (flags & _DPRINTK_FLAGS_INCL_SOURCENAME)
pos += snprintf(buf + pos, remaining(pos), "%s:",
trim_prefix(desc->filename));
- if (desc->flags & _DPRINTK_FLAGS_INCL_LINENO)
+ if (flags & _DPRINTK_FLAGS_INCL_LINENO)
pos += snprintf(buf + pos, remaining(pos), "%d:",
desc->lineno);
if (pos - pos_after_tid)
@@ -857,7 +868,7 @@ static char *__dynamic_emit_prefix(const struct _ddebug *desc, char *buf)
static inline char *dynamic_emit_prefix(struct _ddebug *desc, char *buf)
{
- if (unlikely(desc->flags & _DPRINTK_FLAGS_INCL_ANY))
+ if (unlikely(get_flags(desc) & _DPRINTK_FLAGS_INCL_ANY))
return __dynamic_emit_prefix(desc, buf);
return buf;
}
@@ -916,7 +927,8 @@ static void ddebug_trace(struct _ddebug *desc, const struct device *dev,
__printf(2, 3)
static void ddebug_printk(struct _ddebug *desc, const char *fmt, ...)
{
- if (desc->flags & _DPRINTK_FLAGS_TRACE) {
+
+ if (get_flags(desc) & _DPRINTK_FLAGS_TRACE) {
va_list args;
va_start(args, fmt);
@@ -928,7 +940,7 @@ static void ddebug_printk(struct _ddebug *desc, const char *fmt, ...)
va_end(args);
}
- if (desc->flags & _DPRINTK_FLAGS_PRINTK) {
+ if (get_flags(desc) & _DPRINTK_FLAGS_PRINTK) {
va_list args;
va_start(args, fmt);
@@ -942,7 +954,7 @@ static void ddebug_dev_printk(struct _ddebug *desc, const struct device *dev,
const char *fmt, ...)
{
- if (desc->flags & _DPRINTK_FLAGS_TRACE) {
+ if (get_flags(desc) & _DPRINTK_FLAGS_TRACE) {
va_list args;
va_start(args, fmt);
@@ -950,7 +962,7 @@ static void ddebug_dev_printk(struct _ddebug *desc, const struct device *dev,
va_end(args);
}
- if (desc->flags & _DPRINTK_FLAGS_PRINTK) {
+ if (get_flags(desc) & _DPRINTK_FLAGS_PRINTK) {
va_list args;
va_start(args, fmt);
@@ -1246,7 +1258,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
seq_printf(m, "%s:%u [%s]%s =%s \"",
trim_prefix(dp->filename), dp->lineno,
iter->table->mod_name, dp->function,
- ddebug_describe_flags(dp->flags, &flags));
+ ddebug_describe_flags(get_flags(dp), &flags));
seq_escape_str(m, dp->format, ESCAPE_SPACE, "\t\r\n\"");
seq_puts(m, "\"");
--
2.43.0.687.g38aa6559b0-goog
The trace destination field is used to determine output of debug
logs when +T is set. Setting trace_dst value to 0 enables output
to prdbg and devdbg trace events. Setting trace_dst value to a
value in range of [1..63] enables output to trace instance.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
include/linux/dynamic_debug.h | 13 +++++++++++--
lib/dynamic_debug.c | 28 +++++++++++++++++++---------
2 files changed, 30 insertions(+), 11 deletions(-)
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index a551b2967cb8..dc10c7535f13 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -60,9 +60,18 @@ struct _ddebug {
#else
#define _DPRINTK_FLAGS_DEFAULT 0
#endif
- struct {
+ struct dd_ctrl {
unsigned int flags:8;
- unsigned unused:24;
+ /*
+ * The trace destination field is used to determine output of debug
+ * logs when +T is set. Setting trace_dst value to 0 enables output
+ * to prdbg and devdbg trace events. Setting trace_dst value to a
+ * value in range of [1..63] enables output to trace instance.
+ */
+#define TRACE_DST_BITS 6
+ unsigned int trace_dst:TRACE_DST_BITS;
+#define TRACE_DST_LAST (1 << TRACE_DST_BITS)
+ unsigned unused:18;
} ctrl;
} __attribute__((aligned(8)));
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index f47cb76e0e3d..0dc9ec76b867 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -80,14 +80,24 @@ module_param(verbose, int, 0644);
MODULE_PARM_DESC(verbose, " dynamic_debug/control processing "
"( 0 = off (default), 1 = module add/rm, 2 = >control summary, 3 = parsing, 4 = per-site changes)");
+static inline struct dd_ctrl *get_ctrl(struct _ddebug *desc)
+{
+ return &desc->ctrl;
+}
+
+static inline void set_ctrl(struct _ddebug *desc, struct dd_ctrl *ctrl)
+{
+ desc->ctrl = *ctrl;
+}
+
static inline unsigned int get_flags(const struct _ddebug *desc)
{
return desc->ctrl.flags;
}
-static inline void set_flags(struct _ddebug *desc, unsigned int val)
+static inline unsigned int get_trace_dst(const struct _ddebug *desc)
{
- desc->ctrl.flags = val;
+ return desc->ctrl.trace_dst;
}
/* Return the path relative to source root */
@@ -190,8 +200,8 @@ static int ddebug_change(const struct ddebug_query *query,
{
int i;
struct ddebug_table *dt;
- unsigned int newflags;
unsigned int nfound = 0;
+ struct dd_ctrl nctrl = {0};
struct flagsbuf fbuf, nbuf;
struct ddebug_class_map *map = NULL;
int __outvar valid_class;
@@ -257,14 +267,14 @@ static int ddebug_change(const struct ddebug_query *query,
nfound++;
- newflags = (get_flags(dp) & modifiers->mask) | modifiers->flags;
- if (newflags == get_flags(dp))
+ nctrl.flags = (get_flags(dp) & modifiers->mask) | modifiers->flags;
+ if (!memcmp(&nctrl, get_ctrl(dp), sizeof(struct dd_ctrl)))
continue;
#ifdef CONFIG_JUMP_LABEL
if (get_flags(dp) & _DPRINTK_FLAGS_ENABLED) {
- if (!(newflags & _DPRINTK_FLAGS_ENABLED))
+ if (!(nctrl.flags & _DPRINTK_FLAGS_ENABLED))
static_branch_disable(&dp->key.dd_key_true);
- } else if (newflags & _DPRINTK_FLAGS_ENABLED) {
+ } else if (nctrl.flags & _DPRINTK_FLAGS_ENABLED) {
static_branch_enable(&dp->key.dd_key_true);
}
#endif
@@ -272,8 +282,8 @@ static int ddebug_change(const struct ddebug_query *query,
trim_prefix(dp->filename), dp->lineno,
dt->mod_name, dp->function,
ddebug_describe_flags(get_flags(dp), &fbuf),
- ddebug_describe_flags(newflags, &nbuf));
- set_flags(dp, newflags);
+ ddebug_describe_flags(nctrl.flags, &nbuf));
+ set_ctrl(dp, &nctrl);
}
}
mutex_unlock(&ddebug_lock);
--
2.43.0.687.g38aa6559b0-goog
Add open and close commands for opening and closing trace instances.
The open command has to be mandatory followed by a trace instance name.
If a trace instance already exists in <debugfs>/tracing/instances
directory then the open command will reuse it otherwise a new trace
instance with a name provided to the open will be created. Close
command closes previously opened trace instance. The close will
fail if a user tries to close non-existent trace instances or an
instance which was not previously opened.
For example the following command will open (create or reuse existing)
trace instance located in <debugfs>/tracing/instances/usbcore:
echo "open usbcore" > <debugfs>/dynamic_debug/control
Signed-off-by: Łukasz Bartosik <[email protected]>
---
lib/Kconfig.debug | 2 +
lib/dynamic_debug.c | 194 ++++++++++++++++++++++++++++++++++++++++++++
2 files changed, 196 insertions(+)
diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 975a07f9f1cc..01caf885d86b 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -110,6 +110,7 @@ config DYNAMIC_DEBUG
default n
depends on PRINTK
depends on (DEBUG_FS || PROC_FS)
+ depends on TRACING
select DYNAMIC_DEBUG_CORE
help
@@ -181,6 +182,7 @@ config DYNAMIC_DEBUG_CORE
bool "Enable core function of dynamic debug support"
depends on PRINTK
depends on (DEBUG_FS || PROC_FS)
+ depends on TRACING
help
Enable core functional support of dynamic debug. It is useful
when you want to tie dynamic debug to your kernel modules with
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 0dc9ec76b867..d0d1057911e8 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 <linux/trace.h>
#define CREATE_TRACE_POINTS
#include <trace/events/dyndbg.h>
@@ -73,6 +74,27 @@ struct flag_settings {
unsigned int mask;
};
+#define DD_OPEN_CMD "open"
+#define DD_CLOSE_CMD "close"
+#define DD_TR_EVENT "0"
+
+struct dd_private_tracebuf {
+ const char *name;
+ struct trace_array *arr;
+};
+
+/*
+ * Trace destination value 0 is reserved for writing
+ * debug logs to trace events (prdbg, devdbg), that
+ * is why buf[0] is not used and we traverse bitmap
+ * starting from bit 1 (bit 0 is also not used).
+ */
+struct dd_tracebuf_tbl_info {
+ struct dd_private_tracebuf buf[TRACE_DST_LAST];
+ DECLARE_BITMAP(bmap, TRACE_DST_LAST);
+ int bmap_size;
+};
+
static DEFINE_MUTEX(ddebug_lock);
static LIST_HEAD(ddebug_tables);
static int verbose;
@@ -80,6 +102,9 @@ module_param(verbose, int, 0644);
MODULE_PARM_DESC(verbose, " dynamic_debug/control processing "
"( 0 = off (default), 1 = module add/rm, 2 = >control summary, 3 = parsing, 4 = per-site changes)");
+static struct
+dd_tracebuf_tbl_info trc_tbl = { .bmap_size = TRACE_DST_LAST };
+
static inline struct dd_ctrl *get_ctrl(struct _ddebug *desc)
{
return &desc->ctrl;
@@ -171,6 +196,145 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
query->first_lineno, query->last_lineno, query->class_string);
}
+static bool is_dd_trace_cmd(const char *str)
+{
+ if (!strcmp(str, DD_OPEN_CMD) || !strcmp(str, DD_CLOSE_CMD))
+ return true;
+
+ return false;
+}
+
+static bool dd_good_trace_name(const char *str)
+{
+ /* "0" is reserved for writing debug logs to trace events (prdbg, devdbg) */
+ if (!strcmp(str, DD_TR_EVENT))
+ return false;
+
+ /* we allow trace instance names to include ^\w+ and underscore */
+ while (*str != '\0') {
+ if (!isalnum(*str) && *str != '_')
+ return false;
+ str++;
+ }
+
+ return true;
+}
+
+static int find_tr_instance(const char *name)
+{
+ int idx = 1;
+
+ for_each_set_bit_from(idx, trc_tbl.bmap, trc_tbl.bmap_size)
+ if (!strcmp(trc_tbl.buf[idx].name, name))
+ return idx;
+
+ return -ENOENT;
+}
+
+static int handle_trace_open_cmd(const char *arg)
+{
+ struct dd_private_tracebuf *buf;
+ int idx, ret = 0;
+
+ mutex_lock(&ddebug_lock);
+
+ /* bit 0 is not used, reserved for trace prdbg and devdbg events */
+ idx = find_next_zero_bit(trc_tbl.bmap, trc_tbl.bmap_size, 1);
+ if (idx == trc_tbl.bmap_size) {
+ ret = -ENOSPC;
+ goto end;
+ }
+
+ if (!dd_good_trace_name(arg)) {
+ pr_err("invalid instance name:%s\n", arg);
+ ret = -EINVAL;
+ goto end;
+ }
+
+ if (find_tr_instance(arg) >= 0) {
+ pr_err("instance is already opened name:%s\n", arg);
+ ret = -EEXIST;
+ goto end;
+ }
+
+ buf = &trc_tbl.buf[idx];
+ buf->name = kstrdup(arg, GFP_KERNEL);
+ if (!buf->name) {
+ ret = -ENOMEM;
+ goto end;
+ }
+
+ buf->arr = trace_array_get_by_name(buf->name, NULL);
+ if (!buf->arr) {
+ pr_err("failed to get trace array name:%s", buf->name);
+ ret = -EINVAL;
+ goto end;
+ }
+
+ ret = trace_array_init_printk(buf->arr);
+ if (ret) {
+ pr_err("failed to init trace array name:%s", buf->name);
+ trace_array_put(buf->arr);
+ trace_array_destroy(buf->arr);
+ goto end;
+ }
+
+ set_bit(idx, trc_tbl.bmap);
+ v3pr_info("opened trace instance idx=%d, name=%s\n", idx, arg);
+end:
+ mutex_unlock(&ddebug_lock);
+ return ret;
+}
+
+static int handle_trace_close_cmd(const char *arg)
+{
+ struct dd_private_tracebuf *buf;
+ int idx, ret = 0;
+
+ mutex_lock(&ddebug_lock);
+
+ idx = find_tr_instance(arg);
+ if (idx < 0) {
+ ret = idx;
+ goto end;
+ }
+
+ buf = &trc_tbl.buf[idx];
+
+ trace_array_put(buf->arr);
+ /*
+ * don't destroy trace instance but let user do it manually
+ * with rmdir command at a convenient time later, if it is
+ * destroyed here all debug logs will be lost
+ *
+ * trace_array_destroy(inst->arr);
+ */
+ buf->arr = NULL;
+
+ kfree(buf->name);
+ buf->name = NULL;
+
+ clear_bit(idx, trc_tbl.bmap);
+ v3pr_info("closed trace instance idx=%d, name=%s\n", idx, arg);
+end:
+ mutex_unlock(&ddebug_lock);
+ return ret;
+}
+
+static int ddebug_parse_cmd(char *words[], int nwords)
+{
+ if (nwords != 1)
+ return -EINVAL;
+
+ if (!strcmp(words[0], DD_OPEN_CMD))
+ return handle_trace_open_cmd(words[1]);
+ if (!strcmp(words[0], DD_CLOSE_CMD))
+ return handle_trace_close_cmd(words[1]);
+
+ pr_err("invalid command %s\n", words[0]);
+ return -EINVAL;
+}
+
static struct ddebug_class_map *ddebug_find_valid_class(struct ddebug_table const *dt,
const char *class_string, int *class_id)
{
@@ -567,6 +731,11 @@ static int ddebug_exec_query(char *query_string, const char *modname)
pr_err("tokenize failed\n");
return -EINVAL;
}
+
+ /* check for open, close commands */
+ if (is_dd_trace_cmd(words[0]))
+ return ddebug_parse_cmd(words, nwords-1);
+
/* check flags 1st (last arg) so query is pairs of spec,val */
if (ddebug_parse_flags(words[nwords-1], &modifiers)) {
pr_err("flags parse failed\n");
@@ -1191,6 +1360,20 @@ static struct _ddebug *ddebug_iter_next(struct ddebug_iter *iter)
return &iter->table->ddebugs[iter->idx];
}
+/*
+ * Check if the iterator points to the last _ddebug object
+ * to traverse.
+ */
+static bool ddebug_iter_is_last(struct ddebug_iter *iter)
+{
+ if (iter->table == NULL)
+ return false;
+ if (iter->idx-1 < 0 &&
+ list_is_last(&iter->table->link, &ddebug_tables))
+ return true;
+ return false;
+}
+
/*
* Seq_ops start method. Called at the start of every
* read() call from userspace. Takes the ddebug_lock and
@@ -1281,6 +1464,17 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
}
seq_puts(m, "\n");
+ if (ddebug_iter_is_last(iter) &&
+ !bitmap_empty(trc_tbl.bmap, trc_tbl.bmap_size)) {
+ int idx = 1;
+
+ seq_puts(m, "\n");
+ seq_puts(m, "#: Opened trace instances:");
+ for_each_set_bit_from(idx, trc_tbl.bmap, trc_tbl.bmap_size)
+ seq_printf(m, " %s", trc_tbl.buf[idx].name);
+ seq_puts(m, "\n");
+ }
+
return 0;
}
--
2.43.0.687.g38aa6559b0-goog
Don't allow trace instance to be closed when it
is still being used by at least one callsite.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
lib/dynamic_debug.c | 35 +++++++++++++++++++++++++++++++++++
1 file changed, 35 insertions(+)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index d0d1057911e8..6668f265f2c3 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -81,6 +81,7 @@ struct flag_settings {
struct dd_private_tracebuf {
const char *name;
struct trace_array *arr;
+ int use_cnt;
};
/*
@@ -279,6 +280,7 @@ static int handle_trace_open_cmd(const char *arg)
goto end;
}
+ buf->use_cnt = 0;
set_bit(idx, trc_tbl.bmap);
v3pr_info("opened trace instance idx=%d, name=%s\n", idx, arg);
end:
@@ -301,6 +303,14 @@ static int handle_trace_close_cmd(const char *arg)
buf = &trc_tbl.buf[idx];
+ WARN_ON(buf->use_cnt < 0);
+ if (buf->use_cnt) {
+ pr_err("trace instance is being used name=%s, use_cnt=%d\n",
+ buf->name, buf->use_cnt);
+ ret = -EBUSY;
+ goto end;
+ }
+
trace_array_put(buf->arr);
/*
* don't destroy trace instance but let user do it manually
@@ -321,6 +331,22 @@ static int handle_trace_close_cmd(const char *arg)
return ret;
}
+static
+void update_tr_dst(const struct _ddebug *desc, const struct dd_ctrl *nctrl)
+{
+ int odst = get_trace_dst(desc);
+ int ndst = nctrl->trace_dst;
+
+ if (odst == ndst)
+ return;
+
+ if (odst)
+ trc_tbl.buf[odst].use_cnt--;
+
+ if (ndst)
+ trc_tbl.buf[ndst].use_cnt++;
+}
+
static int ddebug_parse_cmd(char *words[], int nwords)
{
if (nwords != 1)
@@ -447,6 +473,7 @@ static int ddebug_change(const struct ddebug_query *query,
dt->mod_name, dp->function,
ddebug_describe_flags(get_flags(dp), &fbuf),
ddebug_describe_flags(nctrl.flags, &nbuf));
+ update_tr_dst(dp, &nctrl);
set_ctrl(dp, &nctrl);
}
}
@@ -1628,6 +1655,14 @@ int ddebug_dyndbg_module_param_cb(char *param, char *val, const char *module)
static void ddebug_table_free(struct ddebug_table *dt)
{
+ int dst, i;
+
+ for (i = 0; i < dt->num_ddebugs; i++) {
+ dst = get_trace_dst(&dt->ddebugs[i]);
+ if (dst)
+ trc_tbl.buf[dst].use_cnt--;
+ }
+
list_del_init(&dt->link);
kfree(dt);
}
--
2.43.0.687.g38aa6559b0-goog
Add processing to handle the new [+T]:trace_name.flags grammar.
The name provided sets selected callsites' trace-destinations:
"0" - pr_debug()s are written to prdbg and devdbg trace events.
name - pr_debug()s are written to named trace instance,
if its already been open'd, else err.
A user can provide trace destination name by following T flag with
":" and trace destination name, for example:
echo "module thunderbolt =pT:tbt" > <debugfs>/dynamic_debug/control
echo "module thunderbolt =lT:tbt.p" > <debugfs>/dynamic_debug/control
Or user can provide only ":" and trace destination name, for example:
echo "module thunderbolt =p:tbt" > <debugfs>/dynamic_debug/control
echo "module thunderbolt =l:tbt.p" > <debugfs>/dynamic_debug/control
In the former examples trace destination is set (":tbt") and write of
pr_debug()s is enabled ("T"). In the latter examples only trace
destination is set (":tbt") for later use.
When T flag with argument is followed by other flag then the next
flag has to be preceded with ".".
When both T flag and ":" are provided together then ":" has
to follow T flag in the form of "T:".
Use of "." as a separator between flags allows a later patch to treat
',' as a space, which mostly eliminates the need to quote query/rules.
And this in turn avoids quoting hassles:
modprobe test_dynamic_debug dyndbg=class,D2_CORE,+p
It is particularly good for passing boot-args into test-scripts.
vng -p 4 -v \
-a test_dynamic_debug.dyndbg=class,D2_CORE,+p
Signed-off-by: Łukasz Bartosik <[email protected]>
Co-developed-by: Jim Cromie <[email protected]>
Signed-off-by: Jim Cromie <[email protected]>
---
lib/dynamic_debug.c | 201 +++++++++++++++++++++++++++++++++++---------
1 file changed, 162 insertions(+), 39 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 6668f265f2c3..8a81356c52b3 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -72,6 +72,7 @@ struct ddebug_iter {
struct flag_settings {
unsigned int flags;
unsigned int mask;
+ unsigned int trace_dst;
};
#define DD_OPEN_CMD "open"
@@ -84,11 +85,17 @@ struct dd_private_tracebuf {
int use_cnt;
};
+#define DST_NOT_SET (-1)
+
/*
- * Trace destination value 0 is reserved for writing
- * debug logs to trace events (prdbg, devdbg), that
- * is why buf[0] is not used and we traverse bitmap
- * starting from bit 1 (bit 0 is also not used).
+ * When trace is enabled (T flag is set) and trace destination field
+ * value is in range [1..63] then debug logs will be written to trace
+ * instance whose name is stored in buf[trace destination].name, e.g.
+ * when trace destination value is 2 and buf[2].name is set to tbt then
+ * debug logs will be written to <debugfs>/tracing/instances/tbt.
+ * On the other hand trace destination value 0 is reserved for writing
+ * debug logs to trace events (prdbg, devdbg), that is why buf[0] is not
+ * used and we traverse bitmap starting from bit 1 (bit 0 is also not used).
*/
struct dd_tracebuf_tbl_info {
struct dd_private_tracebuf buf[TRACE_DST_LAST];
@@ -126,6 +133,81 @@ static inline unsigned int get_trace_dst(const struct _ddebug *desc)
return desc->ctrl.trace_dst;
}
+static int find_tr_instance(const char *name)
+{
+ int idx = 1;
+
+ for_each_set_bit_from(idx, trc_tbl.bmap, trc_tbl.bmap_size)
+ if (!strcmp(trc_tbl.buf[idx].name, name))
+ return idx;
+
+ return -ENOENT;
+}
+
+static const
+char *read_colon_args(const char *str, struct flag_settings *modifiers)
+{
+ int len, idx = 0;
+ char *end;
+
+ /* Check if trace destination was already set */
+ if (modifiers->trace_dst != DST_NOT_SET)
+ return NULL;
+ /*
+ * When both T flag and ':' are provided then the T flag
+ * has to be followed by ':' in the form of 'T:'.
+ */
+ if (modifiers->flags & _DPRINTK_FLAGS_TRACE &&
+ *(str-1) != 'T')
+ return NULL;
+
+ if (strchr(str, 'T'))
+ return NULL;
+
+ str++;
+ end = strchr(str, '.');
+ if (end) {
+ len = end - str;
+ *end = '\0';
+ } else
+ len = strlen(str);
+ len -= 1;
+
+ /* destination trace events */
+ if (!strcmp(str, DD_TR_EVENT))
+ goto end;
+
+ idx = find_tr_instance(str);
+ if (idx < 0)
+ return NULL;
+end:
+ modifiers->trace_dst = idx;
+ return end ? end : str + len;
+}
+
+/*
+ * Maximum number of characters which are being displayed when
+ * printing trace instance name, longer names are truncated
+ */
+#define FLAG_COLON_ARG_LEN 24
+
+static char *show_colon_args(struct dd_ctrl *ctrl, char *p)
+{
+ int n, len = FLAG_COLON_ARG_LEN;
+ const char *str;
+
+ str = !ctrl->trace_dst ? DD_TR_EVENT :
+ trc_tbl.buf[ctrl->trace_dst].name;
+
+ n = snprintf(p, len, "%s", str);
+ if (n >= len) {
+ strscpy(&p[len-4], "...", 4);
+ n = len - 1;
+ }
+
+ return n < 0 ? p : p + n;
+}
+
/* Return the path relative to source root */
static inline const char *trim_prefix(const char *path)
{
@@ -137,9 +219,28 @@ static inline const char *trim_prefix(const char *path)
return path + skip;
}
-static const struct { unsigned flag:8; char opt_char; } opt_array[] = {
+typedef const char* (*read_flag_args_f)(const char *, struct flag_settings *);
+typedef char* (*show_flag_args_f)(struct dd_ctrl *, char *);
+
+static const struct
+{
+ unsigned flag:8;
+ char opt_char;
+ bool always_show;
+ read_flag_args_f read_args;
+ show_flag_args_f show_args;
+} opt_array[] = {
{ _DPRINTK_FLAGS_PRINTK, 'p' },
{ _DPRINTK_FLAGS_TRACE, 'T' },
+ /*
+ * We don't reserve a flag for ':'. The ':' is used to provide
+ * trace destination name and when provided together with T flag
+ * it enables output to the trace destination. When ':' is provided
+ * without T flag then it sets trace destination for a callsite for
+ * future use. When both T flag and ':'are provided together then
+ * ':' has to follow T flag in the form of 'T:'.
+ */
+ { _DPRINTK_FLAGS_NONE, ':', true, read_colon_args, show_colon_args },
{ _DPRINTK_FLAGS_INCL_MODNAME, 'm' },
{ _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' },
{ _DPRINTK_FLAGS_INCL_SOURCENAME, 's' },
@@ -148,22 +249,31 @@ static const struct { unsigned flag:8; char opt_char; } opt_array[] = {
{ _DPRINTK_FLAGS_NONE, '_' },
};
-struct flagsbuf { char buf[ARRAY_SIZE(opt_array)+1]; };
+struct ctrlbuf { char buf[ARRAY_SIZE(opt_array)+FLAG_COLON_ARG_LEN+1]; };
/* format a string into buf[] which describes the _ddebug's flags */
-static char *ddebug_describe_flags(unsigned int flags, struct flagsbuf *fb)
+static char *ddebug_describe_ctrl(struct dd_ctrl *ctrl, struct ctrlbuf *cb)
{
- char *p = fb->buf;
+ show_flag_args_f show_args = NULL;
+ char *p = cb->buf;
int i;
for (i = 0; i < ARRAY_SIZE(opt_array); ++i)
- if (flags & opt_array[i].flag)
+ if (ctrl->flags & opt_array[i].flag ||
+ opt_array[i].always_show) {
+ if (show_args)
+ *p++ = '.';
*p++ = opt_array[i].opt_char;
- if (p == fb->buf)
+ show_args = opt_array[i].show_args;
+ if (show_args)
+ p = show_args(ctrl, p);
+ }
+
+ if (p == cb->buf)
*p++ = '_';
*p = '\0';
- return fb->buf;
+ return cb->buf;
}
#define vnpr_info(lvl, fmt, ...) \
@@ -221,17 +331,6 @@ static bool dd_good_trace_name(const char *str)
return true;
}
-static int find_tr_instance(const char *name)
-{
- int idx = 1;
-
- for_each_set_bit_from(idx, trc_tbl.bmap, trc_tbl.bmap_size)
- if (!strcmp(trc_tbl.buf[idx].name, name))
- return idx;
-
- return -ENOENT;
-}
-
static int handle_trace_open_cmd(const char *arg)
{
struct dd_private_tracebuf *buf;
@@ -383,7 +482,7 @@ static struct ddebug_class_map *ddebug_find_valid_class(struct ddebug_table cons
* Search the tables for _ddebug's which match the given `query' and
* apply the `flags' and `mask' to them. Returns number of matching
* callsites, normally the same as number of changes. If verbose,
- * logs the changes. Takes ddebug_lock.
+ * logs the changes.
*/
static int ddebug_change(const struct ddebug_query *query,
struct flag_settings *modifiers)
@@ -391,13 +490,12 @@ static int ddebug_change(const struct ddebug_query *query,
int i;
struct ddebug_table *dt;
unsigned int nfound = 0;
+ struct ctrlbuf cbuf, nbuf;
struct dd_ctrl nctrl = {0};
- struct flagsbuf fbuf, nbuf;
struct ddebug_class_map *map = NULL;
int __outvar valid_class;
/* search for matching ddebugs */
- mutex_lock(&ddebug_lock);
list_for_each_entry(dt, &ddebug_tables, link) {
/* match against the module name */
@@ -458,7 +556,8 @@ static int ddebug_change(const struct ddebug_query *query,
nfound++;
nctrl.flags = (get_flags(dp) & modifiers->mask) | modifiers->flags;
- if (!memcmp(&nctrl, get_ctrl(dp), sizeof(struct dd_ctrl)))
+ nctrl.trace_dst = modifiers->trace_dst;
+ if (!memcmp(&nctrl, get_ctrl(dp), sizeof(nctrl)))
continue;
#ifdef CONFIG_JUMP_LABEL
if (get_flags(dp) & _DPRINTK_FLAGS_ENABLED) {
@@ -471,13 +570,12 @@ static int ddebug_change(const struct ddebug_query *query,
v4pr_info("changed %s:%d [%s]%s %s => %s\n",
trim_prefix(dp->filename), dp->lineno,
dt->mod_name, dp->function,
- ddebug_describe_flags(get_flags(dp), &fbuf),
- ddebug_describe_flags(nctrl.flags, &nbuf));
+ ddebug_describe_ctrl(&dp->ctrl, &cbuf),
+ ddebug_describe_ctrl(&nctrl, &nbuf));
update_tr_dst(dp, &nctrl);
set_ctrl(dp, &nctrl);
}
}
- mutex_unlock(&ddebug_lock);
if (!nfound && verbose)
pr_info("no matches for query\n");
@@ -698,6 +796,7 @@ static int ddebug_parse_query(char *words[], int nwords,
*/
static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
{
+ read_flag_args_f read_args;
int op, i;
switch (*str) {
@@ -716,6 +815,12 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
for (i = ARRAY_SIZE(opt_array) - 1; i >= 0; i--) {
if (*str == opt_array[i].opt_char) {
modifiers->flags |= opt_array[i].flag;
+ read_args = opt_array[i].read_args;
+ if (read_args) {
+ str = read_args(str, modifiers);
+ if (!str)
+ return -EINVAL;
+ }
break;
}
}
@@ -724,7 +829,7 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
return -EINVAL;
}
}
- v3pr_info("flags=0x%x\n", modifiers->flags);
+ v3pr_info("flags=0x%x, trace_dest=0x%x\n", modifiers->flags, modifiers->trace_dst);
/* calculate final flags, mask based upon op */
switch (op) {
@@ -747,7 +852,7 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
static int ddebug_exec_query(char *query_string, const char *modname)
{
- struct flag_settings modifiers = {};
+ struct flag_settings modifiers = { .trace_dst = DST_NOT_SET };
struct ddebug_query query = {};
#define MAXWORDS 9
int nwords, nfound;
@@ -763,20 +868,38 @@ static int ddebug_exec_query(char *query_string, const char *modname)
if (is_dd_trace_cmd(words[0]))
return ddebug_parse_cmd(words, nwords-1);
- /* check flags 1st (last arg) so query is pairs of spec,val */
- if (ddebug_parse_flags(words[nwords-1], &modifiers)) {
- pr_err("flags parse failed\n");
- return -EINVAL;
- }
if (ddebug_parse_query(words, nwords-1, &query, modname)) {
pr_err("query parse failed\n");
return -EINVAL;
}
+
+ /*
+ * Both ddebug_parse_flags and ddebug_change have to be run
+ * with locking because ddebug_parse_flags->read_T_args verifies
+ * if a requested trace instance is opened. Next ddebug_change
+ * sets the requested trace instance as output for debug logs of
+ * callsite(s) which matched a query. Because ddebug_proc_write
+ * function can be called concurrently then without locking we
+ * could for example run into a scenario where ddebug_change uses
+ * a trace instance which is already closed.
+ */
+ mutex_lock(&ddebug_lock);
+
+ /* check flags 1st (last arg) so query is pairs of spec,val */
+ if (ddebug_parse_flags(words[nwords-1], &modifiers)) {
+ pr_err("flags parse failed\n");
+ goto err;
+ }
+
/* actually go and implement the change */
nfound = ddebug_change(&query, &modifiers);
- vpr_info_dq(&query, nfound ? "applied" : "no-match");
+ mutex_unlock(&ddebug_lock);
+ vpr_info_dq(&query, nfound ? "applied" : "no-match");
return nfound;
+err:
+ mutex_unlock(&ddebug_lock);
+ return -EINVAL;
}
/* handle multiple queries in query string, continue on error, return
@@ -1466,7 +1589,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
{
struct ddebug_iter *iter = m->private;
struct _ddebug *dp = p;
- struct flagsbuf flags;
+ struct ctrlbuf cbuf;
char const *class;
if (p == SEQ_START_TOKEN) {
@@ -1478,7 +1601,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
seq_printf(m, "%s:%u [%s]%s =%s \"",
trim_prefix(dp->filename), dp->lineno,
iter->table->mod_name, dp->function,
- ddebug_describe_flags(get_flags(dp), &flags));
+ ddebug_describe_ctrl(&dp->ctrl, &cbuf));
seq_escape_str(m, dp->format, ESCAPE_SPACE, "\t\r\n\"");
seq_puts(m, "\"");
--
2.43.0.687.g38aa6559b0-goog
Instead of repeating trace destination name explicitly for each
command (e.g. +T:thunderbolt), this change saves trace destination
provided to last successful open command as default and consecutive
commands which don't provide trace destination explicitly will use
the saved trace destination.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
lib/dynamic_debug.c | 69 ++++++++++++++++++++++++++++++++++++---------
1 file changed, 55 insertions(+), 14 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 8a81356c52b3..f41b0b0c8b47 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -72,7 +72,7 @@ struct ddebug_iter {
struct flag_settings {
unsigned int flags;
unsigned int mask;
- unsigned int trace_dst;
+ int trace_dst;
};
#define DD_OPEN_CMD "open"
@@ -85,8 +85,6 @@ struct dd_private_tracebuf {
int use_cnt;
};
-#define DST_NOT_SET (-1)
-
/*
* When trace is enabled (T flag is set) and trace destination field
* value is in range [1..63] then debug logs will be written to trace
@@ -101,6 +99,9 @@ struct dd_tracebuf_tbl_info {
struct dd_private_tracebuf buf[TRACE_DST_LAST];
DECLARE_BITMAP(bmap, TRACE_DST_LAST);
int bmap_size;
+#define DST_NOT_SET (-1)
+#define DST_TR_EVENT 0
+ int default_dst;
};
static DEFINE_MUTEX(ddebug_lock);
@@ -111,7 +112,8 @@ MODULE_PARM_DESC(verbose, " dynamic_debug/control processing "
"( 0 = off (default), 1 = module add/rm, 2 = >control summary, 3 = parsing, 4 = per-site changes)");
static struct
-dd_tracebuf_tbl_info trc_tbl = { .bmap_size = TRACE_DST_LAST };
+dd_tracebuf_tbl_info trc_tbl = { .bmap_size = TRACE_DST_LAST,
+ .default_dst = DST_TR_EVENT, };
static inline struct dd_ctrl *get_ctrl(struct _ddebug *desc)
{
@@ -147,7 +149,7 @@ static int find_tr_instance(const char *name)
static const
char *read_colon_args(const char *str, struct flag_settings *modifiers)
{
- int len, idx = 0;
+ int len, idx = DST_TR_EVENT;
char *end;
/* Check if trace destination was already set */
@@ -331,6 +333,24 @@ static bool dd_good_trace_name(const char *str)
return true;
}
+static const char *get_tr_default_dst_str(void)
+{
+ if (trc_tbl.default_dst == DST_TR_EVENT)
+ return DD_TR_EVENT;
+ else
+ return trc_tbl.buf[trc_tbl.default_dst].name;
+}
+
+static void update_tr_default_dst(int trace_dst)
+{
+ if (trace_dst == trc_tbl.default_dst)
+ return;
+
+ trc_tbl.default_dst = trace_dst;
+ v3pr_info("set default trace dst to idx=%d, name=%s\n", trace_dst,
+ get_tr_default_dst_str());
+}
+
static int handle_trace_open_cmd(const char *arg)
{
struct dd_private_tracebuf *buf;
@@ -382,6 +402,7 @@ static int handle_trace_open_cmd(const char *arg)
buf->use_cnt = 0;
set_bit(idx, trc_tbl.bmap);
v3pr_info("opened trace instance idx=%d, name=%s\n", idx, arg);
+ update_tr_default_dst(idx);
end:
mutex_unlock(&ddebug_lock);
return ret;
@@ -410,6 +431,13 @@ static int handle_trace_close_cmd(const char *arg)
goto end;
}
+ /*
+ * check if default trace instance is being closed,
+ * if yes then update default destination to '0'
+ */
+ if (trc_tbl.default_dst == idx)
+ trc_tbl.default_dst = DST_TR_EVENT;
+
trace_array_put(buf->arr);
/*
* don't destroy trace instance but let user do it manually
@@ -556,7 +584,8 @@ static int ddebug_change(const struct ddebug_query *query,
nfound++;
nctrl.flags = (get_flags(dp) & modifiers->mask) | modifiers->flags;
- nctrl.trace_dst = modifiers->trace_dst;
+ nctrl.trace_dst = modifiers->trace_dst == DST_NOT_SET ?
+ get_trace_dst(dp) : modifiers->trace_dst;
if (!memcmp(&nctrl, get_ctrl(dp), sizeof(nctrl)))
continue;
#ifdef CONFIG_JUMP_LABEL
@@ -845,7 +874,13 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
modifiers->flags = 0;
break;
}
- v3pr_info("*flagsp=0x%x *maskp=0x%x\n", modifiers->flags, modifiers->mask);
+
+ if (modifiers->flags & _DPRINTK_FLAGS_TRACE &&
+ modifiers->trace_dst == DST_NOT_SET)
+ modifiers->trace_dst = trc_tbl.default_dst;
+
+ v3pr_info("flags=0x%x mask=0x%x, trace_dest=0x%x\n",
+ modifiers->flags, modifiers->mask, modifiers->trace_dst);
return 0;
}
@@ -1614,15 +1649,21 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
}
seq_puts(m, "\n");
- if (ddebug_iter_is_last(iter) &&
- !bitmap_empty(trc_tbl.bmap, trc_tbl.bmap_size)) {
- int idx = 1;
+ if (ddebug_iter_is_last(iter)) {
seq_puts(m, "\n");
- seq_puts(m, "#: Opened trace instances:");
- for_each_set_bit_from(idx, trc_tbl.bmap, trc_tbl.bmap_size)
- seq_printf(m, " %s", trc_tbl.buf[idx].name);
- seq_puts(m, "\n");
+ seq_printf(m, "#: Default trace destination: %s\n",
+ get_tr_default_dst_str());
+
+ if (!bitmap_empty(trc_tbl.bmap, trc_tbl.bmap_size)) {
+ int idx = 1;
+
+ seq_puts(m, "\n");
+ seq_puts(m, "#: Opened trace instances:");
+ for_each_set_bit_from(idx, trc_tbl.bmap, trc_tbl.bmap_size)
+ seq_printf(m, " %s", trc_tbl.buf[idx].name);
+ seq_puts(m, "\n");
+ }
}
return 0;
--
2.43.0.687.g38aa6559b0-goog
The change updates default trace destination when a user requests
to open '0' ('0' writes debug logs to global trace-events buffer
/sys/kernel/tracing/trace) or open an already opened trace instance.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
lib/dynamic_debug.c | 20 +++++++++++++-------
1 file changed, 13 insertions(+), 7 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index f41b0b0c8b47..f91c51234456 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -354,10 +354,21 @@ static void update_tr_default_dst(int trace_dst)
static int handle_trace_open_cmd(const char *arg)
{
struct dd_private_tracebuf *buf;
- int idx, ret = 0;
+ int idx = 0, ret = 0;
mutex_lock(&ddebug_lock);
+ /*
+ * request to open '0' or an already opened trace instance
+ * results in update of default trace destination
+ */
+ if (!strcmp(arg, DD_TR_EVENT))
+ goto update;
+
+ idx = find_tr_instance(arg);
+ if (idx >= 0)
+ goto update;
+
/* bit 0 is not used, reserved for trace prdbg and devdbg events */
idx = find_next_zero_bit(trc_tbl.bmap, trc_tbl.bmap_size, 1);
if (idx == trc_tbl.bmap_size) {
@@ -371,12 +382,6 @@ static int handle_trace_open_cmd(const char *arg)
goto end;
}
- if (find_tr_instance(arg) >= 0) {
- pr_err("instance is already opened name:%s\n", arg);
- ret = -EEXIST;
- goto end;
- }
-
buf = &trc_tbl.buf[idx];
buf->name = kstrdup(arg, GFP_KERNEL);
if (!buf->name) {
@@ -402,6 +407,7 @@ static int handle_trace_open_cmd(const char *arg)
buf->use_cnt = 0;
set_bit(idx, trc_tbl.bmap);
v3pr_info("opened trace instance idx=%d, name=%s\n", idx, arg);
+update:
update_tr_default_dst(idx);
end:
mutex_unlock(&ddebug_lock);
--
2.43.0.687.g38aa6559b0-goog
If callsite's current trace destination is '0' and user provided T flag
without trace destination name then set callsite's trace destination to
default trace destination. If a user provided trace destination name
:trace_dest_name with or without T flag then set callsite's trace
destination to the provided name. Otherwise keep callsite's current
trace destination.
The change main purpose is to preserve trace destination names (different
from '0') set previously by a user which can be later enabled with
'label' keyword.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
lib/dynamic_debug.c | 28 ++++++++++++++++++++++------
1 file changed, 22 insertions(+), 6 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index f91c51234456..172497954e00 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -480,6 +480,27 @@ void update_tr_dst(const struct _ddebug *desc, const struct dd_ctrl *nctrl)
trc_tbl.buf[ndst].use_cnt++;
}
+
+/*
+ * Selects trace destination. If callsite's current trace destination is '0'
+ * and user provided T flag without trace destination name then set callsite's
+ * trace destination to default trace destination. If a user provided trace
+ * destination name :trace_dest_name with or without T flag then set callsite's
+ * trace destination to the provided name. Otherwise keep callsite's current
+ * trace destination.
+ */
+static int select_tr_dst(struct flag_settings *modifiers, int cur_dst)
+{
+ if (!cur_dst && modifiers->flags & _DPRINTK_FLAGS_TRACE &&
+ modifiers->trace_dst == DST_NOT_SET)
+ return trc_tbl.default_dst;
+
+ if (modifiers->trace_dst >= 0)
+ return modifiers->trace_dst;
+
+ return cur_dst;
+}
+
static int ddebug_parse_cmd(char *words[], int nwords)
{
if (nwords != 1)
@@ -590,8 +611,7 @@ static int ddebug_change(const struct ddebug_query *query,
nfound++;
nctrl.flags = (get_flags(dp) & modifiers->mask) | modifiers->flags;
- nctrl.trace_dst = modifiers->trace_dst == DST_NOT_SET ?
- get_trace_dst(dp) : modifiers->trace_dst;
+ nctrl.trace_dst = select_tr_dst(modifiers, get_trace_dst(dp));
if (!memcmp(&nctrl, get_ctrl(dp), sizeof(nctrl)))
continue;
#ifdef CONFIG_JUMP_LABEL
@@ -881,10 +901,6 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
break;
}
- if (modifiers->flags & _DPRINTK_FLAGS_TRACE &&
- modifiers->trace_dst == DST_NOT_SET)
- modifiers->trace_dst = trc_tbl.default_dst;
-
v3pr_info("flags=0x%x mask=0x%x, trace_dest=0x%x\n",
modifiers->flags, modifiers->mask, modifiers->trace_dst);
--
2.43.0.687.g38aa6559b0-goog
When trace is enabled (T flag is set) and trace destination
field value is in range [1..63] (value 0 is reserved for
writing debug logs to trace prdbg and devdbg events) then
debug logs will be written to trace instance whose name is
stored in buf[trace destination].name, e.g. when trace
destination value is 2 and buf[2].name is set to tbt then
debug logs will be written to <debugfs>/tracing/instances/tbt.
Before using trace instance as a destination for writing debug
logs it has to be explicitly opened with open command.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
lib/dynamic_debug.c | 28 ++++++++++++++++++++++++----
1 file changed, 24 insertions(+), 4 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 172497954e00..d379e05837be 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -1278,8 +1278,8 @@ static DEFINE_PER_CPU(struct ddebug_trace_bufs, ddebug_trace_bufs);
static DEFINE_PER_CPU(int, ddebug_trace_reserve);
__printf(3, 0)
-static void ddebug_trace(struct _ddebug *desc, const struct device *dev,
- const char *fmt, va_list args)
+static void ddebug_trace_event(struct _ddebug *desc, const struct device *dev,
+ const char *fmt, va_list args)
{
struct ddebug_trace_buf *buf;
int bufidx;
@@ -1310,6 +1310,18 @@ static void ddebug_trace(struct _ddebug *desc, const struct device *dev,
preempt_enable_notrace();
}
+__printf(2, 0)
+static void ddebug_trace_instance(struct _ddebug *desc, const char *fmt,
+ va_list * args)
+{
+ struct va_format vaf = { .fmt = fmt, .va = args};
+ struct trace_array *arr = trc_tbl.buf[get_trace_dst(desc)].arr;
+
+ WARN_ON_ONCE(!arr);
+
+ trace_array_printk(arr, 0, "%pV", &vaf);
+}
+
__printf(2, 3)
static void ddebug_printk(struct _ddebug *desc, const char *fmt, ...)
{
@@ -1322,7 +1334,12 @@ static void ddebug_printk(struct _ddebug *desc, const char *fmt, ...)
* All callers include the KERN_DEBUG prefix to keep the
* vprintk case simple; strip it out for tracing.
*/
- ddebug_trace(desc, NULL, fmt + strlen(KERN_DEBUG), args);
+ if (!get_trace_dst(desc))
+ ddebug_trace_event(desc, NULL,
+ fmt + strlen(KERN_DEBUG), args);
+ else
+ ddebug_trace_instance(desc, fmt + strlen(KERN_DEBUG),
+ &args);
va_end(args);
}
@@ -1344,7 +1361,10 @@ static void ddebug_dev_printk(struct _ddebug *desc, const struct device *dev,
va_list args;
va_start(args, fmt);
- ddebug_trace(desc, dev, fmt, args);
+ if (!get_trace_dst(desc))
+ ddebug_trace_event(desc, dev, fmt, args);
+ else
+ ddebug_trace_instance(desc, fmt, &args);
va_end(args);
}
--
2.43.0.687.g38aa6559b0-goog
Add support for writing hex_dump debug logs to trace.
Signed-off-by: Łukasz Bartosik <[email protected]>
Co-developed-by: Jim Cromie <[email protected]>
Signed-off-by: Jim Cromie <[email protected]>
---
include/linux/dynamic_debug.h | 16 ++++++++++------
lib/dynamic_debug.c | 36 +++++++++++++++++++++++++++++++++++
2 files changed, 46 insertions(+), 6 deletions(-)
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index dc10c7535f13..76eec3f05be9 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -298,12 +298,16 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
_dynamic_func_call(fmt, __dynamic_ibdev_dbg, \
dev, fmt, ##__VA_ARGS__)
-#define dynamic_hex_dump(prefix_str, prefix_type, rowsize, \
- groupsize, buf, len, ascii) \
- _dynamic_func_call_no_desc(__builtin_constant_p(prefix_str) ? prefix_str : "hexdump", \
- print_hex_dump, \
- KERN_DEBUG, prefix_str, prefix_type, \
- rowsize, groupsize, buf, len, ascii)
+void _print_hex_dump(struct _ddebug *descriptor, const char *level,
+ const char *prefix_str, int prefix_type, int rowsize,
+ int groupsize, const void *buf, size_t len, bool ascii);
+
+#define dynamic_hex_dump(prefix_str, prefix_type, rowsize, \
+ groupsize, buf, len, ascii) \
+ _dynamic_func_call(__builtin_constant_p(prefix_str) ? prefix_str : "hexdump", \
+ _print_hex_dump, \
+ KERN_DEBUG, prefix_str, prefix_type, \
+ rowsize, groupsize, buf, len, ascii)
/* for test only, generally expect drm.debug style macro wrappers */
#define __pr_debug_cls(cls, fmt, ...) do { \
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index d379e05837be..dbae1ed6ab5b 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -1377,6 +1377,42 @@ static void ddebug_dev_printk(struct _ddebug *desc, const struct device *dev,
}
}
+void _print_hex_dump(struct _ddebug *descriptor, const char *level,
+ const char *prefix_str, int prefix_type, int rowsize,
+ int groupsize, const void *buf, size_t len, bool ascii)
+{
+ const u8 *ptr = buf;
+ int i, linelen, remaining = len;
+ unsigned char linebuf[32 * 3 + 2 + 32 + 1];
+
+ if (rowsize != 16 && rowsize != 32)
+ rowsize = 16;
+
+ for (i = 0; i < len; i += rowsize) {
+ linelen = min(remaining, rowsize);
+ remaining -= rowsize;
+
+ hex_dump_to_buffer(ptr + i, linelen, rowsize, groupsize,
+ linebuf, sizeof(linebuf), ascii);
+
+ switch (prefix_type) {
+ case DUMP_PREFIX_ADDRESS:
+ ddebug_printk(descriptor, KERN_DEBUG "%s%s%p: %s\n",
+ level, prefix_str, ptr + i, linebuf);
+ break;
+ case DUMP_PREFIX_OFFSET:
+ ddebug_printk(descriptor, KERN_DEBUG "%s%s%.8x: %s\n",
+ level, prefix_str, i, linebuf);
+ break;
+ default:
+ ddebug_printk(descriptor, KERN_DEBUG "%s%s%s\n",
+ level, prefix_str, linebuf);
+ break;
+ }
+ }
+}
+EXPORT_SYMBOL(_print_hex_dump);
+
void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
{
va_list args;
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
Add a new user_label field to struct ddebug_query, label keyword
handling and saving to the struct, and update ddebug_change to test if
a given user_label is found in the list of known trace-instances.
Signed-off-by: Jim Cromie <[email protected]>
---
lib/dynamic_debug.c | 20 ++++++++++++++++++--
1 file changed, 18 insertions(+), 2 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index dbae1ed6ab5b..17df4bf6863a 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -61,6 +61,7 @@ struct ddebug_query {
const char *function;
const char *format;
const char *class_string;
+ const char *user_label;
unsigned int first_lineno, last_lineno;
};
@@ -300,13 +301,14 @@ 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 class=%s\n",
+ v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u class=%s label=%s\n",
msg,
query->function ?: "",
query->filename ?: "",
query->module ?: "",
fmtlen, query->format ?: "",
- query->first_lineno, query->last_lineno, query->class_string);
+ query->first_lineno, query->last_lineno,
+ query->class_string, query->user_label);
}
static bool is_dd_trace_cmd(const char *str)
@@ -574,6 +576,16 @@ static int ddebug_change(const struct ddebug_query *query,
if (dp->class_id != valid_class)
continue;
+ /* match against a given label */
+ if (query->user_label) {
+ int idx = find_tr_instance(query->user_label);
+
+ if (idx < 0)
+ continue;
+ if (idx != get_trace_dst(dp))
+ continue;
+ }
+
/* match against the source filename */
if (query->filename &&
!match_wildcard(query->filename, dp->filename) &&
@@ -770,6 +782,8 @@ static int check_set(const char **dest, char *src, char *name)
* file <full-pathname>
* file <base-filename>
* module <module-name>
+ * class <class_name>
+ * label <user_label>
* format <escaped-string-to-find-in-format>
* line <lineno>
* line <first-lineno>-<last-lineno> // where either may be empty
@@ -825,6 +839,8 @@ static int ddebug_parse_query(char *words[], int nwords,
return -EINVAL;
} else if (!strcmp(keyword, "class")) {
rc = check_set(&query->class_string, arg, "class");
+ } else if (!strcmp(keyword, "label")) {
+ rc = check_set(&query->user_label, arg, "label");
} else {
pr_err("unknown keyword \"%s\"\n", keyword);
return -EINVAL;
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
Since [1,2], ``cat control`` has displayed callsites without flags as
``=_``, to positively assert that no flags are set.
It also took that as input, and the docs also tried to encourage its
use, allowing users to expressly assert that all flags are unset by
this operation:
alias ddcmd='echo $* > /proc/dynamic_debug/control'
ddcmd =_ # assert no-flags
ddcmd = # allowed, grandfathered
Now, warn on the latter. This allows to disambiguate the meaning of
the :<label> extension:
ddcmd = # if this is dis-allowed,
ddcmd =_ # then this is required to unset all
This positive assertion *allows* the grammar to specify both/either
flags and a :<label> independently and unambiguously:
ddcmd =_:foo # unset all flags, set the foo label
ddcmd =:foo # (only) set the foo label, since no flags are given.
The semantics of setting a label: callsite.dest=map[N], differ
slightly from setting the boolean flags; both ``+=`` op-flags set a
label.
And then the meaning of ``-:foo`` can be decided; either dest=0, or
dest=map[N] (just like ``+=``). I prefer latter, since former can be
seen as turning off only foo, which is the label keyword's job.
Signed-off-by: Jim Cromie <[email protected]>
---
lib/dynamic_debug.c | 6 +++++-
1 file changed, 5 insertions(+), 1 deletion(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index d8cd40faeb4d..3a9dd73357c8 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -884,6 +884,7 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
{
read_flag_args_f read_args;
int op, i;
+ char *fst;
switch (*str) {
case '+':
@@ -896,7 +897,7 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
return -EINVAL;
}
- for (; *str ; ++str) {
+ for (fst = (char *)str; *str ; ++str, fst++) {
for (i = ARRAY_SIZE(opt_array) - 1; i >= 0; i--) {
if (*str == opt_array[i].opt_char) {
modifiers->flags |= opt_array[i].flag;
@@ -917,6 +918,9 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
return -EINVAL;
}
}
+ /* warn if no flags/labels are given */
+ if (!(str - fst))
+ pr_err("no flags or label is specified, please use _ to assert no-flags\n");
/* calculate final flags, mask based upon op */
switch (op) {
--
2.43.0.687.g38aa6559b0-goog
Previously the following commands were equivalent
ddcmd =_:foo
ddcmd =:foo
and both unset all flags and set foo label.
This patch modifies the behavior of the command
ddcmd =:foo
to set (only) the foo label and preserve the flags.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
lib/dynamic_debug.c | 9 +++++++++
1 file changed, 9 insertions(+)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 3a9dd73357c8..7723bb7dfc46 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -882,6 +882,7 @@ static int ddebug_parse_query(char *words[], int nwords,
*/
static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
{
+ bool explicit_no_flags = !strchr(str, '_') ? false : true;
read_flag_args_f read_args;
int op, i;
char *fst;
@@ -927,6 +928,14 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
case '=':
/* modifiers->flags already set */
modifiers->mask = 0;
+
+ /*
+ * cover the case where "ddcmd =:foo" sets (only)
+ * the foo label, since no flags are given
+ */
+ if (!explicit_no_flags && !modifiers->flags &&
+ modifiers->trace_dst != DST_NOT_SET)
+ modifiers->mask = ~0U;
break;
case '+':
modifiers->mask = ~0U;
--
2.43.0.687.g38aa6559b0-goog
When a callsite's trace destination is set to "0"
(default after boot) then don't show this trace
destination in /proc/dynamic_debug/control.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
lib/dynamic_debug.c | 20 ++++++++++++++++----
1 file changed, 16 insertions(+), 4 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 7723bb7dfc46..d6d797830be4 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -188,6 +188,12 @@ char *read_colon_args(const char *str, struct flag_settings *modifiers)
return end ? end : str + len;
}
+static bool is_colon_show_args(struct dd_ctrl *ctrl)
+{
+ /* don't show trace destination when it is set to default "0" */
+ return ctrl->trace_dst;
+}
+
/*
* Maximum number of characters which are being displayed when
* printing trace instance name, longer names are truncated
@@ -223,14 +229,15 @@ static inline const char *trim_prefix(const char *path)
}
typedef const char* (*read_flag_args_f)(const char *, struct flag_settings *);
+typedef bool (*is_show_args_f)(struct dd_ctrl *);
typedef char* (*show_flag_args_f)(struct dd_ctrl *, char *);
static const struct
{
unsigned flag:8;
char opt_char;
- bool always_show;
read_flag_args_f read_args;
+ is_show_args_f is_show_args;
show_flag_args_f show_args;
} opt_array[] = {
{ _DPRINTK_FLAGS_PRINTK, 'p' },
@@ -243,7 +250,8 @@ static const struct
* future use. When both T flag and ':'are provided together then
* ':' has to follow T flag in the form of 'T:'.
*/
- { _DPRINTK_FLAGS_NONE, ':', true, read_colon_args, show_colon_args },
+ { _DPRINTK_FLAGS_NONE, ':', read_colon_args, is_colon_show_args,
+ show_colon_args },
{ _DPRINTK_FLAGS_INCL_MODNAME, 'm' },
{ _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' },
{ _DPRINTK_FLAGS_INCL_SOURCENAME, 's' },
@@ -258,12 +266,15 @@ struct ctrlbuf { char buf[ARRAY_SIZE(opt_array)+FLAG_COLON_ARG_LEN+1]; };
static char *ddebug_describe_ctrl(struct dd_ctrl *ctrl, struct ctrlbuf *cb)
{
show_flag_args_f show_args = NULL;
+ is_show_args_f is_show_args;
char *p = cb->buf;
int i;
- for (i = 0; i < ARRAY_SIZE(opt_array); ++i)
+ for (i = 0; i < ARRAY_SIZE(opt_array); ++i) {
+ is_show_args = opt_array[i].is_show_args;
+
if (ctrl->flags & opt_array[i].flag ||
- opt_array[i].always_show) {
+ (is_show_args && is_show_args(ctrl))) {
if (show_args)
*p++ = '.';
*p++ = opt_array[i].opt_char;
@@ -271,6 +282,7 @@ static char *ddebug_describe_ctrl(struct dd_ctrl *ctrl, struct ctrlbuf *cb)
if (show_args)
p = show_args(ctrl, p);
}
+ }
if (p == cb->buf)
*p++ = '_';
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
The recent change to do whole-buf search (not just single line) had
the side-effect of printing too much $output, which hides the
information in clutter. Print the search pattern instead.
Also add -v last arg handling, like in check_match_ct(). This lets a
single caller enable verbose output, to see the trace-bufs content.
Signed-off-by: Jim Cromie <[email protected]>
---
tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh | 6 ++++--
1 file changed, 4 insertions(+), 2 deletions(-)
diff --git a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
index a48cb57aa5cb..d1f447eef4c0 100755
--- a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
+++ b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
@@ -159,6 +159,7 @@ function search_trace() {
# $1 - trace instance name, 0 for global event trace
# $2 - line number counting from the bottom
# $3 - text to search for
+# $4 - optional -v to see verbose results
function search_trace_name() {
if [ "$1" = "0" ]; then
buf=$(cat /sys/kernel/debug/tracing/trace)
@@ -179,8 +180,9 @@ function search_trace_name() {
in line '$line' or '$buf'"
exit
fi
- if [ $v_search_trace = 1 ]; then
- echo -e "${MAGENTA}: search_trace_name in $1 found: \n$output \nin:${BLUE} $buf ${NC}"
+ if [[ "$4" == "-v" || "$v_search_trace" = 1 ]]; then
+ echo -e "${MAGENTA}: search_trace_name in $1 found: \n${YELLOW}$3 \
+ \nin:${BLUE} $buf ${NC}"
fi
}
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
Test the use of the label keyword by selecting, labelling, and
re-labelling a handful of prdbgs:
4 in module/params.c -> param_log
these are labelled and enabled prior to modprobe test_dynamic_debug
trace output to the instance is verified
4 in test-dynamic-debug -> param_log also
2 class'd, 2 un-class'd
After modprobe, all param_log labels are relabelled to new_out, then
doprints reruns the prdbgs, generating new trace output to the new_out
instance.
Signed-off-by: Jim Cromie <[email protected]>
---
.../dynamic_debug/dyndbg_selftest.sh | 65 +++++++++++++++++++
1 file changed, 65 insertions(+)
diff --git a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
index ae386e4de6a4..c6d428a58889 100755
--- a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
+++ b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
@@ -859,6 +859,69 @@ function setup_env_for_tests {
echo
}
+function test_labelling {
+ echo -e "${GREEN}# TEST_SITE_LABELLING - ${NC}"
+ ifrmmod test_dynamic_debug
+ ddcmd =_
+
+ # trace params processing of the modprobe
+ ddcmd open,param_log%module,params,+T:param_log.tmfs
+ check_match_ct =T:param_log 4 -r -v
+
+ # modprobe with params. This uses the default_dest :param_log
+ modprobe test_dynamic_debug \
+ dyndbg=class,D2_CORE,+Tmf%class,D2_KMS,+Tmf%class,D2_ATOMIC,+pmT
+
+ # check the trace for params processing during modprobe, with the expected prefixes
+ search_trace_name param_log 5 "params:parse_args:kernel/params.c: doing test_dynamic_debug"
+ search_trace_name param_log 4 "params:parse_one:kernel/params.c: doing test_dynamic_debug"
+
+ # and for the enabled test-module's pr-debugs
+ search_trace_name param_log 3 "test_dynamic_debug:do_cats: test_dd: D2_CORE msg"
+ search_trace_name param_log 2 "test_dynamic_debug:do_cats: test_dd: D2_KMS msg"
+ search_trace_name param_log 1 "test_dynamic_debug: test_dd: D2_ATOMIC msg"
+
+ # now change the labelled sites, by using the existing label
+ ddcmd open new_out
+ ddcmd label param_log +T:new_out # redirect unclassed
+ check_match_ct =T:new_out 4 -r # the module params prdbgs got moved
+ check_match_ct =T:param_log 2 -r # CORE, KMS remain
+ ddcmd label param_log class D2_CORE +T:new_out # must name class to change it
+ ddcmd label param_log class D2_KMS +T:new_out # case for class D2_* (wildcard) ??
+ check_match_ct =T:param_log 0
+ check_match_ct =T:new_out 6 -r # all are redirected
+ check_match_ct =T:new_out.mfst 4 # module/params.c prdbgs still have the flags
+
+ doprints
+ search_trace_name new_out 2 "test_dynamic_debug:do_cats: test_dd: D2_CORE msg"
+ search_trace_name new_out 1 "test_dynamic_debug:do_cats: test_dd: D2_KMS msg"
+
+ check_match_ct =T.new_out 6 -r -v
+ check_match_ct =T: 6 -r -v
+
+ # its not enough to turn off T
+ ddcmd -T
+ ddcmd class D2_CORE -T % class D2_KMS -T
+ check_match_ct =T 0
+ check_match_ct =:new_out 6 -r -v
+
+ # must un-label prdbgs to close the label
+ ddcmd label new_out +:0
+ ddcmd label new_out class D2_CORE +:0
+ ddcmd label new_out class D2_KMS +:0
+ ddcmd close new_out
+
+ check_match_ct =T:param_log 0 # ok, but
+ check_match_ct :param_log 1 -r -v # pick up the D2_ATOMIC
+ ddcmd label param_log class D2_ATOMIC +:0
+ ddcmd close param_log # now it closes wo -EBUSY
+
+ ifrmmod test_dynamic_debug
+
+ del_trace_instance_dir param_log 1
+ del_trace_instance_dir new_out 1
+}
+
tests_list=(
basic_tests
comma_terminator_tests
@@ -878,6 +941,8 @@ tests_list=(
test_private_trace_overlong_name
+ test_labelling
+
# works, takes 30 sec
test_private_trace_fill_trace_index
)
--
2.43.0.687.g38aa6559b0-goog
Format, commment and add meaningful name to the following tests:
- test_private_trace_2 -> test_private_trace_syntax_close_in_use,
- test_private_trace_3 -> test_private_trace_syntax_rmmod,
- test_private_trace_4 -> test_private_trace_syntax_delete_in_use_rmmod.
Also update formatting and description of test_private_trace_simple_proper
test.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
.../dynamic_debug/dyndbg_selftest.sh | 127 ++++++++++--------
1 file changed, 71 insertions(+), 56 deletions(-)
diff --git a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
index abe94af0f3eb..86bb039df4a1 100755
--- a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
+++ b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
@@ -357,19 +357,21 @@ function cycle_not_best_practices {
self_test_ delete_directory
}
-# proper life cycle - open, enable:named, disable:named, close
+# test verifies proper life cycle - open, enable:named, disable:named, close
function test_private_trace_simple_proper {
echo -e "${GREEN}# TEST_PRIVATE_TRACE_1 ${NC}"
- # ddcmd close kparm_stream
+
ddcmd open kparm_stream
ddcmd module params +T:kparm_stream.mf
check_match_ct =T:kparm_stream.mf 4
+
ddcmd module params -T:kparm_stream.mf
check_match_ct =T:kparm_stream.mf 0
is_trace_instance_opened kparm_stream
ddcmd module params +:0
ddcmd close kparm_stream
is_trace_instance_closed kparm_stream
+
ddcmd =_
check_trace_instance_dir kparm_stream 1
is_trace_instance_closed kparm_stream
@@ -377,115 +379,128 @@ function test_private_trace_simple_proper {
check_trace_instance_dir kparm_stream 0
}
-function test_private_trace_2 {
- echo -e "${GREEN}# TEST_PRIVATE_TRACE_2 ${NC}"
+# test verifies new syntax and close attempt of trace instance which is still in use
+function test_private_trace_syntax_close_in_use {
+ echo -e "${GREEN}# TEST_PRIVATE_SYNTAX_CLOSE_IN_USE ${NC}"
ddcmd =_
echo > /sys/kernel/tracing/trace
echo 1 >/sys/kernel/tracing/tracing_on
echo 1 >/sys/kernel/tracing/events/dyndbg/enable
+
ddcmd open foo
is_trace_instance_opened foo
check_trace_instance_dir foo 1
modprobe test_dynamic_debug
- ddcmd class,D2_CORE,+T:foo.l,%class,D2_KMS,+fT:foo.ml
+ ddcmd class,D2_CORE,+T:foo.l,%class,D2_KMS,+fT:foo.ml # test new syntax
check_match_ct =T:foo.l 1
check_match_ct =T:foo.mfl 1
- # purpose ?
- echo 1 >/sys/kernel/tracing/tracing_on
- echo 1 >/sys/kernel/tracing/events/dyndbg/enable
-
- tmark test_private_trace about to do_prints
- search_trace "test_private_trace about to do_prints"
- search_trace_name "0" 1 "test_private_trace about to do_prints"
+ tmark test_private_trace_syntax_close_in_use about to do_prints
+ search_trace "test_private_trace_syntax_close_in_use about to do_prints"
+ search_trace_name "0" 1 "test_private_trace_syntax_close_in_use about to do_prints"
doprints
- ddcmd class,D2_CORE,-T:foo
- ddcmd close foo fail
- check_err_msg "Device or resource busy"
- ddcmd class,D2_KMS,-T:foo
- ddcmd close foo
- check_trace_instance_dir foo 1
- is_trace_instance_closed foo
- ddcmd close bar fail
- check_err_msg "No such file or directory"
+ ddcmd class,D2_CORE,-T:0
+ ddcmd close foo fail # close fails because foo is still being used
+ check_err_msg "Device or resource busy" # verify error message
+
+ ddcmd class,D2_KMS,-T:0
+ ddcmd close foo # now close succeeds
+ check_trace_instance_dir foo 1 # verify trace instance foo dir exists
+ is_trace_instance_closed foo # verify trace instance foo is closed
+
+ ddcmd close bar fail # try to close trace instance bar which is not opened
+ check_err_msg "No such file or directory" # verify error message
+
ifrmmod test_dynamic_debug
search_trace_name foo 2 "D2_CORE msg"
search_trace_name foo 1 "D2_KMS msg"
- del_trace_instance_dir foo 1
- check_trace_instance_dir foo 0
+ del_trace_instance_dir foo 1 # delete trace instance foo dir
+ check_trace_instance_dir foo 0 # verify trace instance foo dir does not exist
}
-function test_private_trace_3 {
- echo -e "${GREEN}# TEST_PRIVATE_TRACE_3 ${NC}"
+# test verifies new syntax and removal of module
+function test_private_trace_syntax_rmmod {
+ echo -e "${GREEN}# TEST_PRIVATE_TRACE_SYNTAX_RMMOD ${NC}"
ddcmd =_
echo > /sys/kernel/tracing/trace
echo 1 >/sys/kernel/tracing/tracing_on
echo 1 >/sys/kernel/tracing/events/dyndbg/enable
- ddcmd open foo \; open bar
+
+ ddcmd open foo \; open bar # open foo and bar trace instances and verify they are opened
is_trace_instance_opened foo
is_trace_instance_opened bar
- modprobe test_dynamic_debug
+
+ modprobe test_dynamic_debug # load module and test new syntax
ddcmd class,D2_CORE,+T:foo
ddcmd class,D2_KMS,+T:foo
ddcmd class D2_CORE +T:foo \; class D2_KMS +T:foo
ddcmd "class,D2_CORE,+T:foo;,class,D2_KMS,+T:foo"
ddcmd class,D2_CORE,+T:foo\;class,D2_KMS,+T:foo
- check_match_ct =T 2 -v
+
+ check_match_ct =T:foo 2 -v
check_match_ct =Tl 0
check_match_ct =Tmf 0
- echo 1 >/sys/kernel/tracing/tracing_on
- echo 1 >/sys/kernel/tracing/events/dyndbg/enable
- tmark test_private_trace_2 about to do_prints
+
+ tmark test_private_trace_syntax_rmmod about to do_prints
doprints
- rmmod test_dynamic_debug
- ddcmd "close bar;close foo"
- is_trace_instance_closed bar
+
+ rmmod test_dynamic_debug # remove module whose callsites are writing debug logs
+ # to trace instance foo
+ ddcmd "close bar;close foo" # close bar and foo trace instances, if usage count
+ # of foo instance was not correctly decremented during
+ # removal of module then close will fail
+
+ is_trace_instance_closed bar # verify that foo and bar trace instances are closed
is_trace_instance_closed foo
search_trace_name foo 2 "D2_CORE msg"
search_trace_name foo 1 "D2_KMS msg"
- del_trace_instance_dir foo 1
+
+ del_trace_instance_dir foo 1 # delete trace instance foo and verify its
+ # directory was removed
check_trace_instance_dir foo 0
- search_trace "test_private_trace_2 about to do_prints"
- del_trace_instance_dir bar 1
+
+ search_trace "test_private_trace_syntax_rmmod about to do_prints"
+
+ del_trace_instance_dir bar 1 # delete trace instance bar and verify its
+ # directory was removed
check_trace_instance_dir bar 0
}
-function test_private_trace_4 {
- echo -e "${GREEN}# TEST_PRIVATE_TRACE_4 ${NC}"
+# test verifies new syntax and combination of delete attempt of trace
+# instance which is still in use with module removal
+function test_private_trace_syntax_delete_in_use_rmmod {
+ echo -e "${GREEN}# TEST_PRIVATE_TRACE_SYNTAX_DELETE_IN_USE_RMMOD ${NC}"
ddcmd =_
echo > /sys/kernel/tracing/trace
echo 1 >/sys/kernel/tracing/tracing_on
echo 1 >/sys/kernel/tracing/events/dyndbg/enable
- ddcmd open foo
+ ddcmd open foo # open trace instance foo and test new syntax
modprobe test_dynamic_debug dyndbg=class,D2_CORE,+T:foo%class,D2_KMS,+T:foo
check_match_ct =Tl 0
check_match_ct =Tmf 0
- check_match_ct =T 2
-
- # are these 2 doing anything ?
- echo 1 >/sys/kernel/tracing/tracing_on
- echo 1 >/sys/kernel/tracing/events/dyndbg/enable
+ check_match_ct =T:foo 2 -v
tmark should be ready
- search_trace_name "0" 0 "should be ready" # in global trace
+ search_trace_name "0" 0 "should be ready" # search in global trace
doprints
- search_trace_name foo 2 "D2_CORE msg" # in private buf
+ search_trace_name foo 2 "D2_CORE msg" # search in trace instance foo
search_trace_name foo 1 "D2_KMS msg"
# premature delete
- del_trace_instance_dir foo 0
- check_trace_instance_dir foo 1 # doesn't delete
+ del_trace_instance_dir foo 0 # delete fails because foo is being used
+ check_trace_instance_dir foo 1 # verify trace instance foo dir exists
ifrmmod test_dynamic_debug
- ddcmd "close foo"
- is_trace_instance_closed foo
- del_trace_instance_dir foo 1 # delete works now
+ ddcmd "close foo" # close will succeed only if foo usage count
+ # was correctly decremented during module removal
+ is_trace_instance_closed foo # verify trace instance foo is closed
+ del_trace_instance_dir foo 1 # foo delete works now
- check_trace_instance_dir foo 0
+ check_trace_instance_dir foo 0 # verify trace instance foo dir does not exist
search_trace "should be ready"
}
@@ -651,9 +666,9 @@ tests_list=(
cycle_not_best_practices
test_private_trace_1
test_private_trace_simple_proper
- test_private_trace_2
- test_private_trace_3
- test_private_trace_4
+ test_private_trace_syntax_close_in_use
+ test_private_trace_syntax_rmmod
+ test_private_trace_syntax_delete_in_use_rmmod
test_private_trace_mixed_class
test_private_trace_mixed_class # again, to test pre,post conditions
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
commit 47ea6f99d06e ("dyndbg: use ESCAPE_SPACE for cat control")
changed the control-file to display format strings with "\n" rather
than "\012", etc. Update the docs to match the new reality.
Signed-off-by: Jim Cromie <[email protected]>
---
Documentation/admin-guide/dynamic-debug-howto.rst | 10 +++++-----
1 file changed, 5 insertions(+), 5 deletions(-)
diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst
index 90449a04946e..4d681c37e074 100644
--- a/Documentation/admin-guide/dynamic-debug-howto.rst
+++ b/Documentation/admin-guide/dynamic-debug-howto.rst
@@ -52,12 +52,12 @@ query/commands to the control file. Example::
# grease the interface
:#> alias ddcmd='echo $* > /proc/dynamic_debug/control'
- :#> ddcmd '-p; module main func run* +p'
+ :#> ddcmd '-p; module main func run* +p' # disable all, then enable main
:#> grep =p /proc/dynamic_debug/control
- init/main.c:1424 [main]run_init_process =p " with arguments:\012"
- init/main.c:1426 [main]run_init_process =p " %s\012"
- init/main.c:1427 [main]run_init_process =p " with environment:\012"
- init/main.c:1429 [main]run_init_process =p " %s\012"
+ init/main.c:1424 [main]run_init_process =p " with arguments:\n"
+ init/main.c:1426 [main]run_init_process =p " %s\n"
+ init/main.c:1427 [main]run_init_process =p " with environment:\n"
+ init/main.c:1429 [main]run_init_process =p " %s\n"
Error messages go to console/syslog::
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
Add mention of comma and percent in their respective paragraphs.
Signed-off-by: Jim Cromie <[email protected]>
---
.../admin-guide/dynamic-debug-howto.rst | 18 ++++++++++--------
1 file changed, 10 insertions(+), 8 deletions(-)
diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst
index 4d681c37e074..2d7ee4e558c8 100644
--- a/Documentation/admin-guide/dynamic-debug-howto.rst
+++ b/Documentation/admin-guide/dynamic-debug-howto.rst
@@ -73,16 +73,18 @@ Command Language Reference
==========================
At the basic lexical level, a command is a sequence of words separated
-by spaces or tabs. So these are all equivalent::
+by spaces, tabs, or commas. So these are all equivalent::
:#> ddcmd file svcsock.c line 1603 +p
:#> ddcmd "file svcsock.c line 1603 +p"
:#> ddcmd ' file svcsock.c line 1603 +p '
+ :#> ddcmd file,svcsock.c,line,1603,+p
-Command submissions are bounded by a write() system call.
-Multiple commands can be written together, separated by ``;`` or ``\n``::
+Command submissions are bounded by a write() system call. Multiple
+commands can be written together, separated by ``%``, ``;`` or ``\n``::
- :#> ddcmd "func pnpacpi_get_resources +p; func pnp_assign_mem +p"
+ :#> ddcmd func foo +p % func bar +p
+ :#> ddcmd func foo +p \; func bar +p
:#> ddcmd <<"EOC"
func pnpacpi_get_resources +p
func pnp_assign_mem +p
@@ -104,7 +106,6 @@ The match-spec's select *prdbgs* from the catalog, upon which to apply
the flags-spec, all constraints are ANDed together. An absent keyword
is the same as keyword "*".
-
A match specification is a keyword, which selects the attribute of
the callsite to be compared, and a value to compare against. Possible
keywords are:::
@@ -128,7 +129,6 @@ keywords are:::
``line-range`` cannot contain space, e.g.
"1-30" is valid range but "1 - 30" is not.
-
The meanings of each keyword are:
func
@@ -153,9 +153,11 @@ module
The given string is compared against the module name
of each callsite. The module name is the string as
seen in ``lsmod``, i.e. without the directory or the ``.ko``
- suffix and with ``-`` changed to ``_``. Examples::
+ suffix and with ``-`` changed to ``_``.
+
+ Examples::
- module sunrpc
+ module,sunrpc # with ',' as token separator
module nfsd
module drm* # both drm, drm_kms_helper
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
Treat comma as a token terminator, just like a space. This allows a
user to avoid quoting hassles when spaces are otherwise needed:
:#> modprobe drm dyndbg=class,DRM_UT_CORE,+p\;class,DRM_UT_KMS,+p
or as a boot arg:
drm.dyndbg=class,DRM_UT_CORE,+p # todo: support multi-query here
Given the myriad ways a boot-line can be assembled and then passed
in/down/around shell based tools, if the >control parser treats commas
like spacees, this would allow side-stepping all sorts of quoting
hassles thru those layers.
This change apart from existing query format:
modprobe test_dynamic_debug dyndbg="class D2_CORE +p"
introduces new format:
modprobe test_dynamic_debug dyndbg=class,D2_CORE,+p
Signed-off-by: Jim Cromie <[email protected]>
Co-developed-by: Łukasz Bartosik <[email protected]>
Signed-off-by: Łukasz Bartosik <[email protected]>
---
lib/dynamic_debug.c | 20 ++++++++++++++++----
1 file changed, 16 insertions(+), 4 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 20bfb6de2404..78b06a617918 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -650,6 +650,14 @@ static int ddebug_change(const struct ddebug_query *query,
return nfound;
}
+static char *skip_spaces_and_comma(const char *str)
+{
+ str = skip_spaces(str);
+ if (*str == ',')
+ str = skip_spaces(++str);
+ return (char *)str;
+}
+
/*
* Split the buffer `buf' into space-separated words.
* Handles simple " and ' quoting, i.e. without nested,
@@ -663,12 +671,16 @@ static int ddebug_tokenize(char *buf, char *words[], int maxwords)
while (*buf) {
char *end;
- /* Skip leading whitespace */
- buf = skip_spaces(buf);
+ /* Skip leading whitespace and comma */
+ buf = skip_spaces_and_comma(buf);
if (!*buf)
break; /* oh, it was trailing whitespace */
if (*buf == '#')
break; /* token starts comment, skip rest of line */
+ if (*buf == ',') {
+ buf++;
+ continue;
+ }
/* find `end' of word, whitespace separated or quoted */
if (*buf == '"' || *buf == '\'') {
@@ -680,7 +692,7 @@ static int ddebug_tokenize(char *buf, char *words[], int maxwords)
return -EINVAL; /* unclosed quote */
}
} else {
- for (end = buf; *end && !isspace(*end); end++)
+ for (end = buf; *end && !isspace(*end) && *end != ','; end++)
;
if (end == buf) {
pr_err("parse err after word:%d=%s\n", nwords,
@@ -993,7 +1005,7 @@ static int ddebug_exec_queries(char *query, const char *modname)
if (split)
*split++ = '\0';
- query = skip_spaces(query);
+ query = skip_spaces_and_comma(query);
if (!query || !*query || *query == '#')
continue;
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
Multi-query strings have long allowed:
modprobe drm dyndbg="class DRM_UT_CORE +p; class DRM_UT_KMS +p"
modprobe drm dyndbg=<<EOX
class DRM_UT_CORE +pmf
class DRM_UT_KMS +pmf
EOX
More recently, the need for quoting was avoided by treating a comma
like a space/token-terminator:
modprobe drm dyndbg=class,DRM_UT_CORE,+p\;class,DRM_UT_KMS,+p
But that leaves unfinished business; that semi-colon needs escaping,
and thats not robust to further string interpolation. In particular,
it fails when passed to vng (virtme-ng).
So this patch adds '%' to the existing ';' and '\n' multi-cmd
separators, which is more shell-friendly, and avoids quoting and
escaping hassles.
modprobe drm dyndbg=class,DRM_UT_CORE,+p%class,DRM_UT_KMS,+p
NOTE: it does alter/break this (ill conceived) search:
[root@v6 lx]# ddcmd format %s +p
[ 38.170998] dyndbg: read 13 bytes from userspace
[ 38.171542] dyndbg: query 0: "format " mod:*
[ 38.172011] dyndbg: bad flag-op f, at start of format
[ 38.172487] dyndbg: flags parse failed
[ 38.172839] dyndbg: query 1: "s +p" mod:*
[ 38.173285] dyndbg: expecting pairs of match-spec <value>
[ 38.173791] dyndbg: query parse failed
[ 38.174141] dyndbg: processed 2 queries, with 0 matches, 2 errs
bash: echo: write error: Invalid argument
In trade for that minor format selection limitation, we get to do:
vng -v --user root -p 4 \
-a dynamic_debug.verbose=3 \
-a drm.debug=0x15 \
-a i915.dyndbg=class,DRM_UT_CORE,+pfmlt_%class,DRM_UT_KMS,+pfml
modprobe drm
modprobe i915
NOTES/TLDR:
In this example, using both drm.debug & drm.dyndbg is mostly for
testing. Using drm.debug is preferred, because the drivers all
explicitly depend on that input/control-point, so settings there are
propagated to drivers.
But more to the point, drm.dyndbg explicitly limits the query to drm.
In fact, you could pass a module wildcard in the above, and achieve
the same thing:
vng -v --user root -p 4 \
-a dynamic_debug.verbose=3 \
-a \*.dyndbg=class,DRM_UT_CORE,+pfmlt_%class,DRM_UT_KMS,+pfm%class, \
DRM_UT_ATOMIC,+pf
':' would be a more natural multi-cmd separator, but is reserved
for +T:<trace_buf> to designate separate tracebuf instances.
If '%' is distasteful, the backup plan is ",_,", since that would
never appear in a useful <format "$foo"> cmd.
Signed-off-by: Jim Cromie <[email protected]>
---
lib/dynamic_debug.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 78b06a617918..a6c6392cde3e 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -1001,7 +1001,7 @@ static int ddebug_exec_queries(char *query, const char *modname)
int i, errs = 0, exitcode = 0, rc, nfound = 0;
for (i = 0; query; query = split) {
- split = strpbrk(query, ";\n");
+ split = strpbrk(query, "%;\n");
if (split)
*split++ = '\0';
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
Dyndbg can now send pr_debugs to sysfs *and/or* tracefs.
Since tracefs has 2 user groups, dyndbg can write to either:
0. users of existing trace-events, in the global: tracing/trace
1. users of trace_array_printk(),
writing to private trace buffers: in tracing/instances/*
It is presumed that being able to mix existing pr_debugs into your
trace, to add "framing/context/decorations", will prove useful for
both kinds of users. If nothing else, it lets users apply trace-cmd
upon klog+trace-event activity.
63 private instances are supported, "0" is the global trace.
These capabilities are exposed via new grammar into >control:
1. T-flag enables pr_debugs to tracefs
p-flag to syslog is independent.
by default, +T writes to global buf: /sys/kernel/tracing/trace
+T:0 is the explicit :<label> form.
2. open <label>, close <label>
new command connects to tracing/instances/<label>, or creates it.
the global buf is named "0", its the default destination
"0" is always open, open 0 always succeeds.
63 opened tracing/instances/<label>/'s are supported.
open foo (ok) updates default-dest
3. +:<label>
all pr_debugs are pre-labelled "0" by default
once opened, a label can be set for any callsites, like the flags
4. new "label" keyword:
this lets user select/enable previously labelled pr_debugs.
The change details:
Identify new "label" keyword at the top, where others are summarized.
Describe "label" keyword in the match-spec section, in terms of how it
selects previously labelled callsites.
Rework flags-spec description, tweaking: change-ops, primary/enable
flags, the prefix flags. Drop extra words where possible.
Add "Basic flag examples:" - a large set of flag-setting examples,
with comments on their effect. ISTM this is clearer than a rules
description. This also introduces examples of the new +:<label> flag,
and explains the "0" default.
Add several new sections:
"Debug output to Syslog and/or Tracefs"
"open foo & close foo"
"Labeled Trace Examples"
"Miscellaneous Notes" with relocated notes.
NOTE: I liberally added [#tags] to try to link concepts (and/or
details) across examples and explanations. I don't know how they
actually render in sphinx, they read reasonably well as is.
Signed-off-by: Jim Cromie <[email protected]>
---
.../admin-guide/dynamic-debug-howto.rst | 351 +++++++++++++++---
1 file changed, 305 insertions(+), 46 deletions(-)
diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst
index 2d7ee4e558c8..c89ddcfb3f23 100644
--- a/Documentation/admin-guide/dynamic-debug-howto.rst
+++ b/Documentation/admin-guide/dynamic-debug-howto.rst
@@ -16,8 +16,8 @@ Dynamic debug provides:
* a Catalog of all *prdbgs* in your kernel.
``cat /proc/dynamic_debug/control`` to see them.
- * a Simple query/command language to alter *prdbgs* by selecting on
- any combination of 0 or 1 of:
+ * a Simple query/command language to alter groups (or singles) of
+ *prdbgs* by selecting on any combination of 0 or 1 of:
- source filename
- function name
@@ -25,6 +25,7 @@ Dynamic debug provides:
- module name
- format string
- class name (as known/declared by each module)
+ - label name (trace-label, as determined by user)
Viewing Dynamic Debug Behaviour
===============================
@@ -81,14 +82,15 @@ by spaces, tabs, or commas. So these are all equivalent::
:#> ddcmd file,svcsock.c,line,1603,+p
Command submissions are bounded by a write() system call. Multiple
-commands can be written together, separated by ``%``, ``;`` or ``\n``::
+commands can be sent together in a CMD_BLK, each separated by ``%``,
+``;`` or ``\n``::
:#> ddcmd func foo +p % func bar +p
- :#> ddcmd func foo +p \; func bar +p
- :#> ddcmd <<"EOC"
+ :#> ddcmd "func foo +p ; func bar +p"
+ :#> ddcmd <<CMD_BLK
func pnpacpi_get_resources +p
func pnp_assign_mem +p
- EOC
+ CMD_BLK
:#> cat query-batch-file > /proc/dynamic_debug/control
You can also use wildcards in each query term. The match rule supports
@@ -97,8 +99,8 @@ character). For example, you can match all usb drivers::
:#> ddcmd file "drivers/usb/*" +p # "" to suppress shell expansion
-Syntactically, a command is pairs of keyword values, followed by a
-flags change or setting::
+Syntactically, a query/command is 0 or more pairs of keyword values,
+followed by a flags change or setting::
command ::= match-spec* flags-spec
@@ -106,6 +108,14 @@ The match-spec's select *prdbgs* from the catalog, upon which to apply
the flags-spec, all constraints are ANDed together. An absent keyword
is the same as keyword "*".
+non-query commands support connection to tracefs:
+
+ command ::= open <name>
+ command ::= close <name>
+
+Match specification
+===================
+
A match specification is a keyword, which selects the attribute of
the callsite to be compared, and a value to compare against. Possible
keywords are:::
@@ -115,6 +125,7 @@ keywords are:::
'module' string |
'format' string |
'class' string |
+ 'label' string |
'line' line-range
line-range ::= lineno |
@@ -131,15 +142,15 @@ keywords are:::
The meanings of each keyword are:
-func
- The given string is compared against the function name
- of each callsite. Example::
+func <func_name>
+ The func_name is compared against the function name of each
+ callsite. Example::
func svc_tcp_accept
func *recv* # in rfcomm, bluetooth, ping, tcp
-file
- The given string is compared against either the src-root relative
+file <file_name>
+ The file_name is compared against either the src-root relative
pathname, or the basename of the source file of each callsite.
Examples::
@@ -149,11 +160,10 @@ file
file inode.c:start_* # parse :tail as a func (above)
file inode.c:1-100 # parse :tail as a line-range (above)
-module
- The given string is compared against the module name
- of each callsite. The module name is the string as
- seen in ``lsmod``, i.e. without the directory or the ``.ko``
- suffix and with ``-`` changed to ``_``.
+module <mod_name>
+ The mod_name is compared to each callsites mod_name, as seen in
+ ``lsmod``, i.e. without the directory or the ``.ko`` suffix and
+ with ``-`` changed to ``_``.
Examples::
@@ -161,7 +171,7 @@ module
module nfsd
module drm* # both drm, drm_kms_helper
-format
+format <fmtstr>
The given string is searched for in the dynamic debug format
string. Note that the string does not need to match the
entire format, only some part. Whitespace and other
@@ -177,17 +187,17 @@ format
format "nfsd: SETATTR" // a neater way to match a format with whitespace
format 'nfsd: SETATTR' // yet another way to match a format with whitespace
-class
- The given class_name is validated against each module, which may
- have declared a list of known class_names. If the class_name is
- found for a module, callsite & class matching and adjustment
- proceeds. Examples::
+class <cl_name>
+ The cl_name is validated against each module, which may have
+ declared a list of class_names it knows. If the cl_name is known
+ by a module, site matching and site flags adjustment proceeds.
+ Examples::
class DRM_UT_KMS # a DRM.debug category
class JUNK # silent non-match
- // class TLD_* # NOTICE: no wildcard in class names
+ # class TLD_* # NOTICE: no wildcard in class names
-line
+line <ln_spec>
The given line number or range of line numbers is compared
against the line number of each ``pr_debug()`` callsite. A single
line number matches the callsite line number exactly. A
@@ -201,33 +211,271 @@ 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
-The flags specification comprises a change operation followed
-by one or more flag characters. The change operation is one
-of the characters::
+label <lbl_name>
+ This matches the lbl_name against each callsite's current label
+ (the default is "0"). This allows a user to select and enable a
+ previously labelled set of callsites, after assembling a group label
+ to express the "relatedness" they perceive.
- - remove the given flags
- + add the given flags
- = set the flags to the given flags
+Flags Specification
+===================
-The flags are::
+The flags-spec is a change operation followed by one or more flag
+characters. The change operation is one of the characters::
- p callsite prints to syslog
- T callsite issues a dyndbg:* trace-event
- _ enables no flags
+ - disable these flags
+ + enable these flags
+ = set these flags
- Decorator flags add to the message-prefix, in order:
- t Include thread ID, or <intr>
- m Include module name
- f Include the function name
- s Include the source file name
- l Include line number
+The primary flags are::
-For ``print_hex_dump_debug()`` and ``print_hex_dump_bytes()``, only
-the ``p`` flag has meaning, other flags are ignored.
+ p print to syslog
+ T write to tracefs
+ _ no-flags (allows positive assertion of no-flags)
+ : trace-label pseudo-flag (see below)
+
+The prefix flags append callsite info to each site's dynamic-prefix,
+in the order shown below, (with '':'' between each). That is then
+prepended to the pr_debug message, for both sylog and tracefs.
+
+ t thread ID, or <intr>
+ m module name
+ f the function name
+ s the source file name
+ l line number
+
+Basic flag examples:
+
+ # because match-spec can be empty, these are legal commands.
+ =p # output to syslog (on all sites)
+ =T # output to trace (on all sites)
+ =_ # clear all flags (set them all off)
+ +_ # add no flags [#nochgquery]_
+ -_ # drop no flags [#nochgquery]_
+ +mf # set "module:function: " prefix
+ +sl # set "file:line: " prefix
+
+[#nochgquery] these queries alter no flags, they are processed
+normally.
+
+Labelling pr_debug callsites
+============================
+
+Callsites can also be labelled, using the ``:<lbl_name>`` trace-label
+pseudo-flag, and the following <lbl_name>. This labels the callsite
+with that name, allowing its later selection and enablement using the
+"label" keyword. From boot, the [#default_dest] and all callsite
+labels are set to "0".
+
+Labelling Examples:
+
+ =T:0 # enable tracing to "0"/global explicitly
+ =T:0. # same, dot terminates lbl_name (optional here)
+ =T:0.mf # same, but add "module:func:" prefix to msgs (dot required)
+ =T # enable tracing to site.label (0 by default)
+
+ =T:foo # set labels to foo [#ifopened]_, send them to tracing/instances/foo
+ =T:foo.mf # same, with "module:function:" prefix
+
+ =_:foo # clear all flags, set all labels to foo [#ifopened]_
+ =:foo # set labels, touch no flags, since no flags are given
+ =:0 # reset all labels to global trace-buf
+ =:0. # same (with optional dot)
+
+Labelling is primarily for mapping into tracing, but is syntactically
+separate, and is allowed independently, so the label keyword can be
+used to enable to syslog, or to both.
+
+ =p:foo # enable to syslog, p ignores foo
+ =pT:foo # trace to instances/foo, and to syslog
+
+Debug output to Syslog and/or Tracefs
+=====================================
+
+Dynamic Debug can independently direct pr_debugs to both syslog and
+tracefs, using the +p, +T flags respectively. This allows users to
+migrate away from syslog in bites, if and as they see a reason.
+
+Dyndbg supports 64-way steering of pr_debugs into tracefs, by labelling
+the callsites as described above. You can steer trace traffic for any
+number of reasons:
+
+ - create a flight-recorder buffer.
+ - isolate hi-rate traffic.
+ - simplify buffer management and overwrite guarantees.
+ - assemble "related" sets of prdbgs by labelling them.
+ - select & enable them later, with "label" keyword.
+ - just label some traffic as trash/uninteresting (>/dev/null?)
+ - 63 private buffers are supported + global
+
+The ``:0.`` default label steers output to the global trace-event buf:
+
+ ddcmd open 0 # opened by default, also sets [#default_dest]_
+ ddcmd =:0 # steer pr_debugs to /sys/kernel/tracing/trace
+ ddcmd =T # enable pr_debugs to their respective destinations
+
+ # also need to enable the events into tracefs
+ echo 1 > /sys/kernel/tracing/trace_on
+ echo 1 > /sys/kernel/tracing/events/dyndbg/enable
+
+Or the ``:<name>.`` labels steer +T enabled callsites into
+/sys/kernel/tracing/instances/<name> [#ifopened]_
+
+ ddcmd open foo # open or append to /sys/kernel/tracing/instances/foo
+ ddcmd =:foo # set labels explicitly
+ ddcmd =T # enable tracing to site.label
+
+ # needed if appending (above)
+ echo 1 > /sys/kernel/tracing/instances/foo/trace_on
+ echo 1 > /sys/kernel/tracing/instances/foo/events/dyndbg/enable
+
+open foo & close foo
+====================
+
+The ``open foo`` & ``close foo`` commands allow dyndbg to manage the
+63 private trace-instances it can use simultaneously, so it can error
+with -ENOSPC when asked for one-too-many. Otherwise, [#default_dest]
+is upated accordingly.
+
+[#ifopened] It is an error -EINVAL to set a label (=:foo) that hasn't
+been previously opened.
+
+[#already_opened] If /sys/kernel/tracing/instances/foo has already
+been created separately, then dyndbg just uses it, mixing any =T:foo
+labelled pr_debugs into instances/foo/trace. Otherwise dyndbg will
+open the trace-instance, and enable it for you.
+
+Dyndbg treats ``:0.`` as the name of the global trace-event buffer; it
+is automatically opened, but needs to be enabled in tracefs too.
+
+If ``open bar`` fails (if bar was misspelled), the [#last_good_open]
+is not what the user expects, so the open-cmd also terminates the
+play-thru-query-errors strategy normally used over a CMD_BLK of
+query-cmds.
+
+``open 0`` always succeeds.
+
+``close foo`` insures that no pr_debugs are set to :foo, then unmaps
+the label from its reserved trace-id, preserving the trace buffer for
+trace-cmd etc. Otherwise the command returns -EBUSY.
-Note the regexp ``^[-+=][fslmpt_]+$`` matches a flags specification.
-To clear all flags at once, use ``=_`` or ``-fslmpt``.
+Labeled Trace Examples
+======================
+Example 1:
+
+Use 2 private trace instances to trivially segregate interesting debug.
+
+ ddcmd open usbcore_buf # create or share tracing/instances/usbcore_buf
+ ddcmd module usbcore =T # enable module usbcore to just opened instance
+
+ ddcmd open tbt # create or share tracing/instances/tbt
+ ddcmd module thunderbolt =T # enable module thunderbolt to just opened instance
+
+Example 2:
+
+RFC: This is plausible but aggressive conjecture, needs DRM-folk
+review for potential utility.
+
+ echo <<DRM_CMD_BLK > /proc/dynamic_debug/control
+
+ # open 0 # automatically opened anyway
+ open 0 # but also resets [#default_dest]_ to 0
+
+ # send some traffic to global trace, to mix with other events
+
+ class DRM_UT_KMS +T:0 # set label explicitly
+ class DRM_UT_ATOMIC +T # enable to site.label
+
+ # label 2 classes together (presuming its useful)
+ open drm_bulk # open instances/drm_bulk/, set [#default_dest]_
+
+ class DRM_UT_CORE +T # implicit :drm_bulk
+ class DRM_UT_DRIVER +T:drm_bulk # explicit (but unnecessary)
+
+ # capture DRM screen/layout changes
+ open drm_screens
+ class DRM_UT_LEASE +T # all implied [#default_dest]_
+ class DRM_UT_DP +T
+ class DRM_UT_DRMRES +T
+ class DRM_UT_STATE +T
+
+ # mark traffic to ignore
+ open trash # will remain empty
+ class junk -T # cuz we disable the label
+
+ open drm_vblank # isolate hi-rate traffic
+ class DRM_UT_VBL +T # use drm_vblank (implicitly)
+
+ # afterthought - add to drm_bulk
+ class DRM_UT_DRIVER +T:drm_bulk # explicit name needed here
+
+ open 0 # reset [#default_dest]_ for next user
+
+ DRM_CMD_BLK
+
+This example uses +T (not =T) to enable pr_debugs to tracefs. Doing
+so preserves all other flags, so you can independently use +p for
+syslog, and customize the shared prefix-flags per your personal whim
+(or need), knowing they're not changed later spuriously.
+
+NB: Dyndbg's support for DRM.debug uses ``+p`` & ``-p`` to toggle each
+DRM_UT_* class by name, without altering any prefix customization you
+might favor and apply.
+
+This example also does explicit ``+T:<name>`` labelling more than
+strictly needed, because it also mostly follows a repeating "open then
+label" pattern, and could rely upon [#last_good_open] being set. The
+afterthought provides a counter-example.
+
+Trash is handled by labelling and disabling certain traffic, so it is
+never collected. This will waste a trace instance, but it will stay
+empty.
+
+The extra ``open 0`` commands at the start & end of the DRM_CMD_BLK
+explicitly reset the [#last_good_open], since ``open 0`` never fails.
+This defensive practice prevents surprises when the next user expects
+the "0" default (reasonably!) which enables to the global trace-buf.
+
+Example 3: labelling 1st, deferred enable.
+
+If the DRM_CMD_BLK above had replaced ``+T`` with ``-T``, then the
+selected sites would get their labels set, but the trace-enable flag
+is unset, and they are all trace-disabled.
+
+This style lets a user aggregate an arbitrary set of "related"
+pr_debugs. Then those labels can be later selected and enabled
+together:
+
+ ddcmd label drm_screens +T # enable tracing on the user's label
+ ddcmd label drm_bulk +p # works for syslog too
+
+RFC:
+
+Its practical to not require the open-1st if the trace instance
+already exists, but auto-open of misspelled names would be an
+anti-feature.
+
+Also, without ``open foo`` required, theres no [#last_good_open], and
+[#default_dest] must be set by explicit labelling at least once before
+using [#default_dest] in following query-cmds.
+
+Example 4:
+
+This example opens interesting instances/labels 1st (perhaps at boot),
+then labels several modules, and enables their pr_debugs to the
+labelled trace-instances.
+
+ echo <<ALT_BLK_STYLE > /proc/dynamic_debug/control
+ open x; # set [#default_dest]_ to x
+ open y; # set [#default_dest]_ to y
+ open z # set [#default_dest]_ to z
+ module X +T:z
+ module X1 +T # :z, use [#default_dest]_ implicitly
+ module Y +T:y
+ module Z +T:z
+ module Z1 +T # :z, use [#default_dest]_ implicitly
+ ALT_BLK_STYLE
Debug messages during Boot Process
==================================
@@ -343,6 +591,8 @@ Examples
dyndbg="file init/* +p #cmt ; func parse_one +p"
// enable pr_debugs in 2 functions in a module loaded later
pc87360.dyndbg="func pc87360_init_device +p; func pc87360_find +p"
+ // open private tracing/instances/foo,bar
+ dyndbg=open,foo%open,bar
Kernel Configuration
====================
@@ -375,6 +625,15 @@ Otherwise, they are off by default; ``ccflags += -DDEBUG`` or
If ``CONFIG_DYNAMIC_DEBUG`` is not set, ``print_hex_dump_debug()`` is
just a shortcut for ``print_hex_dump(KERN_DEBUG)``.
+Miscellaneous Notes
+===================
+
For ``print_hex_dump_debug()``/``print_hex_dump_bytes()``, format string is
its ``prefix_str`` argument, if it is constant string; or ``hexdump``
in case ``prefix_str`` is built dynamically.
+
+For ``print_hex_dump_debug()`` and ``print_hex_dump_bytes()``, only
+the ``p`` and ``T`` flags have meaning, other flags are ignored.
+
+pr_fmt displays after the dynamic-prefix.
+
--
2.43.0.687.g38aa6559b0-goog
When trace open or close command fails then stop processing next
queries in multiquery string. The rationale behing this behavior
is to stop processing queries which might be dependent on success
of open/close trace commands.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
lib/dynamic_debug.c | 25 ++++++++++++++++++-------
1 file changed, 18 insertions(+), 7 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 3d0c6b5faa31..d8cd40faeb4d 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -939,7 +939,8 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
return 0;
}
-static int ddebug_exec_query(char *query_string, const char *modname)
+static int ddebug_exec_query(char *query_string, const char *modname,
+ bool *is_trace_cmd)
{
struct flag_settings modifiers = { .trace_dst = DST_NOT_SET };
struct ddebug_query query = {};
@@ -954,7 +955,8 @@ static int ddebug_exec_query(char *query_string, const char *modname)
}
/* check for open, close commands */
- if (is_dd_trace_cmd(words[0]))
+ *is_trace_cmd = is_dd_trace_cmd(words[0]);
+ if (*is_trace_cmd)
return ddebug_parse_cmd(words, nwords-1);
if (ddebug_parse_query(words, nwords-1, &query, modname)) {
@@ -991,16 +993,19 @@ static int ddebug_exec_query(char *query_string, const char *modname)
return -EINVAL;
}
-/* handle multiple queries in query string, continue on error, return
- last error or number of matching callsites. Module name is either
- in param (for boot arg) or perhaps in query string.
-*/
+/* handle multiple queries in query string, continue on error with
+ * exception of open and close commands, return last error or number
+ * of matching callsites. Module name is either in param (for boot arg)
+ * or perhaps in query string.
+ */
static int ddebug_exec_queries(char *query, const char *modname)
{
char *split;
int i, errs = 0, exitcode = 0, rc, nfound = 0;
for (i = 0; query; query = split) {
+ bool is_trace_cmd = false;
+
split = strpbrk(query, "%;\n");
if (split)
*split++ = '\0';
@@ -1011,10 +1016,16 @@ static int ddebug_exec_queries(char *query, const char *modname)
vpr_info("query %d: \"%s\" mod:%s\n", i, query, modname ?: "*");
- rc = ddebug_exec_query(query, modname);
+ rc = ddebug_exec_query(query, modname, &is_trace_cmd);
if (rc < 0) {
errs++;
exitcode = rc;
+ /*
+ * if open or close command failed then
+ * do not continue with next queries
+ */
+ if (is_trace_cmd)
+ break;
} else {
nfound += rc;
}
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
Fix a BUG_ON from 2009. I have hit it while fuzzing >control on some
other patches, and panic from user input is bad. Replace the BUG_ON
with pr_error and return -EINVAL.
Signed-off-by: Jim Cromie <[email protected]>
---
lib/dynamic_debug.c | 6 +++++-
1 file changed, 5 insertions(+), 1 deletion(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 17df4bf6863a..20bfb6de2404 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -682,7 +682,11 @@ static int ddebug_tokenize(char *buf, char *words[], int maxwords)
} else {
for (end = buf; *end && !isspace(*end); end++)
;
- BUG_ON(end == buf);
+ if (end == buf) {
+ pr_err("parse err after word:%d=%s\n", nwords,
+ nwords ? words[nwords - 1] : "<none>");
+ return -EINVAL;
+ }
}
/* `buf' is start of word, `end' is one past its end */
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
If ddebug_parse_flags() rejects user input, identify that input value
in the error message.
Signed-off-by: Jim Cromie <[email protected]>
---
lib/dynamic_debug.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 4954d3e5be5b..089765afc972 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -973,7 +973,7 @@ static int ddebug_exec_query(char *query_string, const char *modname)
/* check flags 1st (last arg) so query is pairs of spec,val */
if (ddebug_parse_flags(words[nwords-1], &modifiers)) {
- pr_err("flags parse failed\n");
+ pr_err("flags parse failed on word-%d: %s\n", nwords-1, words[nwords-1]);
goto err;
}
--
2.43.0.687.g38aa6559b0-goog
Add function setup_env_for_tests which prepares dynamic debug
and trace environment for tests execution. This is to clean up
previous settings or leftovers after a failing test. The function
setup_env_for_tests does the following to prepare the environment:
- unloads test_dynamic_debug, test_dynamic_debug_submod modules
if any of them is loaded,
- it prints info about all callsites which have flags != "_" and
sets these flags to "_:0",
- it closes open trace instances and deletes their respective
directories.
The patch also refactors ifrmmod function.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
.../dynamic_debug/dyndbg_selftest.sh | 36 +++++++++++++++++--
1 file changed, 34 insertions(+), 2 deletions(-)
diff --git a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
index 86bb039df4a1..f8b81e8a3bd6 100755
--- a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
+++ b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
@@ -147,8 +147,8 @@ function error_log_ref {
}
function ifrmmod {
- lsmod | grep $1 2>&1>/dev/null || echo $1 not there
- lsmod | grep $1 2>&1>/dev/null && rmmod $1
+ lsmod | grep $1 2>&1>/dev/null || ([ "$2" == "-v" ] && echo "module '$1' is not loaded")
+ lsmod | grep $1 2>&1>/dev/null && rmmod $1 && [ "$2" == "-v" ] && echo "unload module '$1'"
}
# $1 - text to search for
@@ -657,6 +657,37 @@ function test_private_trace_fill_trace_index {
check_trace_instance_dir trace_instance_63 0
}
+# prepares dynamic debug and trace environment for tests execution
+function setup_env_for_tests {
+ echo -e "${GREEN}# SETUP_ENV_FOR_TESTS ${NC}"
+
+ echo "MODULES"
+ ifrmmod test_dynamic_debug_submod -v # unload test_dynamic_debug_submod module
+ # if it is loaded
+ ifrmmod test_dynamic_debug -v # unload test_dynamic_debug module it if is loaded
+ echo
+
+ # display all callsites which have flags != "_"
+ echo "CALLSITES with flags != \":0\""
+ cat /proc/dynamic_debug/control | grep -v "=_" | grep -v "not set" | grep -v "^$" \
+ | grep -v "#: Opened trace instances" | grep -v "#: Default trace destination"
+ ddcmd module,*,=_:0 # clear all flags and set dest to 0
+ echo
+
+ # close all opened trace instances and delete their respective directories
+ echo "OPEN trace instance"
+ output=$(tail -n9 /proc/dynamic_debug/control | grep "#: Opened trace instances" \
+ | cut -f3 -d":" | xargs -n1)
+ for dst in $output
+ do
+ echo "close trace instance '$dst'"
+ echo close,$dst > /proc/dynamic_debug/control
+ echo "delete '/sys/kernel/debug/tracing/instances/$dst' directory"
+ rmdir /sys/kernel/debug/tracing/instances/$dst
+ done
+ echo
+}
+
tests_list=(
basic_tests
comma_terminator_tests
@@ -680,6 +711,7 @@ tests_list=(
# Run tests
+setup_env_for_tests
for test in "${tests_list[@]}"
do
$test
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
This fn currently is hard-coded to modprobe test_dynamic_debug.ko for
its tests, we'd also like to use test_dynamic_debug_submod.ko.
Add local modname="test_dynamic_debug" to make this explicit.
This leaves the use of search_trace_name for hard-coded reference
content, unfortunately that will take more fiddling.
Signed-off-by: Jim Cromie <[email protected]>
---
.../dynamic_debug/dyndbg_selftest.sh | 32 +++++++++----------
1 file changed, 16 insertions(+), 16 deletions(-)
diff --git a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
index d1f447eef4c0..abe94af0f3eb 100755
--- a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
+++ b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
@@ -499,7 +499,20 @@ function search_in_trace_for {
}
function test_private_trace_mixed_class {
- echo -e "${GREEN}# TEST_PRIVATE_TRACE_5 ${NC}"
+ local modname="test_dynamic_debug"
+ echo -e "${GREEN}# TEST_PRIVATE_TRACE_mixed_class ${NC}"
+
+ local eyeball_ref=<<'EOD'
+ modprobe-1173 [001] ..... 7.781008: 0: test_dynamic_debug:do_cats: test_dd: D2_CORE msg
+ modprobe-1173 [001] ..... 7.781010: 0: test_dynamic_debug:do_cats: test_dd: D2_KMS msg
+ modprobe-1173 [001] ..... 7.781010: 0: test_dynamic_debug:do_levels: test_dd: V3 msg
+ cat-1214 [001] ..... 7.905494: 0: test_dd: doing categories
+ cat-1214 [001] ..... 7.905495: 0: test_dynamic_debug:do_cats: test_dd: D2_CORE msg
+ cat-1214 [001] ..... 7.905496: 0: test_dynamic_debug:do_cats: test_dd: D2_KMS msg
+ cat-1214 [001] ..... 7.905497: 0: test_dd: doing levels
+ cat-1214 [001] ..... 7.905498: 0: test_dynamic_debug:do_levels: test_dd: V3 msg
+EOD
+
ddcmd =_
ddcmd module,params,+T:unopened fail
check_err_msg "Invalid argument"
@@ -509,7 +522,7 @@ function test_private_trace_mixed_class {
ddcmd open bupkus
is_trace_instance_opened bupkus
check_trace_instance_dir bupkus 1
- modprobe test_dynamic_debug \
+ modprobe $modname \
dyndbg=class,D2_CORE,+T:bupkus.mf%class,D2_KMS,+T:bupkus.mf%class,V3,+T:bupkus.mf
# test various name misses
@@ -524,8 +537,7 @@ function test_private_trace_mixed_class {
ddcmd "module params =:0."
check_match_ct =T:bupkus.mf 3 # the 3 classes enabled above
- # enable the 5 non-class'd pr_debug()s
- ddcmd "module test_dynamic_debug =T:bupkus"
+ ddcmd "module $modname =T:bupkus" # enable the 5 non-class'd pr_debug()s
check_match_ct =T:bupkus 8 -r # 8=5+3
doprints
@@ -538,18 +550,6 @@ function test_private_trace_mixed_class {
ddcmd close,bupkus
is_trace_instance_closed bupkus
- # check results
- eyeball_ref=<<EOD
- modprobe-1173 [001] ..... 7.781008: 0: test_dynamic_debug:do_cats: test_dd: D2_CORE msg
- modprobe-1173 [001] ..... 7.781010: 0: test_dynamic_debug:do_cats: test_dd: D2_KMS msg
- modprobe-1173 [001] ..... 7.781010: 0: test_dynamic_debug:do_levels: test_dd: V3 msg
- cat-1214 [001] ..... 7.905494: 0: test_dd: doing categories
- cat-1214 [001] ..... 7.905495: 0: test_dynamic_debug:do_cats: test_dd: D2_CORE msg
- cat-1214 [001] ..... 7.905496: 0: test_dynamic_debug:do_cats: test_dd: D2_KMS msg
- cat-1214 [001] ..... 7.905497: 0: test_dd: doing levels
- cat-1214 [001] ..... 7.905498: 0: test_dynamic_debug:do_levels: test_dd: V3 msg
-EOD
-
# validate the 3 enabled class'd sites, with mf prefix
search_trace_name bupkus 0 "test_dynamic_debug:do_cats: test_dd: D2_CORE msg"
search_trace_name bupkus 0 "test_dynamic_debug:do_cats: test_dd: D2_KMS msg"
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
read_args() fails on '_' (the last opt-char), and returns null.
report this against the opt-char.
Signed-off-by: Jim Cromie <[email protected]>
---
lib/dynamic_debug.c | 5 ++++-
1 file changed, 4 insertions(+), 1 deletion(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 089765afc972..3d0c6b5faa31 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -903,8 +903,11 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
read_args = opt_array[i].read_args;
if (read_args) {
str = read_args(str, modifiers);
- if (!str)
+ if (!str) {
+ pr_err("err on '%c'\n",
+ opt_array[i].opt_char);
return -EINVAL;
+ }
}
break;
}
--
2.43.0.687.g38aa6559b0-goog
Add test which verifies different combinations of flags
and trace destination.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
.../dynamic_debug/dyndbg_selftest.sh | 98 +++++++++++++++++++
1 file changed, 98 insertions(+)
diff --git a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
index f8b81e8a3bd6..4a0340d2c3e8 100755
--- a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
+++ b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
@@ -246,6 +246,103 @@ function test_percent_splitting {
ifrmmod test_dynamic_debug
}
+# test verifies different combinations of flags and trace destination
+function test_flags {
+ echo -e "${GREEN}# TEST_FLAGS ${NC}"
+
+ modprobe test_dynamic_debug dyndbg=+Tlm
+ check_match_ct =Tml 5 -v
+
+ ddcmd open selftest
+ check_trace_instance_dir selftest 1
+ is_trace_instance_opened selftest
+
+ # invalid combinations of flags and trace destination
+ ddcmd module test_dynamic_debug =Tm:0 fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =Tm:0. fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =T:m.:0 fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =T:m.:0. fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =:0lT fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =:0lT. fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =:0.lm:0 fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =:0.lmT. fail
+ check_err_msg "Invalid argument"
+
+ ddcmd module test_dynamic_debug =Tm:selftest fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =Tm:selftest. fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =T:m.:selftest fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =T:m.:selftest. fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =:selftestlT fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =:selftestlT. fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =:selftest.lm:0 fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =:selftest.lmT fail
+ check_err_msg "Invalid argument"
+
+ ddcmd module test_dynamic_debug =Tl.m fail
+ check_err_msg "Invalid argument"
+ ddcmd module test_dynamic_debug =T.lm fail
+ check_err_msg "Invalid argument"
+
+ # valid combinations of flags and trace destination
+ ddcmd module test_dynamic_debug =p
+ check_match_ct =p 5 -v
+ ddcmd module test_dynamic_debug =T
+ check_match_ct =T:selftest 5 -v
+ ddcmd module test_dynamic_debug =_
+ check_match_ct =:selftest 5 -v
+
+ ddcmd module test_dynamic_debug =T:0
+ check_match_ct =T 5 -v
+ ddcmd module test_dynamic_debug -_
+ check_match_ct =T 5 -v
+ ddcmd module test_dynamic_debug =T:0.mf
+ check_match_ct =Tmf 5 -v
+ ddcmd module test_dynamic_debug =T:selftest
+ check_match_ct =T:selftest 5 -v
+ ddcmd module test_dynamic_debug =T:selftest.mf
+ check_match_ct =T:selftest.mf 5 -v
+ ddcmd module test_dynamic_debug =_:selftest
+ check_match_ct =:selftest 5 -v
+
+ ddcmd module test_dynamic_debug =:0
+ ddcmd module test_dynamic_debug =:selftest
+ check_match_ct =:selftest 5 -v
+ ddcmd module test_dynamic_debug =p:selftest
+ check_match_ct =p:selftest 5 -v
+ ddcmd module test_dynamic_debug +_
+ check_match_ct =p:selftest 5 -v
+
+ ddcmd module test_dynamic_debug =T:selftest.mlf
+ ddcmd module test_dynamic_debug =:0
+ check_match_ct =Tmfl 5 -v
+ ddcmd module test_dynamic_debug =:selftest
+ check_match_ct =T:selftest.mfl 5 -v
+ ddcmd module test_dynamic_debug =:0
+ check_match_ct =Tmfl 5 -v
+ ddcmd module test_dynamic_debug =_:selftest
+ check_match_ct =:selftest 5 -v
+
+ ddcmd module test_dynamic_debug =:0.
+
+ ddcmd close selftest
+ is_trace_instance_closed selftest
+ ifrmmod test_dynamic_debug
+}
+
function test_actual_trace {
echo -e "${GREEN}# TEST_ACTUAL_TRACE ${NC}"
ddcmd =_
@@ -692,6 +789,7 @@ tests_list=(
basic_tests
comma_terminator_tests
test_percent_splitting
+ test_flags
test_actual_trace
cycle_tests_normal
cycle_not_best_practices
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
currently, for verbose=3, these are logged for each query
dyndbg: query 0: <class DRM_UT_CORE +p> mod: <*>
dyndbg: split into words: "class" "DRM_UT_CORE" "+p"
dyndbg: op='+'
dyndbg: flags=0x1
dyndbg: *flagsp=0x1 *maskp=0xffffffff
dyndbg: parsed: func="" file="" module="" format="" lineno=0-0 class=...
dyndbg: no matches for query
dyndbg: no-match: func="" file="" module="" format="" lineno=0-0 class=...
dyndbg: processed 1 queries, with 0 matches, 0 errs
That is excessive, so this patch shrinks it to 4 lines:
dyndbg: query 0: <class D2_CORE +T:foo > on module: <*>
dyndbg: split into words: "class" "D2_CORE" "+T:foo"
dyndbg: op='+' flags=0x40 maskp=0xffffffff trace_dest=0x0
dyndbg: applied: func="" file="" module="" format="" lineno=0-0 class=...
Signed-off-by: Jim Cromie <[email protected]>
---
lib/dynamic_debug.c | 7 ++-----
1 file changed, 2 insertions(+), 5 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index a6c6392cde3e..4954d3e5be5b 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -871,7 +871,6 @@ static int ddebug_parse_query(char *words[], int nwords,
*/
query->module = modname;
- vpr_info_dq(query, "parsed");
return 0;
}
@@ -896,7 +895,6 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
pr_err("bad flag-op %c, at start of %s\n", *str, str);
return -EINVAL;
}
- v3pr_info("op='%c'\n", op);
for (; *str ; ++str) {
for (i = ARRAY_SIZE(opt_array) - 1; i >= 0; i--) {
@@ -916,7 +914,6 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
return -EINVAL;
}
}
- v3pr_info("flags=0x%x, trace_dest=0x%x\n", modifiers->flags, modifiers->trace_dst);
/* calculate final flags, mask based upon op */
switch (op) {
@@ -933,8 +930,8 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
break;
}
- v3pr_info("flags=0x%x mask=0x%x, trace_dest=0x%x\n",
- modifiers->flags, modifiers->mask, modifiers->trace_dst);
+ v3pr_info("op='%c' flags=0x%x mask=0x%x trace_dest=0x%x\n",
+ op, modifiers->flags, modifiers->mask, modifiers->trace_dst);
return 0;
}
--
2.43.0.687.g38aa6559b0-goog
From: Jim Cromie <[email protected]>
Add a selftest script for dynamic-debug, in the extant framework,
with other parts based upon ../users/*
This is v3 of an informal test-script started and developed
out-of-tree by the signers below, refined here for the framework.
As of now it passes basic-tests, percent-tests, etc, and most of the
test_private_trace_N() test-scripts; breaking on _6.
Strategy:
- select builtins to manipulate & count callsites
file init/main.c; module mm_init, module params, not modular usbcore.
these should be stable for counting, ref-check.
params handling during modprobe is observable, verifiable.
- use callsite counts from minimal virtme-ng config (vng -bv)
test the stability of counts against this ref.
- modprobe test_dynamic_debug dyndbg=$variations for @list;
this allows to also test do_prints results,
esp against a managed +T:private_buf. (undeveloped fns yet)
later: it may allow to enable and validate dyndbg param processing
NOTES:
"module main" also finds power/main.c and module/main.c, which means
it might appear again with any new module with a main.c, and by itself
is not as stable a count as we'd like to use.
Its likely possible to test more of the early tests using builtins,
and avoiding modprobe based tests and the implied CONFIG_MODULES
dependency. Best is doing the extra modprobe testing when its
available, and not as hard config dep. For later.
Also rename check_matches() to check_match_ct(), to imply method.
TLDR - for further review, refine, re-edit.
dyndbg-test: fixes to pass tests up thru test_private_trace_5
test-count adjustments to pass test_private_trace_2
For test_private_trace_5 and support fns:
s/usbcore/params/ - prefer builtin to an optional modular one.
s/usb_stream/kparm_stream/
ALSO: trace_5 has some residual usb names I just noticed.
can you find suitable / arbitrary / distinctive renames ?
foo bar yada are fine by me.
We need more bupkus. Or maybe open bupkus!
A few -v's to see whats going on, (dont need to keep these).
Maybe later replace these with $v_normal, $v_private, etc,
with or without the implied -v* option handling.
Signed-off-by: Jim Cromie <[email protected]>
Co-developed-by: Łukasz Bartosik <[email protected]>
Signed-off-by: Łukasz Bartosik <[email protected]>
---
MAINTAINERS | 1 +
.../testing/selftests/dynamic_debug/Makefile | 9 +
tools/testing/selftests/dynamic_debug/config | 1 +
.../dynamic_debug/dyndbg_selftest.sh | 672 ++++++++++++++++++
4 files changed, 683 insertions(+)
create mode 100644 tools/testing/selftests/dynamic_debug/Makefile
create mode 100644 tools/testing/selftests/dynamic_debug/config
create mode 100755 tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
diff --git a/MAINTAINERS b/MAINTAINERS
index b584a8468fb9..2647ce78cbfb 100644
--- a/MAINTAINERS
+++ b/MAINTAINERS
@@ -7459,6 +7459,7 @@ F: include/linux/dynamic_debug.h
F: include/trace/events/dyndbg.h
F: lib/dynamic_debug.c
F: lib/test_dynamic_debug.c
+F: tools/testing/selftest/dynamic_debug/dyndbg_selftest.sh
DYNAMIC INTERRUPT MODERATION
M: Tal Gilboa <[email protected]>
diff --git a/tools/testing/selftests/dynamic_debug/Makefile b/tools/testing/selftests/dynamic_debug/Makefile
new file mode 100644
index 000000000000..e90c8e70f320
--- /dev/null
+++ b/tools/testing/selftests/dynamic_debug/Makefile
@@ -0,0 +1,9 @@
+# SPDX-License-Identifier: GPL-2.0-only
+# Makefile for user memory selftests
+
+# No binaries, but make sure arg-less "make" doesn't trigger "run_tests"
+all:
+
+TEST_PROGS := dyndbg_selftest.sh
+
+include ../lib.mk
diff --git a/tools/testing/selftests/dynamic_debug/config b/tools/testing/selftests/dynamic_debug/config
new file mode 100644
index 000000000000..ad47b70fa2b3
--- /dev/null
+++ b/tools/testing/selftests/dynamic_debug/config
@@ -0,0 +1 @@
+CONFIG_TEST_DYNAMIC_DEBUG=m
diff --git a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
new file mode 100755
index 000000000000..a48cb57aa5cb
--- /dev/null
+++ b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
@@ -0,0 +1,672 @@
+# SPDX-License-Identifier: GPL-2.0-only
+#!/bin/bash
+# shell-fns & test-script for dynamic-debug
+# run as: make run_tests, or:
+# vng -v -e path_to_dyndbg_selftest.sh
+
+RED="\033[0;31m"
+GREEN="\033[0;32m"
+YELLOW="\033[0;33m"
+BLUE="\033[0;34m"
+MAGENTA="\033[0;35m"
+CYAN="\033[0;36m"
+NC="\033[0;0m"
+error_msg=""
+v_search_trace=0 # 1 to enable verbose search-trace
+
+function vx () {
+ echo $1 > /sys/module/dynamic_debug/parameters/verbose
+}
+
+function ddgrep () {
+ grep $1 /proc/dynamic_debug/control
+}
+
+function doprints () {
+ cat /sys/module/test_dynamic_debug/parameters/do_prints
+}
+
+function ddcmd () {
+ exp_exit_code=0
+ num_args=$#
+ if [ "${@:$#}" = "pass" ]; then
+ num_args=$#-1
+ elif [ "${@:$#}" = "fail" ]; then
+ num_args=$#-1
+ exp_exit_code=1
+ fi
+ args=${@:1:$num_args}
+ output=$((echo "$args" > /proc/dynamic_debug/control) 2>&1)
+ exit_code=$?
+ error_msg=$(echo $output | cut -d ":" -f 5 | sed -e 's/^[[:space:]]*//')
+ handle_exit_code $BASH_LINENO $FUNCNAME $exit_code $exp_exit_code
+}
+
+function handle_exit_code() {
+ local exp_exit_code=0
+ [ $# == 4 ] && exp_exit_code=$4
+ if [ $3 -ne $exp_exit_code ]; then
+ echo -e "${RED}: $BASH_SOURCE:$1 $2() expected to exit with code $exp_exit_code"
+ [ $3 == 1 ] && echo "Error: '$error_msg'"
+ exit
+ fi
+}
+
+# $1 - pattern to match, pattern in $1 is enclosed by spaces for a match ""\s$1\s"
+# $2 - number of times the pattern passed in $1 is expected to match
+# $3 - optional can be set either to "-r" or "-v"
+ "-r" means relaxed matching in this case pattern provided in $1 is passed
+ as is without enclosing it with spaces
+ "-v" prints matching lines
+# $4 - optional when $3 is set to "-r" then $4 can be used to pass "-v"
+function check_match_ct {
+ pattern="\s$1\s"
+ exp_cnt=0
+
+ [ "$3" == "-r" ] && pattern="$1"
+ let cnt=$(ddgrep "$pattern" | wc -l)
+ if [ "$3" == "-v" ] || [ "$4" == "-v" ]; then
+ echo -ne "${BLUE}" && ddgrep $pattern && echo -ne "${NC}"
+ fi
+ [ $# -gt 1 ] && exp_cnt=$2
+ if [ $cnt -ne $exp_cnt ]; then
+ echo -e "${RED}: $BASH_SOURCE:$BASH_LINENO check failed expected $exp_cnt on $1, got $cnt"
+ exit
+ else
+ echo ": $cnt matches on $1"
+ fi
+}
+
+# $1 - trace instance name
+# #2 - if > 0 then directory is expected to exist, if <= 0 then otherwise
+# $3 - "-v" for verbose
+function check_trace_instance_dir {
+ if [ -e /sys/kernel/tracing/instances/$1 ]; then
+ if [ "$3" == "-v" ] ; then
+ echo "ls -l /sys/kernel/tracing/instances/$1: "
+ ls -l /sys/kernel/tracing/instances/$1
+ fi
+ if [ $2 -le 0 ]; then
+ echo -e "${RED}: $BASH_SOURCE:$BASH_LINENO error trace instance \
+ '/sys/kernel/tracing/instances/$1' does exist"
+ exit
+ fi
+ else
+ if [ $2 -gt 0 ]; then
+ echo -e "${RED}: $BASH_SOURCE:$BASH_LINENO error trace instance \
+ '/sys/kernel/tracing/instances/$1' does not exist"
+ exit
+ fi
+ fi
+}
+
+function tmark {
+ echo $* > /sys/kernel/tracing/trace_marker
+}
+
+# $1 - trace instance name
+# $2 - line number
+# $3 - if > 0 then the instance is expected to be opened, otherwise
+# the instance is expected to be closed
+function check_trace_instance {
+ output=$(tail -n9 /proc/dynamic_debug/control | grep ": Opened trace instances" \
+ | xargs -n1 | grep $1)
+ if [ "$output" != $1 ] && [ $3 -gt 0 ]; then
+ echo -e "${RED}: $BASH_SOURCE:$2 trace instance $1 is not opened"
+ exit
+ fi
+ if [ "$output" == $1 ] && [ $3 -le 0 ]; then
+ echo -e "${RED}: $BASH_SOURCE:$2 trace instance $1 is not closed"
+ exit
+ fi
+}
+
+function is_trace_instance_opened {
+ check_trace_instance $1 $BASH_LINENO 1
+}
+
+function is_trace_instance_closed {
+ check_trace_instance $1 $BASH_LINENO 0
+}
+
+# $1 - trace instance directory to delete
+# $2 - if > 0 then directory is expected to be deleted successfully, if <= 0 then otherwise
+function del_trace_instance_dir() {
+ exp_exit_code=1
+ [ $2 -gt 0 ] && exp_exit_code=0
+ output=$((rmdir /sys/kernel/debug/tracing/instances/$1) 2>&1)
+ exit_code=$?
+ error_msg=$(echo $output | cut -d ":" -f 3 | sed -e 's/^[[:space:]]*//')
+ handle_exit_code $BASH_LINENO $FUNCNAME $exit_code $exp_exit_code
+}
+
+function error_log_ref {
+ # to show what I got
+ : echo "# error-log-ref: $1"
+ : echo cat \$2
+}
+
+function ifrmmod {
+ lsmod | grep $1 2>&1>/dev/null || echo $1 not there
+ lsmod | grep $1 2>&1>/dev/null && rmmod $1
+}
+
+# $1 - text to search for
+function search_trace() {
+ search_trace_name 0 1 $1
+}
+
+# $1 - trace instance name, 0 for global event trace
+# $2 - line number counting from the bottom
+# $3 - text to search for
+function search_trace_name() {
+ if [ "$1" = "0" ]; then
+ buf=$(cat /sys/kernel/debug/tracing/trace)
+ line=$(tail -$2 /sys/kernel/debug/tracing/trace | head -1 | sed -e 's/^[[:space:]]*//')
+ else
+ buf=$(cat /sys/kernel/debug/tracing/instances/$1/trace)
+ line=$(tail -$2 /sys/kernel/debug/tracing/instances/$1/trace | head -1 | \
+ sed -e 's/^[[:space:]]*//')
+ fi
+ if [ $2 = 0 ]; then
+ # whole-buf check
+ output=$(echo $buf | grep "$3")
+ else
+ output=$(echo $line | grep "$3")
+ fi
+ if [ "$output" = "" ]; then
+ echo -e "${RED}: $BASH_SOURCE:$BASH_LINENO search for '$3' failed \
+ in line '$line' or '$buf'"
+ exit
+ fi
+ if [ $v_search_trace = 1 ]; then
+ echo -e "${MAGENTA}: search_trace_name in $1 found: \n$output \nin:${BLUE} $buf ${NC}"
+ fi
+}
+
+# $1 - error message to check
+function check_err_msg() {
+ if [ "$error_msg" != "$1" ]; then
+ echo -e "${RED}: $BASH_SOURCE:$BASH_LINENO error message '$error_msg' \
+ does not match with '$1'"
+ exit
+ fi
+}
+
+function basic_tests {
+ echo -e "${GREEN}# BASIC_TESTS ${NC}"
+ ddcmd =_ # zero everything (except class'd sites)
+ check_match_ct =p 0
+ # there are several main's :-/
+ ddcmd module main file */module/main.c +p
+ check_match_ct =p 14
+ ddcmd =_
+ check_match_ct =p 0
+ # multi-cmd input, newline separated, with embedded comments
+ cat <<"EOF" > /proc/dynamic_debug/control
+ module main +mf # multi-query
+ module main file init/main.c +ml # newline separated
+EOF
+ # the intersection of all those main's is hard to track/count
+ # esp when mixed with overlapping greps
+ check_match_ct =mf 21
+ check_match_ct =ml 0
+ check_match_ct =mfl 6
+ ddcmd =_
+}
+
+function comma_terminator_tests {
+ echo -e "${GREEN}# COMMA_TERMINATOR_TESTS ${NC}"
+ # try combos of space & comma
+ check_match_ct '\[params\]' 4 -r
+ ddcmd module,params,=_ # commas as spaces
+ ddcmd module,params,+mpf # turn on non-classed
+ check_match_ct =pmf 4
+ ddcmd ,module ,, , params, -p # extra commas & spaces
+ check_match_ct =mf 4
+ ddcmd =_
+}
+
+function test_percent_splitting {
+ echo -e "${GREEN}# TEST_PERCENT_SPLITTING - multi-command splitting on % ${NC}"
+ ifrmmod test_dynamic_debug
+ ddcmd =_
+ modprobe test_dynamic_debug dyndbg=class,D2_CORE,+pf%class,D2_KMS,+pt%class,D2_ATOMIC,+pm
+ check_match_ct =pf 1
+ check_match_ct =pt 1
+ check_match_ct =pm 1
+ check_match_ct test_dynamic_debug 32 -r -v
+ ddcmd class,D2_CORE,+mf%class,D2_KMS,+lt%class,D2_ATOMIC,+ml "# add some prefixes"
+ check_match_ct =pmf 1
+ check_match_ct =plt 1
+ check_match_ct =pml 1
+ check_match_ct test_dynamic_debug -r 32
+ ifrmmod test_dynamic_debug
+}
+
+function test_actual_trace {
+ echo -e "${GREEN}# TEST_ACTUAL_TRACE ${NC}"
+ ddcmd =_
+ echo > /sys/kernel/tracing/trace
+ echo 1 >/sys/kernel/tracing/tracing_on
+ echo 1 >/sys/kernel/tracing/events/dyndbg/enable
+ modprobe test_dynamic_debug dyndbg=class,D2_CORE,+T:0
+ search_trace "D2_CORE msg"
+ search_trace_name 0 1 "D2_CORE msg"
+ check_match_ct =T 1
+ tmark "here comes the WARN"
+ search_trace "here comes the WARN"
+ doprints
+ search_trace "D2_CORE msg"
+ ifrmmod test_dynamic_debug
+}
+
+function self_start {
+ echo \# open, modprobe +T:selftest
+ ddcmd open selftest
+ check_trace_instance_dir selftest 1
+ is_trace_instance_opened selftest
+ modprobe test_dynamic_debug dyndbg=+T:selftest.mf
+ check_match_ct =T:selftest.mf 5
+}
+
+function self_end_normal {
+ echo \# disable -T:selftest, rmmod, close
+ ddcmd module test_dynamic_debug -T:selftest # leave mf
+ check_match_ct =:selftest.mf 5 -v
+ ddcmd module test_dynamic_debug +:0
+ ddcmd close selftest
+ is_trace_instance_closed selftest
+ ifrmmod test_dynamic_debug
+}
+
+function self_end_disable_anon {
+ echo \# disable, close, rmmod
+ ddcmd module test_dynamic_debug -T
+ check_match_ct =:selftest.mf 5
+ ddcmd module test_dynamic_debug +:0
+ ddcmd close selftest
+ is_trace_instance_closed selftest
+ ifrmmod test_dynamic_debug
+}
+
+function self_end_disable_anon_mf {
+ echo \# disable, close, rmmod
+ ddcmd module test_dynamic_debug -Tf
+ check_match_ct =:selftest.m 5
+ ddcmd module test_dynamic_debug +:0
+ ddcmd close selftest
+ is_trace_instance_closed selftest
+ ifrmmod test_dynamic_debug
+}
+
+function self_end_nodisable {
+ echo \# SKIPPING: ddcmd module test_dynamic_debug -T:selftest
+ ddcmd close selftest fail # close fails because selftest is still being used
+ check_err_msg "Device or resource busy"
+ check_match_ct =T:selftest.mf 5
+ rmmod test_dynamic_debug
+ ddcmd close selftest # now selftest can be closed because rmmod removed
+ # all callsites which were using it
+ is_trace_instance_closed selftest
+}
+
+function self_end_delete_directory {
+ del_trace_instance_dir selftest 0
+ check_err_msg "Device or resource busy"
+ ddcmd module test_dynamic_debug -mT:selftest
+ check_match_ct =:selftest.f 5
+ del_trace_instance_dir selftest 0
+ check_err_msg "Device or resource busy"
+ ddcmd module test_dynamic_debug +:0
+ ddcmd close selftest
+ check_trace_instance_dir selftest 1
+ is_trace_instance_closed selftest
+ del_trace_instance_dir selftest 1
+ check_trace_instance_dir selftest 0
+}
+
+function test_early_close () {
+ ddcmd open kparm_stream
+ ddcmd module usbcore +T:kparm_stream.mf
+ check_match_ct =T:usb_stream.mf 161
+ echo ":not-running # ddcmd module usbcore -T:kparm_stream.mf"
+ ddcmd close kparm_stream
+}
+
+function self_test_ {
+ echo "# SELFTEST $1"
+ self_start
+ self_end_$1
+}
+
+function cycle_tests_normal {
+ echo -e "${GREEN}# CYCLE_TESTS_NORMAL ${NC}"
+ self_test_ normal # ok
+ self_test_ disable_anon # ok
+ self_test_ normal # ok
+ self_test_ disable_anon_mf # ok
+}
+
+function cycle_not_best_practices {
+ echo -e "${GREEN}# CYCLE_TESTS_PROBLEMS ${NC}"
+ self_test_ nodisable
+ self_test_ normal
+ self_test_ delete_directory
+}
+
+# proper life cycle - open, enable:named, disable:named, close
+function test_private_trace_simple_proper {
+ echo -e "${GREEN}# TEST_PRIVATE_TRACE_1 ${NC}"
+ # ddcmd close kparm_stream
+ ddcmd open kparm_stream
+ ddcmd module params +T:kparm_stream.mf
+ check_match_ct =T:kparm_stream.mf 4
+ ddcmd module params -T:kparm_stream.mf
+ check_match_ct =T:kparm_stream.mf 0
+ is_trace_instance_opened kparm_stream
+ ddcmd module params +:0
+ ddcmd close kparm_stream
+ is_trace_instance_closed kparm_stream
+ ddcmd =_
+ check_trace_instance_dir kparm_stream 1
+ is_trace_instance_closed kparm_stream
+ del_trace_instance_dir kparm_stream 1
+ check_trace_instance_dir kparm_stream 0
+}
+
+function test_private_trace_2 {
+ echo -e "${GREEN}# TEST_PRIVATE_TRACE_2 ${NC}"
+ ddcmd =_
+ echo > /sys/kernel/tracing/trace
+ echo 1 >/sys/kernel/tracing/tracing_on
+ echo 1 >/sys/kernel/tracing/events/dyndbg/enable
+ ddcmd open foo
+ is_trace_instance_opened foo
+ check_trace_instance_dir foo 1
+
+ modprobe test_dynamic_debug
+ ddcmd class,D2_CORE,+T:foo.l,%class,D2_KMS,+fT:foo.ml
+ check_match_ct =T:foo.l 1
+ check_match_ct =T:foo.mfl 1
+
+ # purpose ?
+ echo 1 >/sys/kernel/tracing/tracing_on
+ echo 1 >/sys/kernel/tracing/events/dyndbg/enable
+
+ tmark test_private_trace about to do_prints
+ search_trace "test_private_trace about to do_prints"
+ search_trace_name "0" 1 "test_private_trace about to do_prints"
+
+ doprints
+ ddcmd class,D2_CORE,-T:foo
+ ddcmd close foo fail
+ check_err_msg "Device or resource busy"
+ ddcmd class,D2_KMS,-T:foo
+ ddcmd close foo
+ check_trace_instance_dir foo 1
+ is_trace_instance_closed foo
+ ddcmd close bar fail
+ check_err_msg "No such file or directory"
+ ifrmmod test_dynamic_debug
+ search_trace_name foo 2 "D2_CORE msg"
+ search_trace_name foo 1 "D2_KMS msg"
+ del_trace_instance_dir foo 1
+ check_trace_instance_dir foo 0
+}
+
+function test_private_trace_3 {
+ echo -e "${GREEN}# TEST_PRIVATE_TRACE_3 ${NC}"
+ ddcmd =_
+ echo > /sys/kernel/tracing/trace
+ echo 1 >/sys/kernel/tracing/tracing_on
+ echo 1 >/sys/kernel/tracing/events/dyndbg/enable
+ ddcmd open foo \; open bar
+ is_trace_instance_opened foo
+ is_trace_instance_opened bar
+ modprobe test_dynamic_debug
+ ddcmd class,D2_CORE,+T:foo
+ ddcmd class,D2_KMS,+T:foo
+ ddcmd class D2_CORE +T:foo \; class D2_KMS +T:foo
+ ddcmd "class,D2_CORE,+T:foo;,class,D2_KMS,+T:foo"
+ ddcmd class,D2_CORE,+T:foo\;class,D2_KMS,+T:foo
+ check_match_ct =T 2 -v
+ check_match_ct =Tl 0
+ check_match_ct =Tmf 0
+ echo 1 >/sys/kernel/tracing/tracing_on
+ echo 1 >/sys/kernel/tracing/events/dyndbg/enable
+ tmark test_private_trace_2 about to do_prints
+ doprints
+ rmmod test_dynamic_debug
+ ddcmd "close bar;close foo"
+ is_trace_instance_closed bar
+ is_trace_instance_closed foo
+ search_trace_name foo 2 "D2_CORE msg"
+ search_trace_name foo 1 "D2_KMS msg"
+ del_trace_instance_dir foo 1
+ check_trace_instance_dir foo 0
+ search_trace "test_private_trace_2 about to do_prints"
+ del_trace_instance_dir bar 1
+ check_trace_instance_dir bar 0
+}
+
+function test_private_trace_4 {
+ echo -e "${GREEN}# TEST_PRIVATE_TRACE_4 ${NC}"
+ ddcmd =_
+ echo > /sys/kernel/tracing/trace
+ echo 1 >/sys/kernel/tracing/tracing_on
+ echo 1 >/sys/kernel/tracing/events/dyndbg/enable
+
+ ddcmd open foo
+ modprobe test_dynamic_debug dyndbg=class,D2_CORE,+T:foo%class,D2_KMS,+T:foo
+ check_match_ct =Tl 0
+ check_match_ct =Tmf 0
+ check_match_ct =T 2
+
+ # are these 2 doing anything ?
+ echo 1 >/sys/kernel/tracing/tracing_on
+ echo 1 >/sys/kernel/tracing/events/dyndbg/enable
+
+ tmark should be ready
+ search_trace_name "0" 0 "should be ready" # in global trace
+
+ doprints
+ search_trace_name foo 2 "D2_CORE msg" # in private buf
+ search_trace_name foo 1 "D2_KMS msg"
+
+ # premature delete
+ del_trace_instance_dir foo 0
+ check_trace_instance_dir foo 1 # doesn't delete
+ ifrmmod test_dynamic_debug
+
+ ddcmd "close foo"
+ is_trace_instance_closed foo
+ del_trace_instance_dir foo 1 # delete works now
+
+ check_trace_instance_dir foo 0
+ search_trace "should be ready"
+}
+
+# $1 - trace-buf-name (or "0")
+# $2 - reference-buffer
+function search_in_trace_for {
+ bufname=$1; shift;
+ ref=$2;
+ ref2=$(echo $ref | cut -c20-)
+ echo $ref2
+}
+
+function test_private_trace_mixed_class {
+ echo -e "${GREEN}# TEST_PRIVATE_TRACE_5 ${NC}"
+ ddcmd =_
+ ddcmd module,params,+T:unopened fail
+ check_err_msg "Invalid argument"
+ is_trace_instance_closed unopened
+ check_trace_instance_dir unopened 0
+
+ ddcmd open bupkus
+ is_trace_instance_opened bupkus
+ check_trace_instance_dir bupkus 1
+ modprobe test_dynamic_debug \
+ dyndbg=class,D2_CORE,+T:bupkus.mf%class,D2_KMS,+T:bupkus.mf%class,V3,+T:bupkus.mf
+
+ # test various name misses
+ ddcmd "module params =T:bupkus1" fail # miss on name
+ check_err_msg "Invalid argument"
+ ddcmd "module params =T:unopened" fail # unopened
+ check_err_msg "Invalid argument"
+
+ ddcmd "module params =mlfT:bupkus." # we allow dot at the end of flags
+ ddcmd "module params =T:bupkus."
+ ddcmd "module params =:bupkus."
+ ddcmd "module params =:0."
+
+ check_match_ct =T:bupkus.mf 3 # the 3 classes enabled above
+ # enable the 5 non-class'd pr_debug()s
+ ddcmd "module test_dynamic_debug =T:bupkus"
+ check_match_ct =T:bupkus 8 -r # 8=5+3
+
+ doprints
+ ddcmd close,bupkus fail
+ check_err_msg "Device or resource busy"
+ ddcmd "module * -T:0" # misses class'd ones
+ ddcmd close,bupkus fail
+
+ ddcmd class,D2_CORE,-T:0%class,D2_KMS,-T:0%class,V3,-T:0 # turn off class'd and set dest to 0
+ ddcmd close,bupkus
+ is_trace_instance_closed bupkus
+
+ # check results
+ eyeball_ref=<<EOD
+ modprobe-1173 [001] ..... 7.781008: 0: test_dynamic_debug:do_cats: test_dd: D2_CORE msg
+ modprobe-1173 [001] ..... 7.781010: 0: test_dynamic_debug:do_cats: test_dd: D2_KMS msg
+ modprobe-1173 [001] ..... 7.781010: 0: test_dynamic_debug:do_levels: test_dd: V3 msg
+ cat-1214 [001] ..... 7.905494: 0: test_dd: doing categories
+ cat-1214 [001] ..... 7.905495: 0: test_dynamic_debug:do_cats: test_dd: D2_CORE msg
+ cat-1214 [001] ..... 7.905496: 0: test_dynamic_debug:do_cats: test_dd: D2_KMS msg
+ cat-1214 [001] ..... 7.905497: 0: test_dd: doing levels
+ cat-1214 [001] ..... 7.905498: 0: test_dynamic_debug:do_levels: test_dd: V3 msg
+EOD
+
+ # validate the 3 enabled class'd sites, with mf prefix
+ search_trace_name bupkus 0 "test_dynamic_debug:do_cats: test_dd: D2_CORE msg"
+ search_trace_name bupkus 0 "test_dynamic_debug:do_cats: test_dd: D2_KMS msg"
+ search_trace_name bupkus 0 "test_dynamic_debug:do_levels: test_dd: V3 msg"
+
+ search_trace_name bupkus 0 "test_dd: doing levels"
+ search_trace_name bupkus 0 "test_dd: doing categories"
+
+ # reopen wo error
+ ddcmd open bupkus
+ is_trace_instance_opened bupkus
+ check_trace_instance_dir bupkus 1
+
+ ddcmd "module test_dynamic_debug =T:bupkus" # rearm the 5 plain-old prdbgs
+ check_match_ct =T:bupkus 5
+
+ doprints # 2nd time
+ search_trace_name bupkus 0 "test_dd: doing categories"
+ search_trace_name bupkus 0 "test_dd: doing levels""
+ search_trace_name bupkus 2 "test_dd: doing categories"
+ search_trace_name bupkus 1 "test_dd: doing levels""
+
+ ddcmd close,bupkus fail
+ check_err_msg "Device or resource busy"
+ del_trace_instance_dir bupkus 0
+ check_err_msg "Device or resource busy"
+ check_trace_instance_dir bupkus 1
+ is_trace_instance_opened bupkus
+ check_trace_instance_dir bupkus 1
+
+ # drop last users, now delete works
+ ddcmd "module * -T:0"
+ ddcmd close,bupkus
+ is_trace_instance_closed bupkus
+ del_trace_instance_dir bupkus 1
+ check_trace_instance_dir bupkus 0
+ ifrmmod test_dynamic_debug
+}
+
+function test_private_trace_overlong_name {
+ echo -e "${GREEN}# TEST_PRIVATE_TRACE_overlong_name ${NC}"
+ ddcmd =_
+ name="A_bit_lengthy_trace_instance_name"
+ ddcmd open $name
+ is_trace_instance_opened $name
+ check_trace_instance_dir $name 1
+
+ ddcmd "file kernel/module/main.c +T:$name.mf "
+ check_match_ct =T:A_bit_lengthy_trace_....mf 14
+
+ ddcmd "module * -T"
+ check_match_ct =:A_bit_lengthy_trace_....mf 14
+ check_match_ct kernel/module/main.c 14 -r # to be certain
+
+ ddcmd "module * -T:0"
+ ddcmd close,$name
+ is_trace_instance_closed $name
+ del_trace_instance_dir $name 1
+ check_trace_instance_dir $name 0
+}
+
+function test_private_trace_fill_trace_index {
+ echo -e "${GREEN}# TEST_PRIVATE_TRACE_fill_trace_index ${NC}"
+ ddcmd =_
+ name="trace_instance_"
+ for i in {1..63}
+ do
+ ddcmd open $name$i
+ is_trace_instance_opened $name$i
+ check_trace_instance_dir $name$i 1
+ done
+ # catch the 1-too-many err
+ ddcmd "open too_many" fail
+ check_err_msg "No space left on device"
+
+ ddcmd 'file kernel/module/main.c =T:trace_instance_63.m'
+ check_match_ct =T:trace_instance_63.m 14
+
+ for i in {1..62}
+ do
+ ddcmd close $name$i
+ is_trace_instance_closed $name$i
+ del_trace_instance_dir $name$i 1
+ check_trace_instance_dir $name$i 0
+ done
+ ddcmd "module * -T:0"
+ ddcmd close,trace_instance_63
+ is_trace_instance_closed trace_instance_63
+ del_trace_instance_dir trace_instance_63 1
+ check_trace_instance_dir trace_instance_63 0
+}
+
+tests_list=(
+ basic_tests
+ comma_terminator_tests
+ test_percent_splitting
+ test_actual_trace
+ cycle_tests_normal
+ cycle_not_best_practices
+ test_private_trace_1
+ test_private_trace_simple_proper
+ test_private_trace_2
+ test_private_trace_3
+ test_private_trace_4
+ test_private_trace_mixed_class
+ test_private_trace_mixed_class # again, to test pre,post conditions
+
+ test_private_trace_overlong_name
+
+ # works, takes 30 sec
+ test_private_trace_fill_trace_index
+)
+
+# Run tests
+
+for test in "${tests_list[@]}"
+do
+ $test
+ echo ""
+done
+echo -en "${GREEN}# Done on: "
+date
--
2.43.0.687.g38aa6559b0-goog
Add test which verifies default trace destination feature.
Signed-off-by: Łukasz Bartosik <[email protected]>
---
.../dynamic_debug/dyndbg_selftest.sh | 75 +++++++++++++++++++
1 file changed, 75 insertions(+)
diff --git a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
index 4a0340d2c3e8..ae386e4de6a4 100755
--- a/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
+++ b/tools/testing/selftests/dynamic_debug/dyndbg_selftest.sh
@@ -195,6 +195,16 @@ function check_err_msg() {
fi
}
+# $1 - default destination to check
+function check_default_dst() {
+ dst=$(tail -50 /proc/dynamic_debug/control | grep "#: Default trace destination" | \
+ cut -d':' -f3 | sed -e 's/^[[:space:]]*//')
+ if [ "$dst" != "$1" ]; then
+ echo -e "${RED}: $BASH_SOURCE:$BASH_LINENO default dest '$dst' does not match with '$1'"
+ exit
+ fi
+}
+
function basic_tests {
echo -e "${GREEN}# BASIC_TESTS ${NC}"
ddcmd =_ # zero everything (except class'd sites)
@@ -343,6 +353,70 @@ function test_flags {
ifrmmod test_dynamic_debug
}
+# test verifies default destination
+function test_default_destination {
+ echo -e "${GREEN}# TEST_DEFAULT_DESTINATION ${NC}"
+
+ check_default_dst 0
+ modprobe test_dynamic_debug
+
+ ddcmd class,D2_CORE,+T # default dest is 0
+ check_match_ct =T 1 -v
+
+ ddcmd open foo # foo becomes default dest
+ is_trace_instance_opened foo
+ check_trace_instance_dir foo 1
+ check_default_dst foo
+
+ ddcmd class,D2_CORE,+T # default dest is foo
+ check_match_ct =T:foo 1 -v
+
+ ddcmd open,0 # reopening sets default dest to 0
+ check_default_dst 0
+
+ ddcmd class,D2_CORE,-T
+ check_match_ct =:foo 1 -v
+
+ ddcmd class,D2_CORE,+T # default dest is 0 but since callsite was already labelled
+ # then reuse label
+ check_match_ct =T:foo 1 -v
+
+ ddcmd open bar # bar becomes default dest
+ is_trace_instance_opened bar
+ check_trace_instance_dir bar 1
+ check_default_dst bar
+
+ ddcmd class,D2_KMS,+T # default dest is bar
+ check_match_ct =T:bar 1 -v
+
+ ddcmd class,D2_KMS,+T:0 # set 0 dest explicitly
+ check_match_ct =T 1 -v
+
+ ddcmd class,D2_KMS,-T
+
+ ddcmd open,foo # reopening sets default dest to foo
+ check_default_dst foo
+
+ ddcmd class,D2_KMS,+T # default dest is 0 but since callsite was already labelled
+ # then reuse label
+ check_match_ct =T:foo 2 -v
+
+ ddcmd "class D2_CORE -T:0"
+ ddcmd "class D2_KMS -T:0"
+ check_default_dst foo
+
+ ddcmd close foo
+ is_trace_instance_closed foo
+ check_default_dst 0 # after closing foo which was default dest we revert
+ # to 0 as default dest
+
+ ddcmd close bar
+ is_trace_instance_closed bar
+ check_default_dst 0
+
+ ifrmmod test_dynamic_debug
+}
+
function test_actual_trace {
echo -e "${GREEN}# TEST_ACTUAL_TRACE ${NC}"
ddcmd =_
@@ -790,6 +864,7 @@ tests_list=(
comma_terminator_tests
test_percent_splitting
test_flags
+ test_default_destination
test_actual_trace
cycle_tests_normal
cycle_not_best_practices
--
2.43.0.687.g38aa6559b0-goog