Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) client-ip=23.128.96.18;
Date:   Mon, 8 Jun 2020 12:21:50 +0100
From:   Daniel Thompson <daniel.thompson@linaro.org>
To:     Jim Cromie <jim.cromie@gmail.com>
Cc:     jbaron@akamai.com, linux-kernel@vger.kernel.org,
        akpm@linuxfoundation.org, gregkh@linuxfoundation.org,
        linux@rasmusvillemoes.dk
Subject: Re: [PATCH 03/16] dyndbg: refine debug verbosity; 1 is basic, 2 more
 chatty
Message-ID: <20200608112150.7ohrax6pzpi7ss2l@holly.lan>
References: <20200605162645.289174-1-jim.cromie@gmail.com>
 <20200605162645.289174-4-jim.cromie@gmail.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <20200605162645.289174-4-jim.cromie@gmail.com>
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

On Fri, Jun 05, 2020 at 10:26:32AM -0600, Jim Cromie wrote:
> The verbose/debug logging done for `cat $MNT/dynamic_debug/control` is
> voluminous (2 per control file entry + 2 per PAGE).  Moreover, it just
> prints pointer and sequence, which is not useful to a dyndbg user.
> So just drop them.

I'd assumed these messages where to help the dyndbg implementer rather
than the dyndbg user. If the verbose messages really are useful to help
users who (mis)configure .../control then should the enable/disable
control be shadowed in debugfs to make it easy to find?


Daniel.

> 
> Also require verbose>=2 for several other debug printks that are a bit
> too chatty for typical needs;
> 
> ddebug_change() prints changes, once per modified callsite.  Since
> queries like "+p" will enable ~2300 callsites in a typical laptop, a
> user probably doesnt need to see them often.  ddebug_exec_queries()
> still summarizes with verbose=1.
> 
> ddebug_(add|remove)_module() also print 1 line per action on a module,
> not needed by typical modprobe user.
> 
> This leaves verbose=1 better focussed on the >control parsing process.
> 
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> ---
>  lib/dynamic_debug.c | 21 ++++++++-------------
>  1 file changed, 8 insertions(+), 13 deletions(-)
> 
> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> index b877774dba96..5900c043e979 100644
> --- a/lib/dynamic_debug.c
> +++ b/lib/dynamic_debug.c
> @@ -105,12 +105,15 @@ static char *ddebug_describe_flags(struct _ddebug *dp, char *buf,
>  	return buf;
>  }
>  
> -#define vpr_info(fmt, ...)					\
> +#define vnpr_info(lvl, fmt, ...)				\
>  do {								\
> -	if (verbose)						\
> +	if (verbose >= lvl)					\
>  		pr_info(fmt, ##__VA_ARGS__);			\
>  } while (0)
>  
> +#define vpr_info(fmt, ...)	vnpr_info(1, fmt, ##__VA_ARGS__)
> +#define v2pr_info(fmt, ...)	vnpr_info(2, fmt, ##__VA_ARGS__)
> +
>  static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
>  {
>  	/* trim any trailing newlines */
> @@ -198,7 +201,7 @@ static int ddebug_change(const struct ddebug_query *query,
>  				static_branch_enable(&dp->key.dd_key_true);
>  #endif
>  			dp->flags = newflags;
> -			vpr_info("changed %s:%d [%s]%s =%s\n",
> +			v2pr_info("changed %s:%d [%s]%s =%s\n",
>  				 trim_prefix(dp->filename), dp->lineno,
>  				 dt->mod_name, dp->function,
>  				 ddebug_describe_flags(dp, flagbuf,
> @@ -771,8 +774,6 @@ static void *ddebug_proc_start(struct seq_file *m, loff_t *pos)
>  	struct _ddebug *dp;
>  	int n = *pos;
>  
> -	vpr_info("called m=%p *pos=%lld\n", m, (unsigned long long)*pos);
> -
>  	mutex_lock(&ddebug_lock);
>  
>  	if (!n)
> @@ -795,9 +796,6 @@ static void *ddebug_proc_next(struct seq_file *m, void *p, loff_t *pos)
>  	struct ddebug_iter *iter = m->private;
>  	struct _ddebug *dp;
>  
> -	vpr_info("called m=%p p=%p *pos=%lld\n",
> -		 m, p, (unsigned long long)*pos);
> -
>  	if (p == SEQ_START_TOKEN)
>  		dp = ddebug_iter_first(iter);
>  	else
> @@ -818,8 +816,6 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
>  	struct _ddebug *dp = p;
>  	char flagsbuf[10];
>  
> -	vpr_info("called m=%p p=%p\n", m, p);
> -
>  	if (p == SEQ_START_TOKEN) {
>  		seq_puts(m,
>  			 "# filename:lineno [module]function flags format\n");
> @@ -842,7 +838,6 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
>   */
>  static void ddebug_proc_stop(struct seq_file *m, void *p)
>  {
> -	vpr_info("called m=%p p=%p\n", m, p);
>  	mutex_unlock(&ddebug_lock);
>  }
>  
> @@ -905,7 +900,7 @@ int ddebug_add_module(struct _ddebug *tab, unsigned int n,
>  	list_add_tail(&dt->link, &ddebug_tables);
>  	mutex_unlock(&ddebug_lock);
>  
> -	vpr_info("%u debug prints in module %s\n", n, dt->mod_name);
> +	v2pr_info("%u debug prints in module %s\n", n, dt->mod_name);
>  	return 0;
>  }
>  
> @@ -964,7 +959,7 @@ int ddebug_remove_module(const char *mod_name)
>  	struct ddebug_table *dt, *nextdt;
>  	int ret = -ENOENT;
>  
> -	vpr_info("removing module \"%s\"\n", mod_name);
> +	v2pr_info("removing module \"%s\"\n", mod_name);
>  
>  	mutex_lock(&ddebug_lock);
>  	list_for_each_entry_safe(dt, nextdt, &ddebug_tables, link) {
> -- 
> 2.26.2
>