Re: [PATCH] twist: allow converting pr_devel()/pr_debug() into printk(KERN_DEBUG)

[Petr Mladek]

On Thu 2020-05-28 08:33:37, Tetsuo Handa wrote:
> On 2020/05/28 0:55, Petr Mladek wrote:
> >>> Well, it would be possible to call vsprintf() with NULL buffer. It is
> >>> normally used to calculate the length of the message before it is
> >>> printed. But it also does all the accesses without printing anything.
> >>
> >> OK. I think that redirecting pr_debug() to vsnprintf(NULL, 0) will be
> >> better than modifying dynamic_debug path, for
> > 
> > It might get more complicated if you would actually want to see
> > pr_debug() messages for a selected module in the fuzzer.
> 
> I don't expect that automated testing can afford selectively enabling
> DYNAMIC_DEBUG_BRANCH(id) conditions. But we could evaluate all arguments
> by calling snprintf(NULL, 0) if the condition to call printk() is false.
> 
> > vsprintf(NULL, ) can be called for pr_debug() messages in
> > vprintk_store(). It will be again only a single place for
> > all printk() wrappers.
> 
> I couldn't catch what you mean. The problem of pr_debug() is that
> vprintk_store() might not be called because of
> 
>   #define no_printk(fmt, ...)                             \
>   ({                                                      \
>           if (0)                                          \
>                   printk(fmt, ##__VA_ARGS__);             \
>           0;                                              \
>   })
> 
>   #define pr_debug(fmt, ...) \
>           no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
> 
> or
> 
>   #define __dynamic_func_call(id, fmt, func, ...) do {    \
>           DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt);         \
>           if (DYNAMIC_DEBUG_BRANCH(id))                   \
>                   func(&id, ##__VA_ARGS__);               \
>   } while (0)
> 
>   #define _dynamic_func_call(fmt, func, ...)                              \
>           __dynamic_func_call(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__)
> 
>   #define dynamic_pr_debug(fmt, ...)                              \
>           _dynamic_func_call(fmt, __dynamic_pr_debug,             \
>                              pr_fmt(fmt), ##__VA_ARGS__)
> 
>   #define pr_debug(fmt, ...) \
>           dynamic_pr_debug(fmt, ##__VA_ARGS__)

That is exactly the problem. Your current patch [1] adds checks
for the CONFIG_TWIST into 15 different locations.

This is perfectly fine for testing in linux-next whether this twist
is worth the effort. But I do not like this as a long term solution.

If the testing shows that it was really helpful and you would want
to get this into Linus' tree. Then I would like to do the twist at different
level:

1. Add twist into ddebug_add_module() and enable all newly added
   entries by default. For example, by calling
   ddebug_exec_query("*:+p", const char *modname) or what is the syntax.

   This will cause that any pr_devel() variant will always get called.


2. Add twist into vprintk_store(). In the current, implementation
   it would do:

  #if TWIST
	return text_len;
  #endif

	return log_output(facility, level, lflags,
			  dict, dictlen, text, text_len);

   Something similar would need to be done also in printk_safe().
   Hot you could ignore this because it would be used only in
   very few scenarios.

  In the lock_less variant, we would need to format the message
  into small buffer on stack to detect the log level from the first
  few bytes.


The approach will cause that pr_devel() message will never get really
printed when this TWIST is enabled. But you mention that automatic
testing would not do so anyway.

[1] https://lore.kernel.org/r/20200528065603.3596-1-penguin-kernel@xxxxxxxxxxxxxxxxxxx

Best Regards,
Petr