: Use cmpxchg() in WARN_*_ONCE() functions

PATCH In review Prarit Bhargava 2 participants 4 messages Mar 31, 2011 – Apr 2, 2011 Generic include/asm header files

Share & tools

Prarit Bhargava

author

2011-03-31 12:46 UTC #0 lore raw

PATCH 1/1 : Use cmpxchg() in WARN_*_ONCE() functions

An issue popped up where WARN_ON_ONCE() was used in a callback function in smp_call_function(). This resulted in the WARN_ON executing multiple times when it should have only executed once.

We cannot use a lock in the WARN_*_ONCE functions because it is far too heavy for the code in question. Don Zickus suggested using cmpxchg(), which resolves the problem of the multiple outputs.

The question surrounding cmpxchg(), of course, is one of performance. It appears that, at least on x86, it isn't a concern.

I ran the following test in a simple module:

void prarit_callback(void *info)

{
        WARN_ON_ONCE(1);
}

        for (j = 0; j < 10; j++)
                for (i = 0; i < 1000000; i++)
                        prarit_callback(NULL);

With the current code in place an average of 10 runs was .219s. Doing just a (!cmpxchg(&__warned, 0, 1)) the time jumps to .402s. Adding in a check for the __warned flag, (!__warned && !cmpxchg(&__warned, 0, 1)), results in an average of .220s.

I then did

        for (i = 0; i < 1000000; i++)
                on_each_cpu(prarit_callback, NULL, 0);

The current code, of course, explodes :). That's the bug I'm trying to fix. What is interesting in this test, however, is the impact that checking the !__warned flag has [Aside: Checking the !__warned flag is an enhancement and is not explicitly required for this code].

A run with just (!cmpxchg(&__warned, 0, 1)) results in an average of 21.323s, and a run with (!__warned && !cmpxchg(&__warned, 0, 1)) results in an average of 20.233s. Of course, the !__warned is not necessary for the code to work properly but it seems to be a significant impact to the time to run this code.

WARN_ON_ONCE() is used in callback functions in smp_call_function(). This results in races through the WARN_ON() code.

Use cmxchg() in the WARN_*_ON functions in order to guarantee single execution of the WARN_ONs.

Signed-off-by Prarit Bhargava <[email protected]>

include/asm-generic/bug.h +9 -7

index f2d2faf..cbefd54 100644
@@ -133,30 +133,32 @@ extern void warn_slowpath_null(const char *file, const int line);
 #endif
 
 #define WARN_ON_ONCE(condition)	({				\
-	static bool __warned;					\
+	static int __warned;					\
 	int __ret_warn_once = !!(condition);			\
 								\
 	if (unlikely(__ret_warn_once))				\
-		if (WARN_ON(!__warned)) 			\
-			__warned = true;			\
+		if (!__warned && !cmpxchg(&__warned, 0, 1))	\
+			WARN_ON(1);				\
 	unlikely(__ret_warn_once);				\
 })
 
 #define WARN_ONCE(condition, format...)	({			\
-	static bool __warned;					\
+	static int __warned;					\
 	int __ret_warn_once = !!(condition);			\
 								\
 	if (unlikely(__ret_warn_once))				\
-		if (WARN(!__warned, format)) 			\
-			__warned = true;			\
+		if (!__warned && !cmpxchg(&__warned, 0, 1))	\
+			WARN(1, format);			\
 	unlikely(__ret_warn_once);				\
 })
 
 #define WARN_TAINT_ONCE(condition, taint, format...)	({	\
-	static bool __warned;					\
+	static int __warned;					\
 	int __ret_warn_once = !!(condition);			\
 								\
 	if (unlikely(__ret_warn_once))				\
+		if (!__warned && !cmpxchg(&__warned, 0, 1))	\
+			WARN_TAINT(1, taint, format);		\
 		if (WARN_TAINT(!__warned, taint, format))	\
 			__warned = true;			\
 	unlikely(__ret_warn_once);				\

Steven Rostedt

2011-03-31 15:23 UTC #1 lore raw

Quoted 3 lines · Prarit Bhargava

An issue popped up where WARN_ON_ONCE() was used in a callback function in smp_call_function(). This resulted in the WARN_ON executing multiple times when it should have only executed once.

But that is just once per cpu, correct?

Quoted 7 lines

I then did
        for (i = 0; i < 1000000; i++)
                on_each_cpu(prarit_callback, NULL, 0);
The current code, of course, explodes :). That's the bug I'm trying to fix.

How exactly does it explode? How many CPUs do you have, and does this still just print once per CPU?

Quoted 9 lines

What is interesting in this test, however, is the impact that checking the !__warned flag has [Aside: Checking the !__warned flag is an enhancement and is not explicitly required for this code].
A run with just (!cmpxchg(&__warned, 0, 1)) results in an average of 21.323s, and a run with (!__warned && !cmpxchg(&__warned, 0, 1)) results in an average of 20.233s. Of course, the !__warned is not necessary for the code to work properly but it seems to be a significant impact to the time to run this code.

Yes adding the check for !__warned first should have obvious benefits.

I really do not see anything wrong with this patch, but personally, I would rather fix what caused the WARN_ON_ONCE() than fix the warning itself, as long as the warning itself does not really break anything else.

-- Steve

Prarit Bhargava

author

2011-03-31 15:32 UTC #2 lore raw

Hey Steve,

Quoted 8 lines · Steven Rostedt

Quoted 4 lines · Prarit Bhargava
An issue popped up where WARN_ON_ONCE() was used in a callback function in smp_call_function(). This resulted in the WARN_ON executing multiple times when it should have only executed once.
But that is just once per cpu, correct?

Not always. Sometimes I see a subset of CPUs ... maybe a cacheflush or something hits that finally causes the remaining cpus to see __warned? I dunno...

But I have had 24/24 cpus output the message.

Quoted 12 lines

Quoted 8 lines
I then did
        for (i = 0; i < 1000000; i++)
                on_each_cpu(prarit_callback, NULL, 0);
The current code, of course, explodes :). That's the bug I'm trying to fix.
How exactly does it explode? How many CPUs do you have, and does this still just print once per CPU?

It explodes because each cpu spits out a warning (which is the issue I'm trying to resolve).

24 physical cores is what I tested on, but this has been seen in the field on a system with 6 on RHEL6 (2.6.32/33/34/35/36/37/38-ish).

Quoted 10 lines

Quoted 10 lines
What is interesting in this test, however, is the impact that checking the !__warned flag has [Aside: Checking the !__warned flag is an enhancement and is not explicitly required for this code].
A run with just (!cmpxchg(&__warned, 0, 1)) results in an average of 21.323s, and a run with (!__warned && !cmpxchg(&__warned, 0, 1)) results in an average of 20.233s. Of course, the !__warned is not necessary for the code to work properly but it seems to be a significant impact to the time to run this code.

Quoted 7 lines

Yes adding the check for !__warned first should have obvious benefits.
I really do not see anything wrong with this patch, but personally, I would rather fix what caused the WARN_ON_ONCE() than fix the warning itself, as long as the warning itself does not really break anything else.

The WARN_ON_ONCE was triggering due to bad HW setup. The system in question had the APERFMPERF flag only set on the boot cpu and no other cpus. This caused the system to generate warnings in the acpi cpufreq code.

The HW issue was resolved by modifying a BIOS setting which was found to clear the APERFMPERF cpu flag setting on the !boot cpus. Yes, this means the HW is busted.

But ... that still leaves the possibility that WARN_ON_ONCE spits out many warnings instead of just one. Hence, the patch.

Prarit Bhargava

author

2011-04-02 12:51 UTC #3 lore raw

In reply to Steven Rostedt

Missed deleting a chunk at the end of the patch...

An issue popped up where WARN_ON_ONCE() was used in a callback function in smp_call_function(). This resulted in the WARN_ON executing multiple times when it should have only executed once.

We cannot use a lock in the WARN_*_ONCE functions because it is far too heavy for the code in question. Don Zickus suggested using cmpxchg(), which resolves the problem of the multiple outputs.

The question surrounding cmpxchg(), of course, is one of performance. It appears that, at least on x86, it isn't a concern.

I ran the following test in a simple module:

void prarit_callback(void *info)

{
        WARN_ON_ONCE(1);
}

        for (j = 0; j < 10; j++)
                for (i = 0; i < 1000000; i++)
                        prarit_callback(NULL);

I then did

        for (i = 0; i < 1000000; i++)
                on_each_cpu(prarit_callback, NULL, 0);

WARN_ON_ONCE() is used in callback functions in smp_call_function(). This results in races through the WARN_ON() code.

Use cmxchg() in the WARN_*_ON functions in order to guarantee single execution of the WARN_ONs.

Signed-off-by Prarit Bhargava <[email protected]>

include/asm-generic/bug.h +9 -9

index f2d2faf..1825fd7 100644
@@ -133,32 +133,32 @@ extern void warn_slowpath_null(const char *file, const int line);
 #endif
 
 #define WARN_ON_ONCE(condition)	({				\
-	static bool __warned;					\
+	static int __warned;					\
 	int __ret_warn_once = !!(condition);			\
 								\
 	if (unlikely(__ret_warn_once))				\
-		if (WARN_ON(!__warned)) 			\
-			__warned = true;			\
+		if (!__warned && !cmpxchg(&__warned, 0, 1))	\
+			WARN_ON(1);				\
 	unlikely(__ret_warn_once);				\
 })
 
 #define WARN_ONCE(condition, format...)	({			\
-	static bool __warned;					\
+	static int __warned;					\
 	int __ret_warn_once = !!(condition);			\
 								\
 	if (unlikely(__ret_warn_once))				\
-		if (WARN(!__warned, format)) 			\
-			__warned = true;			\
+		if (!__warned && !cmpxchg(&__warned, 0, 1))	\
+			WARN(1, format);			\
 	unlikely(__ret_warn_once);				\
 })
 
 #define WARN_TAINT_ONCE(condition, taint, format...)	({	\
-	static bool __warned;					\
+	static int __warned;					\
 	int __ret_warn_once = !!(condition);			\
 								\
 	if (unlikely(__ret_warn_once))				\
-		if (WARN_TAINT(!__warned, taint, format))	\
-			__warned = true;			\
+		if (!__warned && !cmpxchg(&__warned, 0, 1))	\
+			WARN_TAINT(1, taint, format);		\
 	unlikely(__ret_warn_once);				\
 })