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

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

[Heiner Kallweit]

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. This would currently fail
if dynamic debugging is enabled because dynamic_pr_debug() has no
return value. So let's change this first.

Heiner Kallweit (2):
  dyndbg: add pr_debug return value if dynamic debugging is enabled
  x86/e820: Use pr_debug to avoid spamming dmesg log with debug messages

 arch/x86/kernel/e820.c        | 27 ++++++++++++++++-----------
 include/linux/dynamic_debug.h | 14 +++++++++++---
 lib/dynamic_debug.c           |  7 +++++--
 3 files changed, 32 insertions(+), 16 deletions(-)

-- 
2.31.1

[PATCH 1/2] dyndbg: add pr_debug return value if dynamic debugging is enabled

[Heiner Kallweit]

If a pr_cont() follows a pr_debug() then it must not print something if
the the pr_debug() output is suppressed. We can use the pr_debug() return
value as criteria, however this fails in case dynamic debugging is enabled
because dynamic_pr_debug() has no return value. So let's add this missing
feature.

Signed-off-by: Heiner Kallweit <hkallweit1@gmail.com>
---
 include/linux/dynamic_debug.h | 14 +++++++++++---
 lib/dynamic_debug.c           |  7 +++++--
 2 files changed, 16 insertions(+), 5 deletions(-)

diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index a57ee7534..1de271d1a 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -57,7 +57,7 @@ int ddebug_add_module(struct _ddebug *tab, unsigned int n,
 				const char *modname);
 extern int ddebug_remove_module(const char *mod_name);
 extern __printf(2, 3)
-void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...);
+int __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...);
 
 extern int ddebug_dyndbg_module_param_cb(char *param, char *val,
 					const char *modname);
@@ -123,6 +123,14 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
 
 #endif /* CONFIG_JUMP_LABEL */
 
+#define __dynamic_func_call_pr_debug(id, fmt, ...) ({		\
+	DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt);			\
+	int ret = 0;						\
+	if (DYNAMIC_DEBUG_BRANCH(id))				\
+		ret = __dynamic_pr_debug(&id, __VA_ARGS__);	\
+	ret;							\
+})
+
 #define __dynamic_func_call(id, fmt, func, ...) do {	\
 	DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt);		\
 	if (DYNAMIC_DEBUG_BRANCH(id))			\
@@ -154,8 +162,8 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
 	__dynamic_func_call_no_desc(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__)
 
 #define dynamic_pr_debug(fmt, ...)				\
-	_dynamic_func_call(fmt,	__dynamic_pr_debug,		\
-			   pr_fmt(fmt), ##__VA_ARGS__)
+	__dynamic_func_call_pr_debug(__UNIQUE_ID(ddebug), fmt,	\
+				     pr_fmt(fmt), ##__VA_ARGS__)
 
 #define dynamic_dev_dbg(dev, fmt, ...)				\
 	_dynamic_func_call(fmt,__dynamic_dev_dbg, 		\
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index c70d6347a..f7a771c06 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -618,11 +618,12 @@ static char *dynamic_emit_prefix(const struct _ddebug *desc, char *buf)
 	return buf;
 }
 
-void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
+int __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
 {
 	va_list args;
 	struct va_format vaf;
 	char buf[PREFIX_SIZE];
+	int ret;
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);
@@ -632,9 +633,11 @@ void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
 	vaf.fmt = fmt;
 	vaf.va = &args;
 
-	printk(KERN_DEBUG "%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf);
+	ret = printk(KERN_DEBUG "%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf);
 
 	va_end(args);
+
+	return ret;
 }
 EXPORT_SYMBOL(__dynamic_pr_debug);
 
-- 
2.31.1

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

[Heiner Kallweit]

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");
+	}
 
 	for (i = 0; i < table->nr_entries; i++) {
 		struct e820_entry *entry = &table->entries[i];
@@ -540,7 +543,7 @@ static u64 __init e820__range_update_kexec(u64 start, u64 size, enum e820_type o
 /* Remove a range of memory from the E820 table: */
 u64 __init e820__range_remove(u64 start, u64 size, enum e820_type old_type, bool check_type)
 {
-	int i;
+	int printed, i;
 	u64 end;
 	u64 real_removed_size = 0;
 
@@ -548,10 +551,12 @@ u64 __init e820__range_remove(u64 start, u64 size, enum e820_type old_type, bool
 		size = ULLONG_MAX - start;
 
 	end = start + size;
-	printk(KERN_DEBUG "e820: remove [mem %#010Lx-%#010Lx] ", start, end - 1);
-	if (check_type)
-		e820_print_type(old_type);
-	pr_cont("\n");
+	printed = pr_debug("e820: remove [mem %#010Lx-%#010Lx] ", start, end - 1);
+	if (printed > 0) {
+		if (check_type)
+			e820_print_type(old_type);
+		pr_cont("\n");
+	}
 
 	for (i = 0; i < e820_table->nr_entries; i++) {
 		struct e820_entry *entry = &e820_table->entries[i];
@@ -1230,7 +1235,7 @@ void __init e820__reserve_resources_late(void)
 		if (start >= end)
 			continue;
 
-		printk(KERN_DEBUG "e820: reserve RAM buffer [mem %#010llx-%#010llx]\n", start, end);
+		pr_debug("e820: reserve RAM buffer [mem %#010llx-%#010llx]\n", start, end);
 		reserve_region_with_split(&iomem_resource, start, end, "RAM buffer");
 	}
 }
-- 
2.31.1

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

[Jason Baron]

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?

Thanks,

-Jason

>  
>  	for (i = 0; i < table->nr_entries; i++) {
>  		struct e820_entry *entry = &table->entries[i];
> @@ -540,7 +543,7 @@ static u64 __init e820__range_update_kexec(u64 start, u64 size, enum e820_type o
>  /* Remove a range of memory from the E820 table: */
>  u64 __init e820__range_remove(u64 start, u64 size, enum e820_type old_type, bool check_type)
>  {
> -	int i;
> +	int printed, i;
>  	u64 end;
>  	u64 real_removed_size = 0;
>  
> @@ -548,10 +551,12 @@ u64 __init e820__range_remove(u64 start, u64 size, enum e820_type old_type, bool
>  		size = ULLONG_MAX - start;
>  
>  	end = start + size;
> -	printk(KERN_DEBUG "e820: remove [mem %#010Lx-%#010Lx] ", start, end - 1);
> -	if (check_type)
> -		e820_print_type(old_type);
> -	pr_cont("\n");
> +	printed = pr_debug("e820: remove [mem %#010Lx-%#010Lx] ", start, end - 1);
> +	if (printed > 0) {
> +		if (check_type)
> +			e820_print_type(old_type);
> +		pr_cont("\n");
> +	}
>  
>  	for (i = 0; i < e820_table->nr_entries; i++) {
>  		struct e820_entry *entry = &e820_table->entries[i];
> @@ -1230,7 +1235,7 @@ void __init e820__reserve_resources_late(void)
>  		if (start >= end)
>  			continue;
>  
> -		printk(KERN_DEBUG "e820: reserve RAM buffer [mem %#010llx-%#010llx]\n", start, end);
> +		pr_debug("e820: reserve RAM buffer [mem %#010llx-%#010llx]\n", start, end);
>  		reserve_region_with_split(&iomem_resource, start, end, "RAM buffer");
>  	}
>  }
> 

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

[Heiner Kallweit]

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

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

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.

> Thanks,
> 
> -Jason
> 

Heiner

>>  
>>  	for (i = 0; i < table->nr_entries; i++) {
>>  		struct e820_entry *entry = &table->entries[i];
>> @@ -540,7 +543,7 @@ static u64 __init e820__range_update_kexec(u64 start, u64 size, enum e820_type o
>>  /* Remove a range of memory from the E820 table: */
>>  u64 __init e820__range_remove(u64 start, u64 size, enum e820_type old_type, bool check_type)
>>  {
>> -	int i;
>> +	int printed, i;
>>  	u64 end;
>>  	u64 real_removed_size = 0;
>>  
>> @@ -548,10 +551,12 @@ u64 __init e820__range_remove(u64 start, u64 size, enum e820_type old_type, bool
>>  		size = ULLONG_MAX - start;
>>  
>>  	end = start + size;
>> -	printk(KERN_DEBUG "e820: remove [mem %#010Lx-%#010Lx] ", start, end - 1);
>> -	if (check_type)
>> -		e820_print_type(old_type);
>> -	pr_cont("\n");
>> +	printed = pr_debug("e820: remove [mem %#010Lx-%#010Lx] ", start, end - 1);
>> +	if (printed > 0) {
>> +		if (check_type)
>> +			e820_print_type(old_type);
>> +		pr_cont("\n");
>> +	}
>>  
>>  	for (i = 0; i < e820_table->nr_entries; i++) {
>>  		struct e820_entry *entry = &e820_table->entries[i];
>> @@ -1230,7 +1235,7 @@ void __init e820__reserve_resources_late(void)
>>  		if (start >= end)
>>  			continue;
>>  
>> -		printk(KERN_DEBUG "e820: reserve RAM buffer [mem %#010llx-%#010llx]\n", start, end);
>> +		pr_debug("e820: reserve RAM buffer [mem %#010llx-%#010llx]\n", start, end);
>>  		reserve_region_with_split(&iomem_resource, start, end, "RAM buffer");
>>  	}
>>  }
>>

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

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

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

[Heiner Kallweit]

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

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

[Jason Baron]

On 5/11/21 4:36 PM, Heiner Kallweit wrote:
> 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

I'm a little confused by this statement because in your changelog you say:

"
e820 emits quite some debug messages to the dmesg log. Let's restrict
this to cases where the debug output is actually requested.
"

So doesn't this mean you are intending to use dynamic debug to allow the user
to increase the verbosity if they want?

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

Ok, well the using the DYNAMIC_DEBUG_BRANCH() will address this b/c the branch
is controlled by dynamic debug.

That said, I do see the value in not having to open code the branch stuff, and
making pr_debug() consistent with printk which does return a value. So that
makes sense to me.

Thanks,

-Jason

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

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

[Joe Perches]

On Tue, 2021-05-11 at 17:31 -0400, Jason Baron wrote:

> That said, I do see the value in not having to open code the branch stuff, and
> making pr_debug() consistent with printk which does return a value. So that
> makes sense to me.

IMO: printk should not return a value.

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

[Jason Baron]

On 5/14/21 1:38 PM, Joe Perches wrote:
> On Tue, 2021-05-11 at 17:31 -0400, Jason Baron wrote:
> 
>> That said, I do see the value in not having to open code the branch stuff, and
>> making pr_debug() consistent with printk which does return a value. So that
>> makes sense to me.
> 
> IMO: printk should not return a value.
> 

Ok, the issue we are trying to resolve is to control whether a 'pr_debug()' statement
is enabled and thus use that to control subsequent output. The proposed patch does:


+	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");
+	}

I do think pr_debug() here is different from printk() b/c it can be explicitly
toggled.

I also suggested an alternative, which is possible with the current code which
is to use DYNAMIC_DEBUG_BRANCH().

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");
}

That however does require one to do something like this first:

DEFINE_DYNAMIC_DEBUG_METADATA(e820_dbg, "e820 verbose mode");

So I don't feel too strongly either way, but maybe others do?

Thanks,

-Jason

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

[Joe Perches]

On Fri, 2021-05-14 at 15:56 -0400, Jason Baron wrote:
> 
> On 5/14/21 1:38 PM, Joe Perches wrote:
> > On Tue, 2021-05-11 at 17:31 -0400, Jason Baron wrote:
> > 
> > > That said, I do see the value in not having to open code the branch stuff, and
> > > making pr_debug() consistent with printk which does return a value. So that
> > > makes sense to me.
> > 
> > IMO: printk should not return a value.
> > 
> 
> Ok, the issue we are trying to resolve is to control whether a 'pr_debug()' statement
> is enabled and thus use that to control subsequent output. The proposed patch does:
> 
> 
> +	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");
> +	}
> 
> I do think pr_debug() here is different from printk() b/c it can be explicitly
> toggled.
> 
> I also suggested an alternative, which is possible with the current code which
> is to use DYNAMIC_DEBUG_BRANCH().
> 
> 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");
> }
> 
> That however does require one to do something like this first:
> 
> DEFINE_DYNAMIC_DEBUG_METADATA(e820_dbg, "e820 verbose mode");
> 
> So I don't feel too strongly either way, but maybe others do?

Why not avoid the problem by using temporaries on the stack
and not use pr_cont altogether?
---
 arch/x86/kernel/e820.c | 71 ++++++++++++++++++++++++++++++++------------------
 1 file changed, 46 insertions(+), 25 deletions(-)

diff --git a/arch/x86/kernel/e820.c b/arch/x86/kernel/e820.c
index bc0657f0deed..a6e7ab4b522b 100644
--- a/arch/x86/kernel/e820.c
+++ b/arch/x86/kernel/e820.c
@@ -184,20 +184,38 @@ void __init e820__range_add(u64 start, u64 size, enum e820_type type)
 	__e820__range_add(e820_table, start, size, type);
 }
 
-static void __init e820_print_type(enum e820_type type)
+static char * __init e820_fmt_type(enum e820_type type, char *buf, size_t size)
 {
 	switch (type) {
-	case E820_TYPE_RAM:		/* Fall through: */
-	case E820_TYPE_RESERVED_KERN:	pr_cont("usable");			break;
-	case E820_TYPE_RESERVED:	pr_cont("reserved");			break;
-	case E820_TYPE_SOFT_RESERVED:	pr_cont("soft reserved");		break;
-	case E820_TYPE_ACPI:		pr_cont("ACPI data");			break;
-	case E820_TYPE_NVS:		pr_cont("ACPI NVS");			break;
-	case E820_TYPE_UNUSABLE:	pr_cont("unusable");			break;
-	case E820_TYPE_PMEM:		/* Fall through: */
-	case E820_TYPE_PRAM:		pr_cont("persistent (type %u)", type);	break;
-	default:			pr_cont("type %u", type);		break;
+	case E820_TYPE_RAM:
+	case E820_TYPE_RESERVED_KERN:
+		strscpy(buf, "usable", size);
+		break;
+	case E820_TYPE_RESERVED:
+		strscpy(buf, "reserved", size);
+		break;
+	case E820_TYPE_SOFT_RESERVED:
+		strscpy(buf, "soft reserved", size);
+		break;
+	case E820_TYPE_ACPI:
+		strscpy(buf, "ACPI data", size);
+		break;
+	case E820_TYPE_NVS:
+		strscpy(buf, "ACPI NVS", size);
+		break;
+	case E820_TYPE_UNUSABLE:
+		strscpy(buf, "unusable", size);
+		break;
+	case E820_TYPE_PMEM:
+	case E820_TYPE_PRAM:
+		scnprintf(buf, size, "persistent (type %u)", type);
+		break;
+	default:
+		scnprintf(buf, size, "type %u", type);
+		break;
 	}
+
+	return buf;
 }
 
 void __init e820__print_table(char *who)
@@ -205,13 +223,14 @@ void __init e820__print_table(char *who)
 	int i;
 
 	for (i = 0; i < e820_table->nr_entries; i++) {
-		pr_info("%s: [mem %#018Lx-%#018Lx] ",
+		char type[32];
+
+		pr_info("%s: [mem %#018Lx-%#018Lx] %s\n",
 			who,
 			e820_table->entries[i].addr,
-			e820_table->entries[i].addr + e820_table->entries[i].size - 1);
-
-		e820_print_type(e820_table->entries[i].type);
-		pr_cont("\n");
+			e820_table->entries[i].addr + e820_table->entries[i].size - 1,
+			e820_fmt_type(e820_table->entries[i].type,
+				      type, sizeof(type)));
 	}
 }
 
@@ -465,6 +484,8 @@ __e820__range_update(struct e820_table *table, u64 start, u64 size, enum e820_ty
 	u64 end;
 	unsigned int i;
 	u64 real_updated_size = 0;
+	char type1[32];
+	char type2[32];
 
 	BUG_ON(old_type == new_type);
 
@@ -472,11 +493,10 @@ __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");
+	printk(KERN_DEBUG "e820: update [mem %#010Lx-%#010Lx] %s ==> %s\n",
+	       start, end - 1,
+	       e820_fmt_type(old_type, type1, sizeof(type1)),
+	       e820_fmt_type(new_type, type2, sizeof(type2)));
 
 	for (i = 0; i < table->nr_entries; i++) {
 		struct e820_entry *entry = &table->entries[i];
@@ -543,15 +563,16 @@ u64 __init e820__range_remove(u64 start, u64 size, enum e820_type old_type, bool
 	int i;
 	u64 end;
 	u64 real_removed_size = 0;
+	char type[32];
 
 	if (size > (ULLONG_MAX - start))
 		size = ULLONG_MAX - start;
 
 	end = start + size;
-	printk(KERN_DEBUG "e820: remove [mem %#010Lx-%#010Lx] ", start, end - 1);
-	if (check_type)
-		e820_print_type(old_type);
-	pr_cont("\n");
+	printk(KERN_DEBUG "e820: remove [mem %#010Lx-%#010Lx]%s%s\n",
+	       start, end - 1,
+	       check_type ? " " : "",
+	       check_type ? e820_fmt_type(old_type, type, sizeof(type)) : "");
 
 	for (i = 0; i < e820_table->nr_entries; i++) {
 		struct e820_entry *entry = &e820_table->entries[i];

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

[Jason Baron]

On 5/14/21 4:22 PM, Joe Perches wrote:
> On Fri, 2021-05-14 at 15:56 -0400, Jason Baron wrote:
>>
>> On 5/14/21 1:38 PM, Joe Perches wrote:
>>> On Tue, 2021-05-11 at 17:31 -0400, Jason Baron wrote:
>>>
>>>> That said, I do see the value in not having to open code the branch stuff, and
>>>> making pr_debug() consistent with printk which does return a value. So that
>>>> makes sense to me.
>>>
>>> IMO: printk should not return a value.
>>>
>>
>> Ok, the issue we are trying to resolve is to control whether a 'pr_debug()' statement
>> is enabled and thus use that to control subsequent output. The proposed patch does:
>>
>>
>> +	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");
>> +	}
>>
>> I do think pr_debug() here is different from printk() b/c it can be explicitly
>> toggled.
>>
>> I also suggested an alternative, which is possible with the current code which
>> is to use DYNAMIC_DEBUG_BRANCH().
>>
>> 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");
>> }
>>
>> That however does require one to do something like this first:
>>
>> DEFINE_DYNAMIC_DEBUG_METADATA(e820_dbg, "e820 verbose mode");
>>
>> So I don't feel too strongly either way, but maybe others do?
> 
> Why not avoid the problem by using temporaries on the stack
> and not use pr_cont altogether?

Nice. That's fine with me Heiner?

I think though Heiner wants to use pr_debug() below instead of printk
with KERN_DEBUG, at least that was my understanding. But that would
be a simpple s/printk/pr_debug().

Thanks,

-Jason




> ---
>  arch/x86/kernel/e820.c | 71 ++++++++++++++++++++++++++++++++------------------
>  1 file changed, 46 insertions(+), 25 deletions(-)
> 
> diff --git a/arch/x86/kernel/e820.c b/arch/x86/kernel/e820.c
> index bc0657f0deed..a6e7ab4b522b 100644
> --- a/arch/x86/kernel/e820.c
> +++ b/arch/x86/kernel/e820.c
> @@ -184,20 +184,38 @@ void __init e820__range_add(u64 start, u64 size, enum e820_type type)
>  	__e820__range_add(e820_table, start, size, type);
>  }
>  
> -static void __init e820_print_type(enum e820_type type)
> +static char * __init e820_fmt_type(enum e820_type type, char *buf, size_t size)
>  {
>  	switch (type) {
> -	case E820_TYPE_RAM:		/* Fall through: */
> -	case E820_TYPE_RESERVED_KERN:	pr_cont("usable");			break;
> -	case E820_TYPE_RESERVED:	pr_cont("reserved");			break;
> -	case E820_TYPE_SOFT_RESERVED:	pr_cont("soft reserved");		break;
> -	case E820_TYPE_ACPI:		pr_cont("ACPI data");			break;
> -	case E820_TYPE_NVS:		pr_cont("ACPI NVS");			break;
> -	case E820_TYPE_UNUSABLE:	pr_cont("unusable");			break;
> -	case E820_TYPE_PMEM:		/* Fall through: */
> -	case E820_TYPE_PRAM:		pr_cont("persistent (type %u)", type);	break;
> -	default:			pr_cont("type %u", type);		break;
> +	case E820_TYPE_RAM:
> +	case E820_TYPE_RESERVED_KERN:
> +		strscpy(buf, "usable", size);
> +		break;
> +	case E820_TYPE_RESERVED:
> +		strscpy(buf, "reserved", size);
> +		break;
> +	case E820_TYPE_SOFT_RESERVED:
> +		strscpy(buf, "soft reserved", size);
> +		break;
> +	case E820_TYPE_ACPI:
> +		strscpy(buf, "ACPI data", size);
> +		break;
> +	case E820_TYPE_NVS:
> +		strscpy(buf, "ACPI NVS", size);
> +		break;
> +	case E820_TYPE_UNUSABLE:
> +		strscpy(buf, "unusable", size);
> +		break;
> +	case E820_TYPE_PMEM:
> +	case E820_TYPE_PRAM:
> +		scnprintf(buf, size, "persistent (type %u)", type);
> +		break;
> +	default:
> +		scnprintf(buf, size, "type %u", type);
> +		break;
>  	}
> +
> +	return buf;
>  }
>  
>  void __init e820__print_table(char *who)
> @@ -205,13 +223,14 @@ void __init e820__print_table(char *who)
>  	int i;
>  
>  	for (i = 0; i < e820_table->nr_entries; i++) {
> -		pr_info("%s: [mem %#018Lx-%#018Lx] ",
> +		char type[32];
> +
> +		pr_info("%s: [mem %#018Lx-%#018Lx] %s\n",
>  			who,
>  			e820_table->entries[i].addr,
> -			e820_table->entries[i].addr + e820_table->entries[i].size - 1);
> -
> -		e820_print_type(e820_table->entries[i].type);
> -		pr_cont("\n");
> +			e820_table->entries[i].addr + e820_table->entries[i].size - 1,
> +			e820_fmt_type(e820_table->entries[i].type,
> +				      type, sizeof(type)));
>  	}
>  }
>  
> @@ -465,6 +484,8 @@ __e820__range_update(struct e820_table *table, u64 start, u64 size, enum e820_ty
>  	u64 end;
>  	unsigned int i;
>  	u64 real_updated_size = 0;
> +	char type1[32];
> +	char type2[32];
>  
>  	BUG_ON(old_type == new_type);
>  
> @@ -472,11 +493,10 @@ __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");
> +	printk(KERN_DEBUG "e820: update [mem %#010Lx-%#010Lx] %s ==> %s\n",
> +	       start, end - 1,
> +	       e820_fmt_type(old_type, type1, sizeof(type1)),
> +	       e820_fmt_type(new_type, type2, sizeof(type2)));
>  
>  	for (i = 0; i < table->nr_entries; i++) {
>  		struct e820_entry *entry = &table->entries[i];
> @@ -543,15 +563,16 @@ u64 __init e820__range_remove(u64 start, u64 size, enum e820_type old_type, bool
>  	int i;
>  	u64 end;
>  	u64 real_removed_size = 0;
> +	char type[32];
>  
>  	if (size > (ULLONG_MAX - start))
>  		size = ULLONG_MAX - start;
>  
>  	end = start + size;
> -	printk(KERN_DEBUG "e820: remove [mem %#010Lx-%#010Lx] ", start, end - 1);
> -	if (check_type)
> -		e820_print_type(old_type);
> -	pr_cont("\n");
> +	printk(KERN_DEBUG "e820: remove [mem %#010Lx-%#010Lx]%s%s\n",
> +	       start, end - 1,
> +	       check_type ? " " : "",
> +	       check_type ? e820_fmt_type(old_type, type, sizeof(type)) : "");
>  
>  	for (i = 0; i < e820_table->nr_entries; i++) {
>  		struct e820_entry *entry = &e820_table->entries[i];
> 
> 

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

[Heiner Kallweit]

On 14.05.2021 22:32, Jason Baron wrote:
> 
> 
> On 5/14/21 4:22 PM, Joe Perches wrote:
>> On Fri, 2021-05-14 at 15:56 -0400, Jason Baron wrote:
>>>
>>> On 5/14/21 1:38 PM, Joe Perches wrote:
>>>> On Tue, 2021-05-11 at 17:31 -0400, Jason Baron wrote:
>>>>
>>>>> That said, I do see the value in not having to open code the branch stuff, and
>>>>> making pr_debug() consistent with printk which does return a value. So that
>>>>> makes sense to me.
>>>>
>>>> IMO: printk should not return a value.
>>>>
>>>
>>> Ok, the issue we are trying to resolve is to control whether a 'pr_debug()' statement
>>> is enabled and thus use that to control subsequent output. The proposed patch does:
>>>
>>>
>>> +	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");
>>> +	}
>>>
>>> I do think pr_debug() here is different from printk() b/c it can be explicitly
>>> toggled.
>>>
>>> I also suggested an alternative, which is possible with the current code which
>>> is to use DYNAMIC_DEBUG_BRANCH().
>>>
>>> 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");
>>> }
>>>
>>> That however does require one to do something like this first:
>>>
>>> DEFINE_DYNAMIC_DEBUG_METADATA(e820_dbg, "e820 verbose mode");
>>>
>>> So I don't feel too strongly either way, but maybe others do?
>>
>> Why not avoid the problem by using temporaries on the stack
>> and not use pr_cont altogether?
> 
> Nice. That's fine with me Heiner?
> 
I once tested a similar approach, just using kasprintf() to dynamically
allocate the substrings. Still using pr_cont() looks a little bit
more elegant to me, but it has its drawbacks. Having said that:
Yes, fine with me (with pr_debug).

> I think though Heiner wants to use pr_debug() below instead of printk
> with KERN_DEBUG, at least that was my understanding. But that would
> be a simpple s/printk/pr_debug().
> 
> Thanks,
> 
> -Jason
> 

Heiner

> 
> 
> 
>> ---
>>  arch/x86/kernel/e820.c | 71 ++++++++++++++++++++++++++++++++------------------
>>  1 file changed, 46 insertions(+), 25 deletions(-)
>>
>> diff --git a/arch/x86/kernel/e820.c b/arch/x86/kernel/e820.c
>> index bc0657f0deed..a6e7ab4b522b 100644
>> --- a/arch/x86/kernel/e820.c
>> +++ b/arch/x86/kernel/e820.c
>> @@ -184,20 +184,38 @@ void __init e820__range_add(u64 start, u64 size, enum e820_type type)
>>  	__e820__range_add(e820_table, start, size, type);
>>  }
>>  
>> -static void __init e820_print_type(enum e820_type type)
>> +static char * __init e820_fmt_type(enum e820_type type, char *buf, size_t size)
>>  {
>>  	switch (type) {
>> -	case E820_TYPE_RAM:		/* Fall through: */
>> -	case E820_TYPE_RESERVED_KERN:	pr_cont("usable");			break;
>> -	case E820_TYPE_RESERVED:	pr_cont("reserved");			break;
>> -	case E820_TYPE_SOFT_RESERVED:	pr_cont("soft reserved");		break;
>> -	case E820_TYPE_ACPI:		pr_cont("ACPI data");			break;
>> -	case E820_TYPE_NVS:		pr_cont("ACPI NVS");			break;
>> -	case E820_TYPE_UNUSABLE:	pr_cont("unusable");			break;
>> -	case E820_TYPE_PMEM:		/* Fall through: */
>> -	case E820_TYPE_PRAM:		pr_cont("persistent (type %u)", type);	break;
>> -	default:			pr_cont("type %u", type);		break;
>> +	case E820_TYPE_RAM:
>> +	case E820_TYPE_RESERVED_KERN:
>> +		strscpy(buf, "usable", size);
>> +		break;
>> +	case E820_TYPE_RESERVED:
>> +		strscpy(buf, "reserved", size);
>> +		break;
>> +	case E820_TYPE_SOFT_RESERVED:
>> +		strscpy(buf, "soft reserved", size);
>> +		break;
>> +	case E820_TYPE_ACPI:
>> +		strscpy(buf, "ACPI data", size);
>> +		break;
>> +	case E820_TYPE_NVS:
>> +		strscpy(buf, "ACPI NVS", size);
>> +		break;
>> +	case E820_TYPE_UNUSABLE:
>> +		strscpy(buf, "unusable", size);
>> +		break;
>> +	case E820_TYPE_PMEM:
>> +	case E820_TYPE_PRAM:
>> +		scnprintf(buf, size, "persistent (type %u)", type);
>> +		break;
>> +	default:
>> +		scnprintf(buf, size, "type %u", type);
>> +		break;
>>  	}
>> +
>> +	return buf;
>>  }
>>  
>>  void __init e820__print_table(char *who)
>> @@ -205,13 +223,14 @@ void __init e820__print_table(char *who)
>>  	int i;
>>  
>>  	for (i = 0; i < e820_table->nr_entries; i++) {
>> -		pr_info("%s: [mem %#018Lx-%#018Lx] ",
>> +		char type[32];
>> +
>> +		pr_info("%s: [mem %#018Lx-%#018Lx] %s\n",
>>  			who,
>>  			e820_table->entries[i].addr,
>> -			e820_table->entries[i].addr + e820_table->entries[i].size - 1);
>> -
>> -		e820_print_type(e820_table->entries[i].type);
>> -		pr_cont("\n");
>> +			e820_table->entries[i].addr + e820_table->entries[i].size - 1,
>> +			e820_fmt_type(e820_table->entries[i].type,
>> +				      type, sizeof(type)));
>>  	}
>>  }
>>  
>> @@ -465,6 +484,8 @@ __e820__range_update(struct e820_table *table, u64 start, u64 size, enum e820_ty
>>  	u64 end;
>>  	unsigned int i;
>>  	u64 real_updated_size = 0;
>> +	char type1[32];
>> +	char type2[32];
>>  
>>  	BUG_ON(old_type == new_type);
>>  
>> @@ -472,11 +493,10 @@ __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");
>> +	printk(KERN_DEBUG "e820: update [mem %#010Lx-%#010Lx] %s ==> %s\n",
>> +	       start, end - 1,
>> +	       e820_fmt_type(old_type, type1, sizeof(type1)),
>> +	       e820_fmt_type(new_type, type2, sizeof(type2)));
>>  
>>  	for (i = 0; i < table->nr_entries; i++) {
>>  		struct e820_entry *entry = &table->entries[i];
>> @@ -543,15 +563,16 @@ u64 __init e820__range_remove(u64 start, u64 size, enum e820_type old_type, bool
>>  	int i;
>>  	u64 end;
>>  	u64 real_removed_size = 0;
>> +	char type[32];
>>  
>>  	if (size > (ULLONG_MAX - start))
>>  		size = ULLONG_MAX - start;
>>  
>>  	end = start + size;
>> -	printk(KERN_DEBUG "e820: remove [mem %#010Lx-%#010Lx] ", start, end - 1);
>> -	if (check_type)
>> -		e820_print_type(old_type);
>> -	pr_cont("\n");
>> +	printk(KERN_DEBUG "e820: remove [mem %#010Lx-%#010Lx]%s%s\n",
>> +	       start, end - 1,
>> +	       check_type ? " " : "",
>> +	       check_type ? e820_fmt_type(old_type, type, sizeof(type)) : "");
>>  
>>  	for (i = 0; i < e820_table->nr_entries; i++) {
>>  		struct e820_entry *entry = &e820_table->entries[i];
>>
>>