Date: Sun, 11 Feb 2024 00:50:09 +0100
From: Łukasz Bartosik <ukaszb@...omium.org>
To: Jason Baron <jbaron@...mai.com>,
	Jim Cromie <jim.cromie@...il.com>,
	Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
	Andrew Morton <akpm@...ux-foundation.org>,
	Kees Cook <keescook@...omium.org>,
	Douglas Anderson <dianders@...omium.org>
Cc: Guenter Roeck <groeck@...gle.com>,
	Yaniv Tzoreff <yanivt@...gle.com>,
	Benson Leung <bleung@...gle.com>,
	Steven Rostedt <rostedt@...dmis.org>,
	Vincent Whitchurch <vincent.whitchurch@...s.com>,
	Pekka Paalanen <ppaalanen@...il.com>,
	Sean Paul <seanpaul@...omium.org>,
	Daniel Vetter <daniel@...ll.ch>,
	Simon Ser <contact@...rsion.fr>,
	John Ogness <john.ogness@...utronix.de>,
	Petr Mladek <pmladek@...e.com>,
	Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
	linux-kernel@...r.kernel.org,
	upstream@...ihalf.com
Subject: [PATCH v4 39/39] docs/dyndbg: explain debug-to-tracefs (=T:label.flags)

From: Jim Cromie <jim.cromie@...il.com>

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 <jim.cromie@...il.com>
---
 .../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

Powered by blists - more mailing lists