Message-ID: <04311d93-7cb4-bf0b-dfa7-162a38b42583@akamai.com>
Date:   Fri, 3 Feb 2023 11:45:33 -0500
MIME-Version: 1.0
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101
 Thunderbird/102.4.2
Subject: Re: [PATCH 3/3] dyndbg: add source filename to prefix
Content-Language: en-US
To:     =?UTF-8?Q?Thomas_Wei=c3=9fschuh?= <linux@weissschuh.net>,
        Jim Cromie <jim.cromie@gmail.com>,
        Jonathan Corbet <corbet@lwn.net>
Cc:     linux-kernel@vger.kernel.org, linux-doc@vger.kernel.org
References: <20221223-dyndbg-filename-v1-0-cbf8543009a1@weissschuh.net>
 <20221223-dyndbg-filename-v1-3-cbf8543009a1@weissschuh.net>
From:   Jason Baron <jbaron@akamai.com>
In-Reply-To: <20221223-dyndbg-filename-v1-3-cbf8543009a1@weissschuh.net>
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 8bit
Precedence: bulk

Hi Thomas,

Thanks for this series, this series is fine with me:
Acked-by: Jason Baron <jbaron@akamai.com>

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

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@weissschuh.net>
> ---
>   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);
>