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

[Łukasz Bartosik]

sob., 4 lis 2023 o 02:25 <jim.cromie@xxxxxxxxx> napisał(a):
>
> Hi Łukasz,
>
> can I haz a git remote url ?
> no webmail antics that way.
>

Here you are https://chromium.googlesource.com/chromiumos/third_party/kernel/+log/refs/sandbox/ukaszb/dyndbg_trace_v1

> 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.
>

Yes +p would be independent from +T so that a given callsite debug log
could be written both to syslog and trace.

> > 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 ?
>

With open/close commands you proposed this will become obsolete.

> 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.
>

Nice comparison :). But it was pretty "socializing" as everyone could
hear a conversation which took place on such a line.

> 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
>

I agree that numbers are not very meaningful, I asked question related to your
proposal in revisited comment.


>
>
>
>
>
>
> > 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
> >