Constant output in syslog of EDAC message

Constant output in syslog of EDAC message

[Raymond Bennett]

Hi,

I am seeing the constant output of the following messages in syslog,
wondering what I can do to resolve this:

Oct 19 13:19:30 hostname kernel: EDAC DEBUG: ie31200_check: MC0

It outputs about once every second.

uname -a
Linux hostname 5.9.0-991.native #1 SMP Mon Oct 12 08:10:54 PDT 2020
x86_64 GNU/Linux

/proc/cpuinfo
processor : 7
vendor_id : GenuineIntel
cpu family : 6
model : 158
model name : Intel(R) Xeon(R) CPU E3-1505M v6 @ 3.00GHz
stepping : 9
microcode : 0xd6

Re: Constant output in syslog of EDAC message

[Borislav Petkov]

On Mon, Oct 19, 2020 at 01:37:16PM -0700, Raymond Bennett wrote:
> Hi,
> 
> I am seeing the constant output of the following messages in syslog,
> wondering what I can do to resolve this:
> 
> Oct 19 13:19:30 hostname kernel: EDAC DEBUG: ie31200_check: MC0

Looks like a debugging leftover. I'll remove it soon unless Jason (CCed)
screams. 

Leaving in the rest for him.
 
> It outputs about once every second.
> 
> uname -a
> Linux hostname 5.9.0-991.native #1 SMP Mon Oct 12 08:10:54 PDT 2020
> x86_64 GNU/Linux
> 
> /proc/cpuinfo
> processor : 7
> vendor_id : GenuineIntel
> cpu family : 6
> model : 158
> model name : Intel(R) Xeon(R) CPU E3-1505M v6 @ 3.00GHz
> stepping : 9
> microcode : 0xd6

-- 
Regards/Gruss,
    Boris.

https://people.kernel.org/tglx/notes-about-netiquette

Re: Constant output in syslog of EDAC message

[Jason Baron]

On 10/19/20 4:56 PM, Borislav Petkov wrote:
> On Mon, Oct 19, 2020 at 01:37:16PM -0700, Raymond Bennett wrote:
>> Hi,
>>
>> I am seeing the constant output of the following messages in syslog,
>> wondering what I can do to resolve this:
>>
>> Oct 19 13:19:30 hostname kernel: EDAC DEBUG: ie31200_check: MC0
> Looks like a debugging leftover. I'll remove it soon unless Jason (CCed)
> screams.
>
> Leaving in the rest for him.

Hi,

Yes, I likely was just following what was in other edac drivers at

the time - for example, i3200_check() has a similar debug. I guess

it could have a higher level. But if we remove this one, we may

want to audit some of the other edac drivers as well.

Thanks,

-Jason


>   
>> It outputs about once every second.
>>
>> uname -a
>> Linux hostname 5.9.0-991.native #1 SMP Mon Oct 12 08:10:54 PDT 2020
>> x86_64 GNU/Linux
>>
>> /proc/cpuinfo
>> processor : 7
>> vendor_id : GenuineIntel
>> cpu family : 6
>> model : 158
>> model name : Intel(R) Xeon(R) CPU E3-1505M v6 @ 3.00GHz
>> stepping : 9
>> microcode : 0xd6

Re: Constant output in syslog of EDAC message

[Borislav Petkov]

On Mon, Oct 19, 2020 at 05:25:43PM -0400, Jason Baron wrote:
> Yes, I likely was just following what was in other edac drivers at
> the time - for example, i3200_check() has a similar debug. I guess
> it could have a higher level. But if we remove this one, we may
> want to audit some of the other edac drivers as well.

Sounds good. So one patch removing them all would make sense. If
you feel like doing it, be my guest. Otherwise, it'll land on my
ever-growing todo. :-\

Thx.

-- 
Regards/Gruss,
    Boris.

https://people.kernel.org/tglx/notes-about-netiquette

[PATCH] EDAC: Do not issue useless debug statements in the polling routine

[Borislav Petkov]

From: Borislav Petkov <bp@suse.de>

They have been spreading around the subsystem by example so remove them
all.

Reported-by: Raymond Bennett <raymond.bennett@gmail.com>
Suggested-by: Jason Baron <jbaron@akamai.com>
Signed-off-by: Borislav Petkov <bp@suse.de>
---
 drivers/edac/amd76x_edac.c     | 1 -
 drivers/edac/e752x_edac.c      | 1 -
 drivers/edac/e7xxx_edac.c      | 1 -
 drivers/edac/i3000_edac.c      | 1 -
 drivers/edac/i3200_edac.c      | 1 -
 drivers/edac/i5000_edac.c      | 2 +-
 drivers/edac/i5400_edac.c      | 2 +-
 drivers/edac/i82443bxgx_edac.c | 1 -
 drivers/edac/i82860_edac.c     | 1 -
 drivers/edac/i82875p_edac.c    | 1 -
 drivers/edac/i82975x_edac.c    | 1 -
 drivers/edac/ie31200_edac.c    | 1 -
 drivers/edac/r82600_edac.c     | 1 -
 drivers/edac/x38_edac.c        | 1 -
 14 files changed, 2 insertions(+), 14 deletions(-)

diff --git a/drivers/edac/amd76x_edac.c b/drivers/edac/amd76x_edac.c
index 9c6e326b4c14..2a49f68a7cf9 100644
--- a/drivers/edac/amd76x_edac.c
+++ b/drivers/edac/amd76x_edac.c
@@ -179,7 +179,6 @@ static int amd76x_process_error_info(struct mem_ctl_info *mci,
 static void amd76x_check(struct mem_ctl_info *mci)
 {
 	struct amd76x_error_info info;
-	edac_dbg(3, "\n");
 	amd76x_get_error_info(mci, &info);
 	amd76x_process_error_info(mci, &info, 1);
 }
diff --git a/drivers/edac/e752x_edac.c b/drivers/edac/e752x_edac.c
index 313d08018166..ac7c9b42d4c7 100644
--- a/drivers/edac/e752x_edac.c
+++ b/drivers/edac/e752x_edac.c
@@ -980,7 +980,6 @@ static void e752x_check(struct mem_ctl_info *mci)
 {
 	struct e752x_error_info info;
 
-	edac_dbg(3, "\n");
 	e752x_get_error_info(mci, &info);
 	e752x_process_error_info(mci, &info, 1);
 }
diff --git a/drivers/edac/e7xxx_edac.c b/drivers/edac/e7xxx_edac.c
index 75d7ce62b3be..497e710fca3d 100644
--- a/drivers/edac/e7xxx_edac.c
+++ b/drivers/edac/e7xxx_edac.c
@@ -333,7 +333,6 @@ static void e7xxx_check(struct mem_ctl_info *mci)
 {
 	struct e7xxx_error_info info;
 
-	edac_dbg(3, "\n");
 	e7xxx_get_error_info(mci, &info);
 	e7xxx_process_error_info(mci, &info, 1);
 }
diff --git a/drivers/edac/i3000_edac.c b/drivers/edac/i3000_edac.c
index 5c1eea96230c..9065bc4386ff 100644
--- a/drivers/edac/i3000_edac.c
+++ b/drivers/edac/i3000_edac.c
@@ -273,7 +273,6 @@ static void i3000_check(struct mem_ctl_info *mci)
 {
 	struct i3000_error_info info;
 
-	edac_dbg(1, "MC%d\n", mci->mc_idx);
 	i3000_get_error_info(mci, &info);
 	i3000_process_error_info(mci, &info, 1);
 }
diff --git a/drivers/edac/i3200_edac.c b/drivers/edac/i3200_edac.c
index a8988db6d423..afccdebf5ac1 100644
--- a/drivers/edac/i3200_edac.c
+++ b/drivers/edac/i3200_edac.c
@@ -253,7 +253,6 @@ static void i3200_check(struct mem_ctl_info *mci)
 {
 	struct i3200_error_info info;
 
-	edac_dbg(1, "MC%d\n", mci->mc_idx);
 	i3200_get_and_clear_error_info(mci, &info);
 	i3200_process_error_info(mci, &info);
 }
diff --git a/drivers/edac/i5000_edac.c b/drivers/edac/i5000_edac.c
index 1a6f69c859ab..ba46057d4220 100644
--- a/drivers/edac/i5000_edac.c
+++ b/drivers/edac/i5000_edac.c
@@ -765,7 +765,7 @@ static void i5000_clear_error(struct mem_ctl_info *mci)
 static void i5000_check_error(struct mem_ctl_info *mci)
 {
 	struct i5000_error_info info;
-	edac_dbg(4, "MC%d\n", mci->mc_idx);
+
 	i5000_get_error_info(mci, &info);
 	i5000_process_error_info(mci, &info, 1);
 }
diff --git a/drivers/edac/i5400_edac.c b/drivers/edac/i5400_edac.c
index 92d63eb533ae..f76624ee82ef 100644
--- a/drivers/edac/i5400_edac.c
+++ b/drivers/edac/i5400_edac.c
@@ -686,7 +686,7 @@ static void i5400_clear_error(struct mem_ctl_info *mci)
 static void i5400_check_error(struct mem_ctl_info *mci)
 {
 	struct i5400_error_info info;
-	edac_dbg(4, "MC%d\n", mci->mc_idx);
+
 	i5400_get_error_info(mci, &info);
 	i5400_process_error_info(mci, &info);
 }
diff --git a/drivers/edac/i82443bxgx_edac.c b/drivers/edac/i82443bxgx_edac.c
index a2ca929e2168..933dcf3cfdff 100644
--- a/drivers/edac/i82443bxgx_edac.c
+++ b/drivers/edac/i82443bxgx_edac.c
@@ -176,7 +176,6 @@ static void i82443bxgx_edacmc_check(struct mem_ctl_info *mci)
 {
 	struct i82443bxgx_edacmc_error_info info;
 
-	edac_dbg(1, "MC%d\n", mci->mc_idx);
 	i82443bxgx_edacmc_get_error_info(mci, &info);
 	i82443bxgx_edacmc_process_error_info(mci, &info, 1);
 }
diff --git a/drivers/edac/i82860_edac.c b/drivers/edac/i82860_edac.c
index 3e3a80ffb322..fbec90d00f1e 100644
--- a/drivers/edac/i82860_edac.c
+++ b/drivers/edac/i82860_edac.c
@@ -135,7 +135,6 @@ static void i82860_check(struct mem_ctl_info *mci)
 {
 	struct i82860_error_info info;
 
-	edac_dbg(1, "MC%d\n", mci->mc_idx);
 	i82860_get_error_info(mci, &info);
 	i82860_process_error_info(mci, &info, 1);
 }
diff --git a/drivers/edac/i82875p_edac.c b/drivers/edac/i82875p_edac.c
index ceac925af38c..553880b9fc12 100644
--- a/drivers/edac/i82875p_edac.c
+++ b/drivers/edac/i82875p_edac.c
@@ -262,7 +262,6 @@ static void i82875p_check(struct mem_ctl_info *mci)
 {
 	struct i82875p_error_info info;
 
-	edac_dbg(1, "MC%d\n", mci->mc_idx);
 	i82875p_get_error_info(mci, &info);
 	i82875p_process_error_info(mci, &info, 1);
 }
diff --git a/drivers/edac/i82975x_edac.c b/drivers/edac/i82975x_edac.c
index 6be99e0d850d..d99f005832cf 100644
--- a/drivers/edac/i82975x_edac.c
+++ b/drivers/edac/i82975x_edac.c
@@ -330,7 +330,6 @@ static void i82975x_check(struct mem_ctl_info *mci)
 {
 	struct i82975x_error_info info;
 
-	edac_dbg(1, "MC%d\n", mci->mc_idx);
 	i82975x_get_error_info(mci, &info);
 	i82975x_process_error_info(mci, &info, 1);
 }
diff --git a/drivers/edac/ie31200_edac.c b/drivers/edac/ie31200_edac.c
index c47963240b65..9a9ff5ad611a 100644
--- a/drivers/edac/ie31200_edac.c
+++ b/drivers/edac/ie31200_edac.c
@@ -333,7 +333,6 @@ static void ie31200_check(struct mem_ctl_info *mci)
 {
 	struct ie31200_error_info info;
 
-	edac_dbg(1, "MC%d\n", mci->mc_idx);
 	ie31200_get_and_clear_error_info(mci, &info);
 	ie31200_process_error_info(mci, &info);
 }
diff --git a/drivers/edac/r82600_edac.c b/drivers/edac/r82600_edac.c
index 851e53e122aa..d0aef83dca2a 100644
--- a/drivers/edac/r82600_edac.c
+++ b/drivers/edac/r82600_edac.c
@@ -204,7 +204,6 @@ static void r82600_check(struct mem_ctl_info *mci)
 {
 	struct r82600_error_info info;
 
-	edac_dbg(1, "MC%d\n", mci->mc_idx);
 	r82600_get_error_info(mci, &info);
 	r82600_process_error_info(mci, &info, 1);
 }
diff --git a/drivers/edac/x38_edac.c b/drivers/edac/x38_edac.c
index a65e2f78a402..49ab5721aab2 100644
--- a/drivers/edac/x38_edac.c
+++ b/drivers/edac/x38_edac.c
@@ -238,7 +238,6 @@ static void x38_check(struct mem_ctl_info *mci)
 {
 	struct x38_error_info info;
 
-	edac_dbg(1, "MC%d\n", mci->mc_idx);
 	x38_get_and_clear_error_info(mci, &info);
 	x38_process_error_info(mci, &info);
 }
-- 
2.21.0


-- 
Regards/Gruss,
    Boris.

https://people.kernel.org/tglx/notes-about-netiquette

Re: Constant output in syslog of EDAC message

[Jason Baron]

On 10/20/20 5:19 AM, Borislav Petkov wrote:
> On Mon, Oct 19, 2020 at 05:25:43PM -0400, Jason Baron wrote:
>> Yes, I likely was just following what was in other edac drivers at
>> the time - for example, i3200_check() has a similar debug. I guess
>> it could have a higher level. But if we remove this one, we may
>> want to audit some of the other edac drivers as well.
> 
> Sounds good. So one patch removing them all would make sense. If
> you feel like doing it, be my guest. Otherwise, it'll land on my
> ever-growing todo. :-\
> 
> Thx.
> 

Hi Boris,

I thought a bit about this - and was wondering if it made sense to
hook the edac debug messages up to 'dynamic debug'. The idea is that
different users may want different debug messages enabled, and this
way they can control each message as desired. Jim (added to 'cc)
recently exported 'ddebug_exec_queries()' to make that easier to do:
https://lore.kernel.org/lkml/20200620180643.887546-16-jim.cromie@gmail.com/

So, we would still continue to support edac_debug_level=N but the
user would have additional control. I tried it out (below) and
doesn't look too bad (at least to me).

Thanks,

-Jason

diff --git a/drivers/edac/Kconfig b/drivers/edac/Kconfig
index 7a47680d6f07..0c1c97e42a63 100644
--- a/drivers/edac/Kconfig
+++ b/drivers/edac/Kconfig
@@ -34,6 +34,7 @@ config EDAC_LEGACY_SYSFS
 config EDAC_DEBUG
 	bool "Debugging"
 	select DEBUG_FS
+	select DYNAMIC_DEBUG_CORE
 	help
 	  This turns on debugging information for the entire EDAC subsystem.
 	  You do so by inserting edac_module with "edac_debug_level=x." Valid
diff --git a/drivers/edac/Makefile b/drivers/edac/Makefile
index 3a849168780d..21ad452f1193 100644
--- a/drivers/edac/Makefile
+++ b/drivers/edac/Makefile
@@ -8,6 +8,10 @@

 obj-$(CONFIG_EDAC)			:= edac_core.o

+ifdef CONFIG_EDAC_DEBUG
+ccflags-y += -DDYNAMIC_DEBUG_MODULE
+endif
+
 edac_core-y	:= edac_mc.o edac_device.o edac_mc_sysfs.o
 edac_core-y	+= edac_module.o edac_device_sysfs.o wq.o

diff --git a/drivers/edac/edac_mc.h b/drivers/edac/edac_mc.h
index 881b00eadf7a..75dd4357d430 100644
--- a/drivers/edac/edac_mc.h
+++ b/drivers/edac/edac_mc.h
@@ -48,6 +48,9 @@
 #define edac_printk(level, prefix, fmt, arg...) \
 	printk(level "EDAC " prefix ": " fmt, ##arg)

+#define edac_dbg_printk(level, prefix, fmt, arg...) \
+	pr_debug("EDAC " prefix #level ": " fmt, ##arg)
+
 #define edac_mc_printk(mci, level, fmt, arg...) \
 	printk(level "EDAC MC%d: " fmt, mci->mc_idx, ##arg)

@@ -70,11 +73,9 @@ extern const char * const edac_mem_types[];
 #ifdef CONFIG_EDAC_DEBUG
 extern int edac_debug_level;

-#define edac_dbg(level, fmt, ...)					\
-do {									\
-	if (level <= edac_debug_level)					\
-		edac_printk(KERN_DEBUG, EDAC_DEBUG,			\
-			    "%s: " fmt, __func__, ##__VA_ARGS__);	\
+#define edac_dbg(level, fmt, ...)					    \
+do {									    \
+	edac_dbg_printk(level, EDAC_DEBUG, "%s: " fmt, __func__, ##__VA_ARGS__);\
 } while (0)

 #else				/* !CONFIG_EDAC_DEBUG */
diff --git a/drivers/edac/edac_module.c b/drivers/edac/edac_module.c
index 32a931d0cb71..6109589858c0 100644
--- a/drivers/edac/edac_module.c
+++ b/drivers/edac/edac_module.c
@@ -11,6 +11,7 @@
  *
  */
 #include <linux/edac.h>
+#include <linux/dynamic_debug.h>

 #include "edac_mc.h"
 #include "edac_module.h"
@@ -19,6 +20,29 @@

 #ifdef CONFIG_EDAC_DEBUG

+static int edac_debug_level_initialized;
+/* Values of 0 to 4 will generate output */
+int edac_debug_level = 2;
+EXPORT_SYMBOL_GPL(edac_debug_level);
+
+static void edac_set_dynamic_debug_level(int level)
+{
+	char buf[32];
+	int i;
+
+	edac_debug_level_initialized = 1;
+	for (i = 0; i <= 4; i++) {
+		snprintf(buf, 32, "format '^EDAC DEBUG%d' %cp", i, i <= level ? '+' : '-');
+		dynamic_debug_exec_queries(buf, NULL);
+	}
+}
+
+static void edac_set_debug_level_init(void)
+{
+	if (!edac_debug_level_initialized)
+		edac_set_dynamic_debug_level(edac_debug_level);
+}
+
 static int edac_set_debug_level(const char *buf,
 				const struct kernel_param *kp)
 {
@@ -32,13 +56,11 @@ static int edac_set_debug_level(const char *buf,
 	if (val > 4)
 		return -EINVAL;

+	edac_set_dynamic_debug_level(val);
+
 	return param_set_int(buf, kp);
 }

-/* Values of 0 to 4 will generate output */
-int edac_debug_level = 2;
-EXPORT_SYMBOL_GPL(edac_debug_level);
-
 module_param_call(edac_debug_level, edac_set_debug_level, param_get_int,
 		  &edac_debug_level, 0644);
 MODULE_PARM_DESC(edac_debug_level, "EDAC debug level: [0-4], default: 2");
@@ -130,6 +152,8 @@ static int __init edac_init(void)
 		goto err_wq;
 	}

+	edac_set_debug_level_init();
+
 	return 0;

 err_wq:
diff --git a/drivers/edac/edac_module.h b/drivers/edac/edac_module.h
index aa1f91688eb8..7f16428a266a 100644
--- a/drivers/edac/edac_module.h
+++ b/drivers/edac/edac_module.h
@@ -99,6 +99,7 @@ static inline void edac_debugfs_create_x16(const char *name, umode_t mode,
 					   struct dentry *parent, u16 *value)	{ }
 static inline void edac_debugfs_create_x32(const char *name, umode_t mode,
 		       struct dentry *parent, u32 *value)			{ }
+static inline void edac_set_debug_level_init(void)				{ }
 #endif

 /*

Re: Constant output in syslog of EDAC message

[Borislav Petkov]

Hi,

On Mon, Oct 26, 2020 at 01:47:05PM -0400, Jason Baron wrote:
> So, we would still continue to support edac_debug_level=N but the
> user would have additional control.

Do you have any actual users needing this? If yes, what are their use
cases?

Because I have this aversion towards adding functionality just because
and that it potentially might be useful and "users may want". Either
they do and they want to use it for X or we don't do anything... yet.

In this particular example, those debug printks are just useless noise
so off they go.

Thx.

-- 
Regards/Gruss,
    Boris.

https://people.kernel.org/tglx/notes-about-netiquette

Re: Constant output in syslog of EDAC message

[Jason Baron]

On 10/26/20 2:10 PM, Borislav Petkov wrote:
> Hi,
> 
> On Mon, Oct 26, 2020 at 01:47:05PM -0400, Jason Baron wrote:
>> So, we would still continue to support edac_debug_level=N but the
>> user would have additional control.
> 
> Do you have any actual users needing this? If yes, what are their use
> cases?
> 
> Because I have this aversion towards adding functionality just because
> and that it potentially might be useful and "users may want". Either
> they do and they want to use it for X or we don't do anything... yet.
> 
> In this particular example, those debug printks are just useless noise
> so off they go.
> 
> Thx.
> 

Hi Boris,

So I was motivated by this example, where if we had this facility,
we could easily say just go turn off that specific print instead of
wait for a new kernel. More generally, I think as you crank up the
verbosity there may be more of a need to customize the debug
information, but I don't have any specific use case in mind beyond
that.

I was also curious if various subsystems would find this facility
useful.

Thanks,

-Jason