Message-ID: <20231130234048.157509-1-lb@semihalf.com>
Date:   Fri,  1 Dec 2023 00:40:33 +0100
From:   Łukasz Bartosik <lb@...ihalf.com>
To:     Jason Baron <jbaron@...mai.com>, Jim Cromie <jim.cromie@...il.com>,
        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>, linux-kernel@...r.kernel.org,
        upstream@...ihalf.com
Subject: [PATCH v2 00/15] dyndbg: add support for writing debug logs to trace

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. The debug
logs output to trace can be enabled with T flag. Additionally the T flag
accepts trace destination which can be provided to the T flag after ":".
The trace destination field is used to determine where debug logs will be
written. 

In order to redirect callsite debug log to a trace instance it has to be
initialized first with a newly introduced "open" command. For example,
"usb" trace instance in <debugfs>/tracing/instances/ can be initialized
by issuing the command:

localhost ~ # echo "open usb" >
                                <debugfs>/dynamic_debug/control

If the trace instance <debugfs>/tracing/instances/usb already exists
then it will be reused otherwise new usbcore instance will be created.
Maximum 63 trace instances can be "opened". The trace instance name can
include any of ^\w+ and underscore characters. There is also a special
name "0" reserved for writing debug logs to trace prdbg and devdbg events.
The reserved name "0" does not require to be "opened" before use.

To enable writing usbcore module debug logs to the "usb" trace instance
opened above a user can issue the command:

localhost ~ # echo "module usbcore =pT:usb" >
                                <debugfs>/dynamic_debug/control

Please note that output of debug logs to syslog (p flag) and trace (T flag)
can be independently enabled/disabled for each callsite. Therefore the
above command will enable writing of debug logs not only to the trace
instance "usb" but also to syslog.

When trace destination is followed by another flag the next flag has to
be preeceded with ",", for example

localhost ~ # echo "module usbcore =pT:usb,l" > 
                                <debugfs>/dynamic_debug/control

To simplify processing trace destination can be omitted when default
trace destination is set, for example the command

localhost ~ # echo "module usbcore =pTl" >   
                                <debugfs>/dynamic_debug/control

will use default trace destination. If default trace destination is not
set the above command will fail. The default trace destination is set
when a command with any of the flags [-+=] and explicitly provided trace
destination matches at least one callsite, for example the command

localhost ~ # echo "module usbcore -T:usb" >   
                                <debugfs>/dynamic_debug/control

will disable trace for all usbcore module callsites (if any was enabled)
and will set "usb" instance as default trace destination. To enable writing
thunderbolt module debug logs to the "usb" trace instance as well a user
can issue the command:
  
localhost ~ # echo "module thunderbolt =T" >    
                                <debugfs>/dynamic_debug/control

Since default trace destination was previously set therefore "usb" instance
name does not have to be explicitly provided.

When no callsite writes debug logs to a trace instance then it can be
released (its reference counter decrased) with the "close" command. 
Closing a trace instance make it unavailable for dynamic debug and also
allows a user to delete such a trace instance at convenient time later
with rmdir command. For example when "usb" instance is not used anymore
a user can issue the command:

localhost ~ # echo "close usb" >
                                <debugfs>/dynamic_debug/control 
and then to delete it with:

localhost ~ # rmdir <debugfs>/tracing/instances/

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 

And displayed with the command:

localhost ~ # trace-cmd show



TODOs:
- update dynamic debug documentation,
- create test harness for the verification of dynamic debug
functionality ???,



There is one checkpatch error left:

ERROR: need consistent spacing around '*' (ctx:WxV)
140: FILE: lib/dynamic_debug.c:1070:
+				  va_list *args)

Which seems to be a false positive to me.



Changes:
V2->V1
Major rework after receiving feedback in
https://lore.kernel.org/all/20231103131011.1316396-1-lb@semihalf.com/

This includes among other things:
- addition 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 side (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/20230915154856.1896062-1-lb@semihalf.com/

Jim Cromie (7):
  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 - RFC
  dyndbg: use __get_str_strip_nl in prdbg and devdbg
  dyndbg: repack _ddebug structure

Łukasz Bartosik (8):
  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: add processing of T(race) flag argument
  dyndbg: add support for default trace destination
  dyndbg: write debug logs to trace instance
  dyndbg: add support for hex_dump output to trace

 .../admin-guide/dynamic-debug-howto.rst       |   5 +-
 MAINTAINERS                                   |   1 +
 include/linux/dynamic_debug.h                 |  59 +-
 include/trace/events/dyndbg.h                 |  54 ++
 include/trace/stages/stage3_trace_output.h    |   9 +
 lib/Kconfig.debug                             |   1 +
 lib/dynamic_debug.c                           | 688 ++++++++++++++++--
 7 files changed, 735 insertions(+), 82 deletions(-)
 create mode 100644 include/trace/events/dyndbg.h

-- 
2.43.0.rc2.451.g8631bc7472-goog

Powered by blists - more mailing lists