Skip to contentSkip to conversation

Fix suspicious RCU usage in msr tracing.

PATCH Dave Jones 3 participants 3 messages Mar 15, 2016 – Mar 18, 2016 x86

lore
Share & tools
lore

Dave Jones

author
#0 lore raw

Since 4.4, I've been able to trigger this occasionally:

===============================
[ INFO: suspicious RCU usage. ]
4.5.0-rc7-think+ #3 Not tainted
-------------------------------
./arch/x86/include/asm/msr-trace.h:47 suspicious rcu_dereference_check() usage!

other info that might help us debug this:

RCU used illegally from idle CPU!
rcu_scheduler_active = 1, debug_locks = 1
RCU used illegally from extended quiescent state!
no locks held by swapper/3/0.

stack backtrace:
CPU: 3 PID: 0 Comm: swapper/3 Not tainted 4.5.0-rc7-think+ #3
 ffffffff92f821e0 1f3e5c340597d7fc ffff880468e07f10 ffffffff92560c2a
 ffff880462145280 0000000000000001 ffff880468e07f40 ffffffff921376a6
 ffffffff93665ea0 0000cc7c876d28da 0000000000000005 ffffffff9383dd60
Call Trace:
 <IRQ>  [<ffffffff92560c2a>] dump_stack+0x67/0x9d
 [<ffffffff921376a6>] lockdep_rcu_suspicious+0xe6/0x100
 [<ffffffff925ae7a7>] do_trace_write_msr+0x127/0x1a0
 [<ffffffff92061c83>] native_apic_msr_eoi_write+0x23/0x30
 [<ffffffff92054408>] smp_trace_call_function_interrupt+0x38/0x360
 [<ffffffff92d1ca60>] trace_call_function_interrupt+0x90/0xa0
 <EOI>  [<ffffffff92ac5124>] ? cpuidle_enter_state+0x1b4/0x520
 [<ffffffff92ac54e7>] cpuidle_enter+0x17/0x20
 [<ffffffff9212a984>] cpu_startup_entry+0x4e4/0x610
 [<ffffffff9212a4a0>] ? default_idle_call+0x60/0x60
 [<ffffffff921908e4>] ? clockevents_config_and_register+0x64/0x70
 [<ffffffff92055843>] start_secondary+0x283/0x390
 [<ffffffff920555c0>] ? set_cpu_sibling_map+0x970/0x970

Back in January, Andi suggested swapping the order in which we ack the APIC irq, so it too is protected by rcu. There was no follow-up, and it seems to work for me.

Cc Andi Kleen <[email protected]>
Signed-off-by Dave Jones <[email protected]>
arch/x86/include/asm/apic.h +1 -1
index c80f6b6f3da2..e8c4fba52d3d 100644
@@ -644,8 +644,8 @@ static inline void entering_irq(void)
 
 static inline void entering_ack_irq(void)
 {
-	ack_APIC_irq();
 	entering_irq();
+	ack_APIC_irq();
 }
 
 static inline void ipi_entering_ack_irq(void)
Reviewed-by
#1 lore raw
Quoted 5 lines

Back in January, Andi suggested swapping the order in which we ack the APIC irq, so it too is protected by rcu. There was no follow-up, and it seems to work for me.

Cc Andi Kleen <[email protected]>
Reviewed-by Andi Kleen <[email protected]>

-Andi

Quoted 16 lines
Signed-off-by Dave Jones <[email protected]>
arch/x86/include/asm/apic.h +1 -1
index c80f6b6f3da2..e8c4fba52d3d 100644
@@ -644,8 +644,8 @@ static inline void entering_irq(void)
 
 static inline void entering_ack_irq(void)
 {
-	ack_APIC_irq();
 	entering_irq();
+	ack_APIC_irq();
 }
 
 static inline void ipi_entering_ack_irq(void)
Signature · 1 line
[email protected] -- Speaking for myself only
merge bot
#2 lore raw

[tip:x86/urgent] x86/apic: Fix suspicious RCU usage in smp_trace_call_function_interrupt()

In reply to Dave Jones
x86/apic: Fix suspicious RCU usage in smp_trace_call_function_interrupt()
Commit-ID:  7834c10313fb823e538f2772be78edcdeed2e6e3
Gitweb:     http://git.kernel.org/tip/7834c10313fb823e538f2772be78edcdeed2e6e3
Author:     Dave Jones <[email protected]>
AuthorDate: Mon, 14 Mar 2016 21:20:54 -0400
Committer:  Thomas Gleixner <[email protected]>
CommitDate: Fri, 18 Mar 2016 14:51:06 +0100

x86/apic: Fix suspicious RCU usage in smp_trace_call_function_interrupt()

Since 4.4, I've been able to trigger this occasionally:

===============================
[ INFO: suspicious RCU usage. ]
4.5.0-rc7-think+ #3 Not tainted

Cc Andi Kleen <[email protected]>
Link http://lkml.kernel.org/r/[email protected] open here
Signed-off-by Thomas Gleixner <[email protected]>

-------------------------------
./arch/x86/include/asm/msr-trace.h:47 suspicious rcu_dereference_check() usage!

other info that might help us debug this:

RCU used illegally from idle CPU!
rcu_scheduler_active = 1, debug_locks = 1
RCU used illegally from extended quiescent state!
no locks held by swapper/3/0.

stack backtrace:
CPU: 3 PID: 0 Comm: swapper/3 Not tainted 4.5.0-rc7-think+ #3
 ffffffff92f821e0 1f3e5c340597d7fc ffff880468e07f10 ffffffff92560c2a
 ffff880462145280 0000000000000001 ffff880468e07f40 ffffffff921376a6
 ffffffff93665ea0 0000cc7c876d28da 0000000000000005 ffffffff9383dd60
Call Trace:
 <IRQ>  [<ffffffff92560c2a>] dump_stack+0x67/0x9d
 [<ffffffff921376a6>] lockdep_rcu_suspicious+0xe6/0x100
 [<ffffffff925ae7a7>] do_trace_write_msr+0x127/0x1a0
 [<ffffffff92061c83>] native_apic_msr_eoi_write+0x23/0x30
 [<ffffffff92054408>] smp_trace_call_function_interrupt+0x38/0x360
 [<ffffffff92d1ca60>] trace_call_function_interrupt+0x90/0xa0
 <EOI>  [<ffffffff92ac5124>] ? cpuidle_enter_state+0x1b4/0x520

Move the entering_irq() call before ack_APIC_irq(), because entering_irq() tells the RCU susbstems to end the extended quiescent state, so that the following trace call in ack_APIC_irq() works correctly.

Suggested-by Andi Kleen <[email protected]>
Fixes 4787c368a9bc "x86/tracing: Add irq_enter/exit() in smp_trace_reschedule_interrupt()"
Signed-off-by Dave Jones <[email protected]>
Signed-off-by Thomas Gleixner <[email protected]>
Cc [email protected]
---
 arch/x86/include/asm/apic.h | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
arch/x86/include/asm/apic.h +1 -1
index 0899cfc..98f25bb 100644
@@ -643,8 +643,8 @@ static inline void entering_irq(void)
 
 static inline void entering_ack_irq(void)
 {
-	ack_APIC_irq();
 	entering_irq();
+	ack_APIC_irq();
 }
 
 static inline void ipi_entering_ack_irq(void)