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

[Jason Baron]

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@xxxxxxxxx>
>>> ---
>>>  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?

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