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

[linux]

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.

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