Re: [PATCH 3/3] dyndbg: add source filename to prefix

[jim . cromie]

On Sat, Feb 4, 2023 at 7:49 AM <linux@xxxxxxxxxxxxxx> wrote:
>
> Hi Jason,
>
>
> Feb 3, 2023 10:45:49 Jason Baron <jbaron@xxxxxxxxxx>:
>
> > Hi Thomas,
> >
> > Thanks for this series, this series is fine with me:
> > Acked-by: Jason Baron <jbaron@xxxxxxxxxx>
>
> Thanks!
>
> > Your comment about making the output more relatable to the control file made me think if we should try and make the logged output look more like the control file:
> >
> > # cat /proc/dynamic_debug/control
> > # filename:lineno [module]function flags format
> >
> > So for your example, I think that would look like:
> >
> > [   71.802212] lib/test_dynamic_debug.c:103 do_cats: test_dd: doing categories
> > [   71.802227] lib/test_dynamic_debug.c:123 do_levels: doing levels
> >
> > But even if we think it looks better, there maybe too many dependencies on the current output format...
>
> I agree on both points.
>
> An alternative could be a new flag that prints the
> full format from the control file.
> The control file even has a format header that
> tools could use to parse out the fields, making it
> extensible.
>
> Not sure it's worth it though.
> And it should be in addition to this series in my
> opinion.

Boy howdy, I was hoping you were gonna do it. :-)

I think we need the 's' flag.
it displays properly as "$src:$line"

I agree that shuffling the "$src:$line" part before the "$mod:$func"
part would be ideal
(reluctantly) its a separate patch

Acked-by: Jim Cromie <jim.cromie@xxxxxxxxx>

(resisting the urge to hijack this thread for "designing")

>
> Thomas
>
> > Thanks,
> >
> > -Jason
> >
> > On 1/29/23 9:01 PM, Thomas Weißschuh wrote:
> >> Printing the line number without the file is of limited usefulness.
> >> Knowing the filename also makes it also easier to relate the logged
> >> information to the controlfile.
> >> Example:
> >>      # modprobe test_dynamic_debug
> >>      # echo 'file test_dynamic_debug.c =pfsl' > /proc/dynamic_debug/control
> >>      # echo 1 > /sys/module/test_dynamic_debug/parameters/do_prints
> >>      # dmesg | tail -2
> >>      [   71.802212] do_cats:lib/test_dynamic_debug.c:103: test_dd: doing categories
> >>      [   71.802227] do_levels:lib/test_dynamic_debug.c:123: test_dd: doing levels
> >> Signed-off-by: Thomas Weißschuh <linux@xxxxxxxxxxxxxx>
> >> ---
> >>   Documentation/admin-guide/dynamic-debug-howto.rst | 5 +++--
> >>   include/linux/dynamic_debug.h                     | 4 +++-
> >>   lib/dynamic_debug.c                               | 4 ++++
> >>   3 files changed, 10 insertions(+), 3 deletions(-)
> >> diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst
> >> index faa22f77847a..f9fa8163fba6 100644
> >> --- a/Documentation/admin-guide/dynamic-debug-howto.rst
> >> +++ b/Documentation/admin-guide/dynamic-debug-howto.rst
> >> @@ -216,13 +216,14 @@ The flags are::
> >>     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
> >>     For ``print_hex_dump_debug()`` and ``print_hex_dump_bytes()``, only
> >>   the ``p`` flag has meaning, other flags are ignored.
> >>   -Note the regexp ``^[-+=][flmpt_]+$`` matches a flags specification.
> >> -To clear all flags at once, use ``=_`` or ``-flmpt``.
> >> +Note the regexp ``^[-+=][fslmpt_]+$`` matches a flags specification.
> >> +To clear all flags at once, use ``=_`` or ``-fslmpt``.
> >>       Debug messages during Boot Process
> >> diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
> >> index 41682278d2e8..0c77105d583c 100644
> >> --- a/include/linux/dynamic_debug.h
> >> +++ b/include/linux/dynamic_debug.h
> >> @@ -37,10 +37,12 @@ struct _ddebug {
> >>   #define _DPRINTK_FLAGS_INCL_FUNCNAME  (1<<2)
> >>   #define _DPRINTK_FLAGS_INCL_LINENO    (1<<3)
> >>   #define _DPRINTK_FLAGS_INCL_TID       (1<<4)
> >> +#define _DPRINTK_FLAGS_INCL_SOURCENAME (1<<5)
> >>     #define _DPRINTK_FLAGS_INCL_ANY     \
> >>     (_DPRINTK_FLAGS_INCL_MODNAME | _DPRINTK_FLAGS_INCL_FUNCNAME |\
> >> -    _DPRINTK_FLAGS_INCL_LINENO  | _DPRINTK_FLAGS_INCL_TID)
> >> +    _DPRINTK_FLAGS_INCL_LINENO  | _DPRINTK_FLAGS_INCL_TID |\
> >> +    _DPRINTK_FLAGS_INCL_SOURCENAME)
> >>     #if defined DEBUG
> >>   #define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINT
> >> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> >> index e96ea427d8af..fa7418e35197 100644
> >> --- a/lib/dynamic_debug.c
> >> +++ b/lib/dynamic_debug.c
> >> @@ -92,6 +92,7 @@ static const struct { unsigned flag:8; char opt_char; } opt_array[] = {
> >>     { _DPRINTK_FLAGS_PRINT, 'p' },
> >>     { _DPRINTK_FLAGS_INCL_MODNAME, 'm' },
> >>     { _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' },
> >> +   { _DPRINTK_FLAGS_INCL_SOURCENAME, 's' },
> >>     { _DPRINTK_FLAGS_INCL_LINENO, 'l' },
> >>     { _DPRINTK_FLAGS_INCL_TID, 't' },
> >>     { _DPRINTK_FLAGS_NONE, '_' },
> >> @@ -836,6 +837,9 @@ static char *__dynamic_emit_prefix(const struct _ddebug *desc, char *buf)
> >>     if (desc->flags & _DPRINTK_FLAGS_INCL_FUNCNAME)
> >>         pos += snprintf(buf + pos, remaining(pos), "%s:",
> >>                 desc->function);
> >> +   if (desc->flags & _DPRINTK_FLAGS_INCL_SOURCENAME)
> >> +       pos += snprintf(buf + pos, remaining(pos), "%s:",
> >> +               trim_prefix(desc->filename));
> >>     if (desc->flags & _DPRINTK_FLAGS_INCL_LINENO)
> >>         pos += snprintf(buf + pos, remaining(pos), "%d:",
> >>                 desc->lineno);
> >>
>