Re: [PATCH v1 00/12] dyndbg: add support for writing debug logs to trace

From: jim . cromie
Date: Fri Nov 03 2023 - 21:25:56 EST


Hi Łukasz,

can I haz a git remote url ?
no webmail antics that way.

On Fri, Nov 3, 2023 at 7:10 AM Łukasz Bartosik <lb@xxxxxxxxxxxx> wrote:
>
> 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 indivdually) to trace to aid in debugging. The debug
> logs output to trace can be enabled with T flag. Additionally trace
> destination can be provided to the T flag after ":". The trace destination
> field is used to determine where debug logs will be written. Setting trace
> destination value to 0 (default) enables output to prdbg and devdbg trace

isnt +p independent of dest var ? its just "on" to syslog.

> events. Setting trace destination value to a value in range of [1..255]
> enables output to trace instance identified by trace destination value.
> For example when trace destination value is 2 then debug logs will
> be written to <debugfs>/tracing/instances/dyndbg_inst_2 instance.
>
> Usage examples:
>
> localhost ~ # echo "module thunderbolt =pT:7" >
> <debugfs>/dynamic_debug/control
>
> This will enable output of debug logs to trace instance
> <debugfs>/tracing/instances/dyndbg_inst_7 and debug logs will
> be written to the syslog also because p flag is set.
>
> localhost ~ # echo "module thunderbolt =pT:7,l" >
> <debugfs>/dynamic_debug/control
>
> When trace destination is followed by another flag then trace
> destination has to be followed by ",".
>
> localhost ~ # echo "module thunderbolt =pTl" >
> <debugfs>/dynamic_debug/control
>
> When trace destination is not provided explicitly then its value
> defaults to 0. In this case debug logs will be written to the prdbg
> and devdbg trace events.
>
> localhost ~ # echo "module thunderbolt =T:25" >
> <debugfs>/dynamic_debug/control
>
> This will enable output of debug logs to trace instance
> <debugfs>/tracing/instances/dyndbg_inst_25 with debug logs output
> to syslog disabled.
>
> Given trace instance will not be initialized until debug logs are
> requested to be written to it and afer init it will persist until
> reboot.
>

that (delayed init) might be a problem,
user side will have to look for the appearance of traces ?

Also, I have some reservations about exposing numeric destinations -
the user(space) must then decide/coordinate what dest-number
is used for which instance/purpose.

It would be fine for 1 customer, but might be a little tedious for many,
who now have to coordinate. A bit like a shared/party line in the early
days of rural telephone.

As I recall, an early early version of classmaps used numeric classes,
(taken straight from drm_debug_category).
As Jason noted (more diplomatically than I assimilated)
it was kind of arbitrary and obscure/obtuse/unhelpful numbering.

It is why I added classnames, with the bonus that
the name->num mapping was also a validation step
against known CLASSMAP_DEFINE-itions
(if you knew DRM drivers knew "DRM_KMS_CORE",
you knew what you were asking for)

Your earlier version had a dest keyword which maybe fits better with this point.
that said, it was in a selector position, so it doesnt work grammatically.

So, what do you think about a new command:

echo <<EoCMDBlk
open kms-stream
class DRM_UT_CORE +T # global
class DRM_UT_KMS +T:kms-stream
EoCMDBlk \
> /proc/dynamic/debug

this allows tracking names, assigning ids, erroring when all used,
and validating names > control
without exposing the numbers.

the open/close changes are (would be) persistent

the thing it doesnt allow is pre-selecting the destination,
then arming it later with a +T

so it doesnt (wouldnt) play super-nice with
echo 0x1F > /sys/module/drm/parameters/debug_trace

that said, we can preset the dst:

echo <<EoCMDBlk
open drm-kms-stream
open drm-core-stream
class DRM_UT_CORE -T:drm-core-stream
class DRM_UT_KMS -T:drm-kms-stream
EoCMDBlk \
> /proc/dynamic/debug

then enable whatever is preset selectively:

echo $I_forgot_the_bit > /sys/module/drm/parameters/debug_trace
OR
echo class DRM_UT_KMS +T > /proc/dynamic/debug







> Please note that output of debug logs to syslog (p flag) and trace
> (T flag) can be independently enabled/disabled for each callsite.
>

so its the specific wording I previously grumbled about, I think.

>
>
> Jim I took the liberty and based my work on your patches you pointed me
> to https://github.com/jimc/linux/tree/dd-kitchen-sink. I picked up
> the commits relevant to trace from the dd-kitchen-sink branch.
> The only changes I introduced in your commits were related to checkpatch
> complains. There are two errors still left:

Bah - macros !
I'll look at your diffs in git :-)

>
> 1)
> 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.
>
> 2)
> ERROR: Macros with complex values should be enclosed in parentheses
> 62: FILE: include/trace/stages/stage3_trace_output.h:12:
> +#define TP_printk_no_nl(fmt, args...) fmt, args
>
> I have not figured out how to fix it.

those 2 no_nl patches were pretty exploratory,
IIRC, Steve was inclined to add the \n when not already in the format.
It would be variation-proof


>
> Changes:
> V1) Major rework after receiving feedback in
> https://lore.kernel.org/all/20230915154856.1896062-1-lb@xxxxxxxxxxxx/
>
> 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: pr_debug, dev_dbg
> tracefs: add TP_printk_no_nl - RFC
> trace: use TP_printk_no_nl in dyndbg:prdbg,devdbg
> dyndbg: repack struct _ddebug
>
> Łukasz Bartosik (5):
> dyndbg: move flags field to a new structure
> dyndbg: add trace destination field to _ddebug
> dyndbg: add processing of T(race) flag argument
> dyndbg: write debug logs to trace instance
> dyndbg: add trace support for hexdump
>
> .../admin-guide/dynamic-debug-howto.rst | 5 +-
> MAINTAINERS | 1 +
> include/linux/dynamic_debug.h | 57 ++-
> include/trace/events/dyndbg.h | 54 +++
> include/trace/stages/stage3_trace_output.h | 3 +
> include/trace/stages/stage7_class_define.h | 3 +
> lib/Kconfig.debug | 1 +
> lib/dynamic_debug.c | 414 +++++++++++++++---
> 8 files changed, 465 insertions(+), 73 deletions(-)
> create mode 100644 include/trace/events/dyndbg.h
>
> --
> 2.42.0.869.gea05f2083d-goog
>