Message-ID: <CAJfuBxz8mORgH9WaGVPsu7Z1cpgqWuJLxZNgFt1ocKa1sze5sw@mail.gmail.com>
Date:   Fri, 3 Nov 2023 19:25:24 -0600
From:   jim.cromie@...il.com
To:     Łukasz Bartosik <lb@...ihalf.com>
Cc:     Jason Baron <jbaron@...mai.com>,
        Andrew Morton <akpm@...ux-foundation.org>,
        Kees Cook <keescook@...omium.org>,
        Douglas Anderson <dianders@...omium.org>,
        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: Re: [PATCH v1 00/12] dyndbg: add support for writing debug logs to trace

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@...ihalf.com> 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@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: 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
>

Powered by blists - more mailing lists