Re: [PATCH 2/2] x86/e820: Use pr_debug to avoid spamming dmesg log with debug messages

[Heiner Kallweit <hkallweit1@gmail.com>]

On 11.05.2021 05:21, Jason Baron wrote:
> 
> 
> On 5/5/21 2:40 PM, Heiner Kallweit wrote:
>> On 05.05.2021 18:58, Jason Baron wrote:
>>>
>>>
>>> On 5/3/21 3:40 PM, Heiner Kallweit wrote:
>>>> e820 emits quite some debug messages to the dmesg log. Let's restrict
>>>> this to cases where the debug output is actually requested. Switch to
>>>> pr_debug() for this purpose and make sure by checking the return code
>>>> that pr_cont() is only called if applicable.
>>>>
>>>> Signed-off-by: Heiner Kallweit <hkallweit1@gmail.com>
>>>> ---
>>>>  arch/x86/kernel/e820.c | 27 ++++++++++++++++-----------
>>>>  1 file changed, 16 insertions(+), 11 deletions(-)
>>>>
>>>> diff --git a/arch/x86/kernel/e820.c b/arch/x86/kernel/e820.c
>>>> index bc0657f0d..67ad4d8f0 100644
>>>> --- a/arch/x86/kernel/e820.c
>>>> +++ b/arch/x86/kernel/e820.c
>>>> @@ -465,6 +465,7 @@ __e820__range_update(struct e820_table *table, u64 start, u64 size, enum e820_ty
>>>>  	u64 end;
>>>>  	unsigned int i;
>>>>  	u64 real_updated_size = 0;
>>>> +	int printed;
>>>>  
>>>>  	BUG_ON(old_type == new_type);
>>>>  
>>>> @@ -472,11 +473,13 @@ __e820__range_update(struct e820_table *table, u64 start, u64 size, enum e820_ty
>>>>  		size = ULLONG_MAX - start;
>>>>  
>>>>  	end = start + size;
>>>> -	printk(KERN_DEBUG "e820: update [mem %#010Lx-%#010Lx] ", start, end - 1);
>>>> -	e820_print_type(old_type);
>>>> -	pr_cont(" ==> ");
>>>> -	e820_print_type(new_type);
>>>> -	pr_cont("\n");
>>>> +	printed = pr_debug("e820: update [mem %#010Lx-%#010Lx] ", start, end - 1);
>>>> +	if (printed > 0) {
>>>> +		e820_print_type(old_type);
>>>> +		pr_cont(" ==> ");
>>>> +		e820_print_type(new_type);
>>>> +		pr_cont("\n");
>>>> +	}
>>>
>>>
>>> Hi Heiner,
>>>
>>> We've been doing these like:
>>>
>>> DEFINE_DYNAMIC_DEBUG_METADATA(e820_dbg, "e820 verbose mode");
>>>
>>> .
>>> .
>>> .
>>>
>>> if (DYNAMIC_DEBUG_BRANCH(e820_debg)) {
>>>     printk(KERN_DEBUG "e820: update [mem %#010Lx-%#010Lx] ", start, end - 1);
>>>     e820_print_type(old_type);
>>>     pr_cont(" ==> ");
>>>     e820_print_type(new_type);
>>>     pr_cont("\n");
>>> }
>>>
>>>
>>> You could then have one DEFINE_DYNAMIC_DEBUG_METADATA statement - such that it enables
>>> it all in one go, or do separate ones that enable it how you see fit.
>>>
>>> Would that work here?
>>>
>>
>> How would we handle the case that CONFIG_DYNAMIC_DEBUG_CORE isn't defined?
>> Then also DEFINE_DYNAMIC_DEBUG_METADATA isn't defined and we'd need to
>> duplicate the logic used here:
>>
>> #if defined(CONFIG_DYNAMIC_DEBUG) || \
>> 	(defined(CONFIG_DYNAMIC_DEBUG_CORE) && defined(DYNAMIC_DEBUG_MODULE))
>> #include <linux/dynamic_debug.h>
>> #define pr_debug(fmt, ...)			\
>> 	dynamic_pr_debug(fmt, ##__VA_ARGS__)
>> #elif defined(DEBUG)
>> #define pr_debug(fmt, ...) \
>> 	printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
>> #else
>> #define pr_debug(fmt, ...) \
>> 	no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
>> #endif
>>
> 
> I'm not sure we need to duplicate all that I think we just need something
> like the following for the !CONFIG_DYNAMIC_DEBUG_CORE case. Would this
> help?
> 
> diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
> index a57ee75..91ede70 100644
> --- a/include/linux/dynamic_debug.h
> +++ b/include/linux/dynamic_debug.h
> @@ -182,6 +182,15 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
>  #include <linux/errno.h>
>  #include <linux/printk.h>
> 
> +#ifdef DEBUG
> +#define DYNAMIC_DEBUG_BRANCH(descriptor) true
> +#else
> +#define DYNAMIC_DEBUG_BRANCH(descriptor) false
> +#if
> +
> +#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt)
> +
> +
>  static inline int ddebug_add_module(struct _ddebug *tab, unsigned int n,
>                                     const char *modname)
>  {
> 
> 
> 
>> IMO it's better to have the complexity of using DEFINE_DYNAMIC_DEBUG_METADATA
>> only once in the implementation of dynamic_pr_debug(), and not in every
>> code that wants to use pr_debug() in combination with pr_cont().
> 
> I think for your use-case it would just require one DEFINE_DYNAMIC_DEBUG_METADATA()
> statement?
> 
The point is that e820 isn't interested in using dynamic debugging. It just
would need to be able to deal with it because pr_debug() uses it. The actual
issue is independent of e820. It boils down to pr_cont() having no way to find
out whether it should print something or not if it follows a pr_debug() and
dynamic debugging is enabled.

>>
>> Also I think that to a certain extent pr_debug() is broken currently in case
>> of dynamic debugging because it has no return value, one drawback of
>> using not type-safe macros. This doesn't hurt so far because no caller seems to
>> check the return value or very few people have dynamic debugging enabled.
> 
> The model of:
> 
> DEFINE_DYNAMIC_DEBUG_METADATA(foo, "enble_foo");
> 
> .
> .
> .
> 
> if (DYNAMIC_DEBUG_BRANCH(foo) {
> 	do debugging stuff;
> }
> 
> Seems more general since the 'do debugging stuff' doesn't have to be limited
> to printk, it can be anything. So if we add another different model for this
> use-case, it seems like it might be less general.
> 
> Thanks,
> 
> -Jason
> 
Heiner