Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1526322 > unrolled thread

[BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage!

Started byJiri Olsa <jolsa@redhat.com>
First post2016-11-21 02:00 +0100
Last post2016-11-21 21:20 +0100
Articles 20 on this page of 34 — 6 participants

Back to article view | Back to linux.kernel

Contents

  [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Jiri Olsa <jolsa@redhat.com> - 2016-11-21 02:00 +0100
    Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-11-21 10:10 +0100
      Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Peter Zijlstra <peterz@infradead.org> - 2016-11-21 10:50 +0100
        Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-11-21 12:10 +0100
    Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Peter Zijlstra <peterz@infradead.org> - 2016-11-21 10:30 +0100
      Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Jiri Olsa <jolsa@redhat.com> - 2016-11-21 10:40 +0100
        Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Peter Zijlstra <peterz@infradead.org> - 2016-11-21 10:50 +0100
          Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Jiri Olsa <jolsa@redhat.com> - 2016-11-21 12:30 +0100
            Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Peter Zijlstra <peterz@infradead.org> - 2016-11-21 12:40 +0100
              Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Jiri Olsa <jolsa@redhat.com> - 2016-11-21 13:50 +0100
        Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Peter Zijlstra <peterz@infradead.org> - 2016-11-21 14:00 +0100
          Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Steven Rostedt <rostedt@goodmis.org> - 2016-11-21 15:30 +0100
            Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Peter Zijlstra <peterz@infradead.org> - 2016-11-21 15:40 +0100
              Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Borislav Petkov <bp@alien8.de> - 2016-11-21 16:40 +0100
                Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Peter Zijlstra <peterz@infradead.org> - 2016-11-21 16:50 +0100
                  Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Borislav Petkov <bp@alien8.de> - 2016-11-21 17:10 +0100
          Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Steven Rostedt <rostedt@goodmis.org> - 2016-11-21 15:30 +0100
      Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Andi Kleen <andi@firstfloor.org> - 2016-11-21 18:10 +0100
        Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Peter Zijlstra <peterz@infradead.org> - 2016-11-21 18:20 +0100
          Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Andi Kleen <andi@firstfloor.org> - 2016-11-21 18:50 +0100
            Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Andi Kleen <andi@firstfloor.org> - 2016-11-21 19:10 +0100
              Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Steven Rostedt <rostedt@goodmis.org> - 2016-11-21 19:30 +0100
                Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Andi Kleen <andi@firstfloor.org> - 2016-11-21 19:40 +0100
                  Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Steven Rostedt <rostedt@goodmis.org> - 2016-11-21 20:10 +0100
                  Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Steven Rostedt <rostedt@goodmis.org> - 2016-11-21 20:20 +0100
                    Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Andi Kleen <andi@firstfloor.org> - 2016-11-21 21:50 +0100
                      Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-11-22 09:20 +0100
                  Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Steven Rostedt <rostedt@goodmis.org> - 2016-11-22 15:40 +0100
                    Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Andi Kleen <andi@firstfloor.org> - 2016-11-22 20:10 +0100
                  Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Steven Rostedt <rostedt@goodmis.org> - 2016-11-24 03:10 +0100
            Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Steven Rostedt <rostedt@goodmis.org> - 2016-11-21 19:10 +0100
          Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Steven Rostedt <rostedt@goodmis.org> - 2016-11-21 19:00 +0100
            Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! Steven Rostedt <rostedt@goodmis.org> - 2016-11-21 19:30 +0100
              Re: [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage! "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-11-21 21:20 +0100

Page 1 of 2  [1] 2  Next page →

#1526322 — [BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage!

FromJiri Olsa <jolsa@redhat.com>
Date2016-11-21 02:00 +0100
Subject[BUG] msr-trace.h:42 suspicious rcu_dereference_check() usage!
Message-ID<sFL7H-2pc-3@gated-at.bofh.it>
hi,
Jan hit following output when msr tracepoints are enabled on amd server:

[   91.585653] ===============================
[   91.589840] [ INFO: suspicious RCU usage. ]
[   91.594025] 4.9.0-rc1+ #1 Not tainted
[   91.597691] -------------------------------
[   91.601877] ./arch/x86/include/asm/msr-trace.h:42 suspicious rcu_dereference_check() usage!
[   91.610222] 
[   91.610222] other info that might help us debug this:
[   91.610222] 
[   91.618224] 
[   91.618224] RCU used illegally from idle CPU!
[   91.618224] rcu_scheduler_active = 1, debug_locks = 0
[   91.629081] RCU used illegally from extended quiescent state!
[   91.634820] no locks held by swapper/1/0.
[   91.638832] 
[   91.638832] stack backtrace:
[   91.643192] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.9.0-rc1+ #1
[   91.649457] Hardware name: empty empty/S3992, BIOS 'V2.03   ' 05/09/2008
[   91.656159]  ffffc900018fbdf8 ffffffff813ed43c ffff88017ede8000 0000000000000001
[   91.663637]  ffffc900018fbe28 ffffffff810fdcd7 ffff880233f95dd0 00000000c0010055
[   91.671107]  0000000000000000 0000000000000000 ffffc900018fbe58 ffffffff814297ac
[   91.678560] Call Trace:
[   91.681022]  [<ffffffff813ed43c>] dump_stack+0x85/0xc9
[   91.686164]  [<ffffffff810fdcd7>] lockdep_rcu_suspicious+0xe7/0x120
[   91.692429]  [<ffffffff814297ac>] do_trace_read_msr+0x14c/0x1b0
[   91.698349]  [<ffffffff8106ddb2>] native_read_msr+0x32/0x40
[   91.703921]  [<ffffffff8103b2be>] amd_e400_idle+0x7e/0x110
[   91.709407]  [<ffffffff8103b78f>] arch_cpu_idle+0xf/0x20
[   91.714720]  [<ffffffff8181cd33>] default_idle_call+0x23/0x40
[   91.720467]  [<ffffffff810f306a>] cpu_startup_entry+0x1da/0x2b0
[   91.726387]  [<ffffffff81058b1f>] start_secondary+0x17f/0x1f0


it got away with attached change.. but this rcu logic
is far beyond me, so it's just wild guess.. ;-)

thanks,
jirka


---
diff --git a/arch/x86/lib/msr.c b/arch/x86/lib/msr.c
index d1dee753b949..ca15becea3b6 100644
--- a/arch/x86/lib/msr.c
+++ b/arch/x86/lib/msr.c
@@ -115,14 +115,14 @@ int msr_clear_bit(u32 msr, u8 bit)
 #ifdef CONFIG_TRACEPOINTS
 void do_trace_write_msr(unsigned msr, u64 val, int failed)
 {
-	trace_write_msr(msr, val, failed);
+	trace_write_msr_rcuidle(msr, val, failed);
 }
 EXPORT_SYMBOL(do_trace_write_msr);
 EXPORT_TRACEPOINT_SYMBOL(write_msr);
 
 void do_trace_read_msr(unsigned msr, u64 val, int failed)
 {
-	trace_read_msr(msr, val, failed);
+	trace_read_msr_rcuidle(msr, val, failed);
 }
 EXPORT_SYMBOL(do_trace_read_msr);
 EXPORT_TRACEPOINT_SYMBOL(read_msr);

[toc] | [next] | [standalone]

#1526474

From"Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
Date2016-11-21 10:10 +0100
Message-ID<sFSLU-7Fl-55@gated-at.bofh.it>
In reply to#1526322
On Mon, Nov 21, 2016 at 01:53:43AM +0100, Jiri Olsa wrote:
> hi,
> Jan hit following output when msr tracepoints are enabled on amd server:
> 
> [   91.585653] ===============================
> [   91.589840] [ INFO: suspicious RCU usage. ]
> [   91.594025] 4.9.0-rc1+ #1 Not tainted
> [   91.597691] -------------------------------
> [   91.601877] ./arch/x86/include/asm/msr-trace.h:42 suspicious rcu_dereference_check() usage!
> [   91.610222] 
> [   91.610222] other info that might help us debug this:
> [   91.610222] 
> [   91.618224] 
> [   91.618224] RCU used illegally from idle CPU!
> [   91.618224] rcu_scheduler_active = 1, debug_locks = 0
> [   91.629081] RCU used illegally from extended quiescent state!
> [   91.634820] no locks held by swapper/1/0.
> [   91.638832] 
> [   91.638832] stack backtrace:
> [   91.643192] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.9.0-rc1+ #1
> [   91.649457] Hardware name: empty empty/S3992, BIOS 'V2.03   ' 05/09/2008
> [   91.656159]  ffffc900018fbdf8 ffffffff813ed43c ffff88017ede8000 0000000000000001
> [   91.663637]  ffffc900018fbe28 ffffffff810fdcd7 ffff880233f95dd0 00000000c0010055
> [   91.671107]  0000000000000000 0000000000000000 ffffc900018fbe58 ffffffff814297ac
> [   91.678560] Call Trace:
> [   91.681022]  [<ffffffff813ed43c>] dump_stack+0x85/0xc9
> [   91.686164]  [<ffffffff810fdcd7>] lockdep_rcu_suspicious+0xe7/0x120
> [   91.692429]  [<ffffffff814297ac>] do_trace_read_msr+0x14c/0x1b0
> [   91.698349]  [<ffffffff8106ddb2>] native_read_msr+0x32/0x40
> [   91.703921]  [<ffffffff8103b2be>] amd_e400_idle+0x7e/0x110
> [   91.709407]  [<ffffffff8103b78f>] arch_cpu_idle+0xf/0x20
> [   91.714720]  [<ffffffff8181cd33>] default_idle_call+0x23/0x40
> [   91.720467]  [<ffffffff810f306a>] cpu_startup_entry+0x1da/0x2b0
> [   91.726387]  [<ffffffff81058b1f>] start_secondary+0x17f/0x1f0
> 
> 
> it got away with attached change.. but this rcu logic
> is far beyond me, so it's just wild guess.. ;-)

If in idle, the _rcuidle() is needed, so:

Acked-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>

> thanks,
> jirka
> 
> 
> ---
> diff --git a/arch/x86/lib/msr.c b/arch/x86/lib/msr.c
> index d1dee753b949..ca15becea3b6 100644
> --- a/arch/x86/lib/msr.c
> +++ b/arch/x86/lib/msr.c
> @@ -115,14 +115,14 @@ int msr_clear_bit(u32 msr, u8 bit)
>  #ifdef CONFIG_TRACEPOINTS
>  void do_trace_write_msr(unsigned msr, u64 val, int failed)
>  {
> -	trace_write_msr(msr, val, failed);
> +	trace_write_msr_rcuidle(msr, val, failed);
>  }
>  EXPORT_SYMBOL(do_trace_write_msr);
>  EXPORT_TRACEPOINT_SYMBOL(write_msr);
> 
>  void do_trace_read_msr(unsigned msr, u64 val, int failed)
>  {
> -	trace_read_msr(msr, val, failed);
> +	trace_read_msr_rcuidle(msr, val, failed);
>  }
>  EXPORT_SYMBOL(do_trace_read_msr);
>  EXPORT_TRACEPOINT_SYMBOL(read_msr);
>

[toc] | [prev] | [next] | [standalone]

#1526487

FromPeter Zijlstra <peterz@infradead.org>
Date2016-11-21 10:50 +0100
Message-ID<sFToB-7Sv-13@gated-at.bofh.it>
In reply to#1526474
On Mon, Nov 21, 2016 at 01:02:25AM -0800, Paul E. McKenney wrote:
> On Mon, Nov 21, 2016 at 01:53:43AM +0100, Jiri Olsa wrote:
> > 
> > it got away with attached change.. but this rcu logic
> > is far beyond me, so it's just wild guess.. ;-)
> 
> If in idle, the _rcuidle() is needed, so:

Well, the point is, only this one rdmsr users is in idle, all the others
are not, so we should not be annotating _all_ of them, should we?

[toc] | [prev] | [next] | [standalone]

#1526577

From"Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
Date2016-11-21 12:10 +0100
Message-ID<sFUE1-pB-19@gated-at.bofh.it>
In reply to#1526487
On Mon, Nov 21, 2016 at 10:43:21AM +0100, Peter Zijlstra wrote:
> On Mon, Nov 21, 2016 at 01:02:25AM -0800, Paul E. McKenney wrote:
> > On Mon, Nov 21, 2016 at 01:53:43AM +0100, Jiri Olsa wrote:
> > > 
> > > it got away with attached change.. but this rcu logic
> > > is far beyond me, so it's just wild guess.. ;-)
> > 
> > If in idle, the _rcuidle() is needed, so:
> 
> Well, the point is, only this one rdmsr users is in idle, all the others
> are not, so we should not be annotating _all_ of them, should we?

Fair enough!

							Thanx, Paul

[toc] | [prev] | [next] | [standalone]

#1526478

FromPeter Zijlstra <peterz@infradead.org>
Date2016-11-21 10:30 +0100
Message-ID<sFT5f-7LV-3@gated-at.bofh.it>
In reply to#1526322
On Mon, Nov 21, 2016 at 01:53:43AM +0100, Jiri Olsa wrote:
> hi,
> Jan hit following output when msr tracepoints are enabled on amd server:
> 
> [   91.585653] ===============================
> [   91.589840] [ INFO: suspicious RCU usage. ]
> [   91.594025] 4.9.0-rc1+ #1 Not tainted
> [   91.597691] -------------------------------
> [   91.601877] ./arch/x86/include/asm/msr-trace.h:42 suspicious rcu_dereference_check() usage!
> [   91.610222] 
> [   91.610222] other info that might help us debug this:
> [   91.610222] 
> [   91.618224] 
> [   91.618224] RCU used illegally from idle CPU!
> [   91.618224] rcu_scheduler_active = 1, debug_locks = 0
> [   91.629081] RCU used illegally from extended quiescent state!
> [   91.634820] no locks held by swapper/1/0.
> [   91.638832] 
> [   91.638832] stack backtrace:
> [   91.643192] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.9.0-rc1+ #1
> [   91.649457] Hardware name: empty empty/S3992, BIOS 'V2.03   ' 05/09/2008
> [   91.656159]  ffffc900018fbdf8 ffffffff813ed43c ffff88017ede8000 0000000000000001
> [   91.663637]  ffffc900018fbe28 ffffffff810fdcd7 ffff880233f95dd0 00000000c0010055
> [   91.671107]  0000000000000000 0000000000000000 ffffc900018fbe58 ffffffff814297ac
> [   91.678560] Call Trace:
> [   91.681022]  [<ffffffff813ed43c>] dump_stack+0x85/0xc9
> [   91.686164]  [<ffffffff810fdcd7>] lockdep_rcu_suspicious+0xe7/0x120
> [   91.692429]  [<ffffffff814297ac>] do_trace_read_msr+0x14c/0x1b0
> [   91.698349]  [<ffffffff8106ddb2>] native_read_msr+0x32/0x40
> [   91.703921]  [<ffffffff8103b2be>] amd_e400_idle+0x7e/0x110
> [   91.709407]  [<ffffffff8103b78f>] arch_cpu_idle+0xf/0x20
> [   91.714720]  [<ffffffff8181cd33>] default_idle_call+0x23/0x40
> [   91.720467]  [<ffffffff810f306a>] cpu_startup_entry+0x1da/0x2b0
> [   91.726387]  [<ffffffff81058b1f>] start_secondary+0x17f/0x1f0
> 
> 
> it got away with attached change.. but this rcu logic
> is far beyond me, so it's just wild guess.. ;-)

I think I prefer something like the below, that only annotates the one
RDMSR in question, instead of all of them.


diff --git a/arch/x86/kernel/process.c b/arch/x86/kernel/process.c
index 0888a879120f..d6c6aa80675f 100644
--- a/arch/x86/kernel/process.c
+++ b/arch/x86/kernel/process.c
@@ -357,7 +357,7 @@ static void amd_e400_idle(void)
 	if (!amd_e400_c1e_detected) {
 		u32 lo, hi;
 
-		rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi);
+		RCU_NONIDLE(rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi));
 
 		if (lo & K8_INTP_C1E_ACTIVE_MASK) {
 			amd_e400_c1e_detected = true;

[toc] | [prev] | [next] | [standalone]

#1526485

FromJiri Olsa <jolsa@redhat.com>
Date2016-11-21 10:40 +0100
Message-ID<sFTeW-7P2-9@gated-at.bofh.it>
In reply to#1526478
On Mon, Nov 21, 2016 at 10:28:50AM +0100, Peter Zijlstra wrote:
> On Mon, Nov 21, 2016 at 01:53:43AM +0100, Jiri Olsa wrote:
> > hi,
> > Jan hit following output when msr tracepoints are enabled on amd server:
> > 
> > [   91.585653] ===============================
> > [   91.589840] [ INFO: suspicious RCU usage. ]
> > [   91.594025] 4.9.0-rc1+ #1 Not tainted
> > [   91.597691] -------------------------------
> > [   91.601877] ./arch/x86/include/asm/msr-trace.h:42 suspicious rcu_dereference_check() usage!
> > [   91.610222] 
> > [   91.610222] other info that might help us debug this:
> > [   91.610222] 
> > [   91.618224] 
> > [   91.618224] RCU used illegally from idle CPU!
> > [   91.618224] rcu_scheduler_active = 1, debug_locks = 0
> > [   91.629081] RCU used illegally from extended quiescent state!
> > [   91.634820] no locks held by swapper/1/0.
> > [   91.638832] 
> > [   91.638832] stack backtrace:
> > [   91.643192] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.9.0-rc1+ #1
> > [   91.649457] Hardware name: empty empty/S3992, BIOS 'V2.03   ' 05/09/2008
> > [   91.656159]  ffffc900018fbdf8 ffffffff813ed43c ffff88017ede8000 0000000000000001
> > [   91.663637]  ffffc900018fbe28 ffffffff810fdcd7 ffff880233f95dd0 00000000c0010055
> > [   91.671107]  0000000000000000 0000000000000000 ffffc900018fbe58 ffffffff814297ac
> > [   91.678560] Call Trace:
> > [   91.681022]  [<ffffffff813ed43c>] dump_stack+0x85/0xc9
> > [   91.686164]  [<ffffffff810fdcd7>] lockdep_rcu_suspicious+0xe7/0x120
> > [   91.692429]  [<ffffffff814297ac>] do_trace_read_msr+0x14c/0x1b0
> > [   91.698349]  [<ffffffff8106ddb2>] native_read_msr+0x32/0x40
> > [   91.703921]  [<ffffffff8103b2be>] amd_e400_idle+0x7e/0x110
> > [   91.709407]  [<ffffffff8103b78f>] arch_cpu_idle+0xf/0x20
> > [   91.714720]  [<ffffffff8181cd33>] default_idle_call+0x23/0x40
> > [   91.720467]  [<ffffffff810f306a>] cpu_startup_entry+0x1da/0x2b0
> > [   91.726387]  [<ffffffff81058b1f>] start_secondary+0x17f/0x1f0
> > 
> > 
> > it got away with attached change.. but this rcu logic
> > is far beyond me, so it's just wild guess.. ;-)
> 
> I think I prefer something like the below, that only annotates the one
> RDMSR in question, instead of all of them.

I was wondering about that, but haven't found RCU_NONIDLE 

thanks,
jirka

> 
> 
> diff --git a/arch/x86/kernel/process.c b/arch/x86/kernel/process.c
> index 0888a879120f..d6c6aa80675f 100644
> --- a/arch/x86/kernel/process.c
> +++ b/arch/x86/kernel/process.c
> @@ -357,7 +357,7 @@ static void amd_e400_idle(void)
>  	if (!amd_e400_c1e_detected) {
>  		u32 lo, hi;
>  
> -		rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi);
> +		RCU_NONIDLE(rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi));
>  
>  		if (lo & K8_INTP_C1E_ACTIVE_MASK) {
>  			amd_e400_c1e_detected = true;

[toc] | [prev] | [next] | [standalone]

#1526486

FromPeter Zijlstra <peterz@infradead.org>
Date2016-11-21 10:50 +0100
Message-ID<sFToB-7Sv-5@gated-at.bofh.it>
In reply to#1526485
On Mon, Nov 21, 2016 at 10:34:25AM +0100, Jiri Olsa wrote:
> On Mon, Nov 21, 2016 at 10:28:50AM +0100, Peter Zijlstra wrote:

> > I think I prefer something like the below, that only annotates the one
> > RDMSR in question, instead of all of them.
> 
> I was wondering about that, but haven't found RCU_NONIDLE 

Its in rcupdate.h ;-)

[toc] | [prev] | [next] | [standalone]

#1526587

FromJiri Olsa <jolsa@redhat.com>
Date2016-11-21 12:30 +0100
Message-ID<sFUXn-vK-21@gated-at.bofh.it>
In reply to#1526486
On Mon, Nov 21, 2016 at 10:42:27AM +0100, Peter Zijlstra wrote:
> On Mon, Nov 21, 2016 at 10:34:25AM +0100, Jiri Olsa wrote:
> > On Mon, Nov 21, 2016 at 10:28:50AM +0100, Peter Zijlstra wrote:
> 
> > > I think I prefer something like the below, that only annotates the one
> > > RDMSR in question, instead of all of them.
> > 
> > I was wondering about that, but haven't found RCU_NONIDLE 
> 
> Its in rcupdate.h ;-)

it was too late in the morning.. ;-) I'm assuming you'll queue this patch.. ?

thanks,
jirka

[toc] | [prev] | [next] | [standalone]

#1526589

FromPeter Zijlstra <peterz@infradead.org>
Date2016-11-21 12:40 +0100
Message-ID<sFV73-yJ-13@gated-at.bofh.it>
In reply to#1526587
On Mon, Nov 21, 2016 at 12:22:29PM +0100, Jiri Olsa wrote:
> On Mon, Nov 21, 2016 at 10:42:27AM +0100, Peter Zijlstra wrote:
> > On Mon, Nov 21, 2016 at 10:34:25AM +0100, Jiri Olsa wrote:
> > > On Mon, Nov 21, 2016 at 10:28:50AM +0100, Peter Zijlstra wrote:
> > 
> > > > I think I prefer something like the below, that only annotates the one
> > > > RDMSR in question, instead of all of them.
> > > 
> > > I was wondering about that, but haven't found RCU_NONIDLE 
> > 
> > Its in rcupdate.h ;-)
> 
> it was too late in the morning.. ;-) I'm assuming you'll queue this patch.. ?

Probably, I still have to make pretty the uncore patch from last week,
and I have a PEBS patch that needs looking at :-)

BTW, if you have any opinion on that PEBS register set crap, do holler
:-)

  lkml.kernel.org/r/20161117171731.GV3157@twins.programming.kicks-ass.net

[toc] | [prev] | [next] | [standalone]

#1526639

FromJiri Olsa <jolsa@redhat.com>
Date2016-11-21 13:50 +0100
Message-ID<sFWcN-1f8-11@gated-at.bofh.it>
In reply to#1526589
On Mon, Nov 21, 2016 at 12:31:31PM +0100, Peter Zijlstra wrote:
> On Mon, Nov 21, 2016 at 12:22:29PM +0100, Jiri Olsa wrote:
> > On Mon, Nov 21, 2016 at 10:42:27AM +0100, Peter Zijlstra wrote:
> > > On Mon, Nov 21, 2016 at 10:34:25AM +0100, Jiri Olsa wrote:
> > > > On Mon, Nov 21, 2016 at 10:28:50AM +0100, Peter Zijlstra wrote:
> > > 
> > > > > I think I prefer something like the below, that only annotates the one
> > > > > RDMSR in question, instead of all of them.
> > > > 
> > > > I was wondering about that, but haven't found RCU_NONIDLE 
> > > 
> > > Its in rcupdate.h ;-)
> > 
> > it was too late in the morning.. ;-) I'm assuming you'll queue this patch.. ?
> 
> Probably, I still have to make pretty the uncore patch from last week,
> and I have a PEBS patch that needs looking at :-)
> 
> BTW, if you have any opinion on that PEBS register set crap, do holler
> :-)
> 
>   lkml.kernel.org/r/20161117171731.GV3157@twins.programming.kicks-ass.net

ook, will check

thanks,
jirka

[toc] | [prev] | [next] | [standalone]

#1526650

FromPeter Zijlstra <peterz@infradead.org>
Date2016-11-21 14:00 +0100
Message-ID<sFWmz-1in-13@gated-at.bofh.it>
In reply to#1526485
On Mon, Nov 21, 2016 at 10:34:25AM +0100, Jiri Olsa wrote:

> > diff --git a/arch/x86/kernel/process.c b/arch/x86/kernel/process.c
> > index 0888a879120f..d6c6aa80675f 100644
> > --- a/arch/x86/kernel/process.c
> > +++ b/arch/x86/kernel/process.c
> > @@ -357,7 +357,7 @@ static void amd_e400_idle(void)
> >  	if (!amd_e400_c1e_detected) {
> >  		u32 lo, hi;
> >  
> > -		rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi);
> > +		RCU_NONIDLE(rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi));
> >  
> >  		if (lo & K8_INTP_C1E_ACTIVE_MASK) {
> >  			amd_e400_c1e_detected = true;

OK, so while looking at this again, I don't like this ether :/

Problem with this one is that it always adds the RCU fiddling overhead,
even when we're not tracing.

I could do an rdmsr_notrace() for this one, dunno if its important.

[toc] | [prev] | [next] | [standalone]

#1526715

FromSteven Rostedt <rostedt@goodmis.org>
Date2016-11-21 15:30 +0100
Message-ID<sFXLz-2km-9@gated-at.bofh.it>
In reply to#1526650
On Mon, 21 Nov 2016 13:58:30 +0100
Peter Zijlstra <peterz@infradead.org> wrote:

> On Mon, Nov 21, 2016 at 10:34:25AM +0100, Jiri Olsa wrote:
> 
> > > diff --git a/arch/x86/kernel/process.c b/arch/x86/kernel/process.c
> > > index 0888a879120f..d6c6aa80675f 100644
> > > --- a/arch/x86/kernel/process.c
> > > +++ b/arch/x86/kernel/process.c
> > > @@ -357,7 +357,7 @@ static void amd_e400_idle(void)
> > >  	if (!amd_e400_c1e_detected) {
> > >  		u32 lo, hi;
> > >  
> > > -		rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi);
> > > +		RCU_NONIDLE(rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi));
> > >  
> > >  		if (lo & K8_INTP_C1E_ACTIVE_MASK) {
> > >  			amd_e400_c1e_detected = true;  
> 
> OK, so while looking at this again, I don't like this ether :/
> 
> Problem with this one is that it always adds the RCU fiddling overhead,
> even when we're not tracing.
> 
> I could do an rdmsr_notrace() for this one, dunno if its important.

But that would neglect the point of tracing rdmsr. What about:

	/* tracepoints require RCU enabled */
	if (trace_read_msr_enabled())
		RCU_NONIDLE(rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi));
	else
		rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi);

-- Steve

[toc] | [prev] | [next] | [standalone]

#1526726

FromPeter Zijlstra <peterz@infradead.org>
Date2016-11-21 15:40 +0100
Message-ID<sFXVf-2nj-29@gated-at.bofh.it>
In reply to#1526715
On Mon, Nov 21, 2016 at 09:15:43AM -0500, Steven Rostedt wrote:
> On Mon, 21 Nov 2016 13:58:30 +0100
> Peter Zijlstra <peterz@infradead.org> wrote:
> 
> > On Mon, Nov 21, 2016 at 10:34:25AM +0100, Jiri Olsa wrote:
> > 
> > > > diff --git a/arch/x86/kernel/process.c b/arch/x86/kernel/process.c
> > > > index 0888a879120f..d6c6aa80675f 100644
> > > > --- a/arch/x86/kernel/process.c
> > > > +++ b/arch/x86/kernel/process.c
> > > > @@ -357,7 +357,7 @@ static void amd_e400_idle(void)
> > > >  	if (!amd_e400_c1e_detected) {
> > > >  		u32 lo, hi;
> > > >  
> > > > -		rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi);
> > > > +		RCU_NONIDLE(rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi));
> > > >  
> > > >  		if (lo & K8_INTP_C1E_ACTIVE_MASK) {
> > > >  			amd_e400_c1e_detected = true;  
> > 
> > OK, so while looking at this again, I don't like this ether :/
> > 
> > Problem with this one is that it always adds the RCU fiddling overhead,
> > even when we're not tracing.
> > 
> > I could do an rdmsr_notrace() for this one, dunno if its important.
> 
> But that would neglect the point of tracing rdmsr. What about:
> 
> 	/* tracepoints require RCU enabled */
> 	if (trace_read_msr_enabled())
> 		RCU_NONIDLE(rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi));
> 	else
> 		rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi);

Yeah, but this one does a printk() when it hits the contidion it checks
for, so not tracing it would be fine I think.

Also, Boris, why do we need to redo that rdmsr until we see that bit
set? Can't we simply do the rdmsr once and then be done with it?

[toc] | [prev] | [next] | [standalone]

#1526807

FromBorislav Petkov <bp@alien8.de>
Date2016-11-21 16:40 +0100
Message-ID<sFYRk-2Wx-37@gated-at.bofh.it>
In reply to#1526726
On Mon, Nov 21, 2016 at 03:37:16PM +0100, Peter Zijlstra wrote:
> Yeah, but this one does a printk() when it hits the contidion it checks
> for, so not tracing it would be fine I think.

FWIW, there's already:

static inline void notrace
native_write_msr(unsigned int msr, u32 low, u32 high)
{
        __native_write_msr_notrace(msr, low, high);
        if (msr_tracepoint_active(__tracepoint_write_msr))
                do_trace_write_msr(msr, ((u64)high << 32 | low), 0);
}

so could be mirrored.

> Also, Boris, why do we need to redo that rdmsr until we see that bit
> set? Can't we simply do the rdmsr once and then be done with it?

Hmm, so the way I read the definition of those bits -
K8_INTP_C1E_ACTIVE_MASK - it looks like they get set when the cores
enter halt:

28 C1eOnCmpHalt: C1E on chip multi-processing halt. Read-write.

1=When all cores of a processor have entered the halt state, the processor
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
generates an IO cycle as specified by IORd, IOMsgData, and IOMsgAddr.
When this bit is set, SmiOnCmpHalt and IntPndMsg must be 0, otherwise
the behavior is undefined. For revision DA-C, this bit is only supported
for dual-core processors. For revision C3 and E, this bit is supported
for any number of cores. See 2.4.3.3.3 [Hardware Initiated C1E].

27 SmiOnCmpHalt: SMI on chip multi-processing halt. Read-write.

1=When all cores of the processor have entered the halt state, the
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

processor generates an SMI-trigger IO cycle as specified by IORd,
IOMsgData, and IOMsgAddr. When this bit is set C1eOnCmpHalt and
IntPndMsg must be 0, otherwise the behavior is undefined. The status is
stored in SMMFEC4[SmiOnCmpHaltSts]. See 2.4.3.3.1 [SMI Initiated C1E].

But the thing is, we do it only once until amd_e400_c1e_detected is true.

FWIW, I'd love it if we could do

	if (cpu_has_bug(c, X86_BUG_AMD_APIC_C1E))

but I'm afraid we need to look at that MSR at least once until we set
the boolean.

I could ask if that is really the case and whether we can detect it
differently...

In any case, I have a box here in case you want me to test patches.

-- 
Regards/Gruss,
    Boris.

Good mailing practices for 400: avoid top-posting and trim the reply.

[toc] | [prev] | [next] | [standalone]

#1526820

FromPeter Zijlstra <peterz@infradead.org>
Date2016-11-21 16:50 +0100
Message-ID<sFZ10-2ZM-35@gated-at.bofh.it>
In reply to#1526807
On Mon, Nov 21, 2016 at 04:35:38PM +0100, Borislav Petkov wrote:
> On Mon, Nov 21, 2016 at 03:37:16PM +0100, Peter Zijlstra wrote:
> > Yeah, but this one does a printk() when it hits the contidion it checks
> > for, so not tracing it would be fine I think.
> 
> FWIW, there's already:
> 
> static inline void notrace
> native_write_msr(unsigned int msr, u32 low, u32 high)
> {
>         __native_write_msr_notrace(msr, low, high);
>         if (msr_tracepoint_active(__tracepoint_write_msr))
>                 do_trace_write_msr(msr, ((u64)high << 32 | low), 0);
> }
> 
> so could be mirrored.

Yeah, I know. I caused that to appear ;-)

> > Also, Boris, why do we need to redo that rdmsr until we see that bit
> > set? Can't we simply do the rdmsr once and then be done with it?
> 
> Hmm, so the way I read the definition of those bits -
> K8_INTP_C1E_ACTIVE_MASK - it looks like they get set when the cores
> enter halt:
> 
> 28 C1eOnCmpHalt: C1E on chip multi-processing halt. Read-write.
> 
> 1=When all cores of a processor have entered the halt state, the processor
> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
> generates an IO cycle as specified by IORd, IOMsgData, and IOMsgAddr.
> When this bit is set, SmiOnCmpHalt and IntPndMsg must be 0, otherwise
> the behavior is undefined. For revision DA-C, this bit is only supported
> for dual-core processors. For revision C3 and E, this bit is supported
> for any number of cores. See 2.4.3.3.3 [Hardware Initiated C1E].
> 
> 27 SmiOnCmpHalt: SMI on chip multi-processing halt. Read-write.
> 
> 1=When all cores of the processor have entered the halt state, the
> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
> 
> processor generates an SMI-trigger IO cycle as specified by IORd,
> IOMsgData, and IOMsgAddr. When this bit is set C1eOnCmpHalt and
> IntPndMsg must be 0, otherwise the behavior is undefined. The status is
> stored in SMMFEC4[SmiOnCmpHaltSts]. See 2.4.3.3.1 [SMI Initiated C1E].
> 
> But the thing is, we do it only once until amd_e400_c1e_detected is true.
> 
> FWIW, I'd love it if we could do
> 
> 	if (cpu_has_bug(c, X86_BUG_AMD_APIC_C1E))
> 
> but I'm afraid we need to look at that MSR at least once until we set
> the boolean.
> 
> I could ask if that is really the case and whether we can detect it
> differently...
> 
> In any case, I have a box here in case you want me to test patches.

Right, I just wondered about the !c1e present case. In that case we'll
forever read the msr in the hope of finding that bit set, and we never
will.

Don't care too much, just idle curiousity. Let me do the rdmsr_notrace()
thing.

[toc] | [prev] | [next] | [standalone]

#1526851

FromBorislav Petkov <bp@alien8.de>
Date2016-11-21 17:10 +0100
Message-ID<sFZkq-3oh-15@gated-at.bofh.it>
In reply to#1526820
+ tglx.

On Mon, Nov 21, 2016 at 04:41:04PM +0100, Peter Zijlstra wrote:
> Right, I just wondered about the !c1e present case. In that case we'll
> forever read the msr in the hope of finding that bit set, and we never
> will.

Well, erratum 400 flag is set on everything F10h from model 0x2 onwards,
which is basically everything that's still out there. And we set it for
most of the K8s too. So I don't think there's an affected machine out
there where we don't enable that erratum for so I'd assume it is turned
on everywhere.

IOW, what's the worst thing that can happen if we did this below?

We basically get rid of the detection and switch the timer to broadcast
mode immediately on the halting CPU.

amd_e400_idle() is behind an "if (cpu_has_bug(c, X86_BUG_AMD_APIC_C1E))"
check so it will run on the affected CPUs only...

Thoughts?

---
diff --git a/arch/x86/kernel/process.c b/arch/x86/kernel/process.c
index 0888a879120f..7ab9d0254b4d 100644
--- a/arch/x86/kernel/process.c
+++ b/arch/x86/kernel/process.c
@@ -354,41 +354,30 @@ void amd_e400_remove_cpu(int cpu)
  */
 static void amd_e400_idle(void)
 {
-	if (!amd_e400_c1e_detected) {
-		u32 lo, hi;
+	int cpu = smp_processor_id();
 
-		rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi);
+	if (!static_cpu_has(X86_FEATURE_NONSTOP_TSC))
+		mark_tsc_unstable("TSC halt in AMD C1E");
 
-		if (lo & K8_INTP_C1E_ACTIVE_MASK) {
-			amd_e400_c1e_detected = true;
-			if (!boot_cpu_has(X86_FEATURE_NONSTOP_TSC))
-				mark_tsc_unstable("TSC halt in AMD C1E");
-			pr_info("System has AMD C1E enabled\n");
-		}
-	}
-
-	if (amd_e400_c1e_detected) {
-		int cpu = smp_processor_id();
+	pr_info("System has AMD C1E enabled\n");
 
-		if (!cpumask_test_cpu(cpu, amd_e400_c1e_mask)) {
-			cpumask_set_cpu(cpu, amd_e400_c1e_mask);
-			/* Force broadcast so ACPI can not interfere. */
-			tick_broadcast_force();
-			pr_info("Switch to broadcast mode on CPU%d\n", cpu);
-		}
-		tick_broadcast_enter();
+	if (!cpumask_test_cpu(cpu, amd_e400_c1e_mask)) {
+		cpumask_set_cpu(cpu, amd_e400_c1e_mask);
+		/* Force broadcast so ACPI can not interfere. */
+		tick_broadcast_force();
+		pr_info("Switch to broadcast mode on CPU%d\n", cpu);
+	}
+	tick_broadcast_enter();
 
-		default_idle();
+	default_idle();
 
-		/*
-		 * The switch back from broadcast mode needs to be
-		 * called with interrupts disabled.
-		 */
-		local_irq_disable();
-		tick_broadcast_exit();
-		local_irq_enable();
-	} else
-		default_idle();
+	/*
+	 * The switch back from broadcast mode needs to be
+	 * called with interrupts disabled.
+	 */
+	local_irq_disable();
+	tick_broadcast_exit();
+	local_irq_enable();
 }
 
 /*

-- 
Regards/Gruss,
    Boris.

Good mailing practices for 400: avoid top-posting and trim the reply.

[toc] | [prev] | [next] | [standalone]

#1526720

FromSteven Rostedt <rostedt@goodmis.org>
Date2016-11-21 15:30 +0100
Message-ID<sFXLA-2km-29@gated-at.bofh.it>
In reply to#1526650
On Mon, 21 Nov 2016 13:58:30 +0100
Peter Zijlstra <peterz@infradead.org> wrote:

> On Mon, Nov 21, 2016 at 10:34:25AM +0100, Jiri Olsa wrote:
> 
> > > diff --git a/arch/x86/kernel/process.c b/arch/x86/kernel/process.c
> > > index 0888a879120f..d6c6aa80675f 100644
> > > --- a/arch/x86/kernel/process.c
> > > +++ b/arch/x86/kernel/process.c
> > > @@ -357,7 +357,7 @@ static void amd_e400_idle(void)
> > >  	if (!amd_e400_c1e_detected) {
> > >  		u32 lo, hi;
> > >  
> > > -		rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi);
> > > +		RCU_NONIDLE(rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi));
> > >  
> > >  		if (lo & K8_INTP_C1E_ACTIVE_MASK) {
> > >  			amd_e400_c1e_detected = true;  
> 
> OK, so while looking at this again, I don't like this ether :/
> 
> Problem with this one is that it always adds the RCU fiddling overhead,
> even when we're not tracing.
> 
> I could do an rdmsr_notrace() for this one, dunno if its important.

But that would neglect the point of tracing rdmsr. What about:

	/* tracepoints require RCU enabled */
	if (trace_read_msr_enabled())
		RCU_NONIDLE(rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi));
	else
		rdmsr(MSR_K8_INT_PENDING_MSG, lo, hi);

-- Steve

[toc] | [prev] | [next] | [standalone]

#1526923

FromAndi Kleen <andi@firstfloor.org>
Date2016-11-21 18:10 +0100
Message-ID<sG0gp-41g-7@gated-at.bofh.it>
In reply to#1526478
> > it got away with attached change.. but this rcu logic
> > is far beyond me, so it's just wild guess.. ;-)
> 
> I think I prefer something like the below, that only annotates the one
> RDMSR in question, instead of all of them.

It would be far better to just fix trace points that they always work.

This whole thing is a travesty: we have tens of thousands of lines of code in
ftrace to support tracing in NMIs, but then "debug features"[1] like
this come around and make trace points unusable for far more code than
just the NMI handlers.

-Andi

[1] unclear what they  actually "debug" here.

[toc] | [prev] | [next] | [standalone]

#1526935

FromPeter Zijlstra <peterz@infradead.org>
Date2016-11-21 18:20 +0100
Message-ID<sG0q5-44i-19@gated-at.bofh.it>
In reply to#1526923
On Mon, Nov 21, 2016 at 09:06:13AM -0800, Andi Kleen wrote:
> > > it got away with attached change.. but this rcu logic
> > > is far beyond me, so it's just wild guess.. ;-)
> > 
> > I think I prefer something like the below, that only annotates the one
> > RDMSR in question, instead of all of them.
> 
> It would be far better to just fix trace points that they always work.
> 
> This whole thing is a travesty: we have tens of thousands of lines of code in
> ftrace to support tracing in NMIs, but then "debug features"[1] like
> this come around and make trace points unusable for far more code than
> just the NMI handlers.

Not sure the idle handlers are more code than we have NMI code, but yes,
its annoying.

Its not ftrace as such though, its RCU, ftrace simply uses RCU to avoid
locking, as one does.

Biggest objection would be that the rcu_irq_enter_irqson() thing does
POPF and rcu_irq_exit_irqson() does again. So wrapping every tracepoint
with that is quite a few cycles.

[toc] | [prev] | [next] | [standalone]

#1526951

FromAndi Kleen <andi@firstfloor.org>
Date2016-11-21 18:50 +0100
Message-ID<sG0T7-4em-21@gated-at.bofh.it>
In reply to#1526935
On Mon, Nov 21, 2016 at 06:18:53PM +0100, Peter Zijlstra wrote:
> On Mon, Nov 21, 2016 at 09:06:13AM -0800, Andi Kleen wrote:
> > > > it got away with attached change.. but this rcu logic
> > > > is far beyond me, so it's just wild guess.. ;-)
> > > 
> > > I think I prefer something like the below, that only annotates the one
> > > RDMSR in question, instead of all of them.
> > 
> > It would be far better to just fix trace points that they always work.
> > 
> > This whole thing is a travesty: we have tens of thousands of lines of code in
> > ftrace to support tracing in NMIs, but then "debug features"[1] like
> > this come around and make trace points unusable for far more code than
> > just the NMI handlers.
> 
> Not sure the idle handlers are more code than we have NMI code, but yes,
> its annoying.
> 
> Its not ftrace as such though, its RCU, ftrace simply uses RCU to avoid
> locking, as one does.
> 
> Biggest objection would be that the rcu_irq_enter_irqson() thing does
> POPF and rcu_irq_exit_irqson() does again. So wrapping every tracepoint
> with that is quite a few cycles.

This is only when the trace point is enabled right?

ftrace is already executing a lot of instructions when enabled. Adding two POPF
won't be end of the world.

-Andi


264171.903577780:  ffffffff810d6040 trace_event_raw_event_sched_switch	push %rbp
264171.903577780:  ffffffff810d6041 trace_event_raw_event_sched_switch	mov %rsp, %rbp
264171.903577780:  ffffffff810d6044 trace_event_raw_event_sched_switch	push %r15
264171.903577780:  ffffffff810d6046 trace_event_raw_event_sched_switch	push %r14
264171.903577780:  ffffffff810d6048 trace_event_raw_event_sched_switch	push %r13
264171.903577780:  ffffffff810d604a trace_event_raw_event_sched_switch	push %r12
264171.903577780:  ffffffff810d604c trace_event_raw_event_sched_switch	mov %esi, %r13d
264171.903577780:  ffffffff810d604f trace_event_raw_event_sched_switch	push %rbx
264171.903577780:  ffffffff810d6050 trace_event_raw_event_sched_switch	mov %rdi, %r12
264171.903577780:  ffffffff810d6053 trace_event_raw_event_sched_switch	mov %rdx, %r14
264171.903577780:  ffffffff810d6056 trace_event_raw_event_sched_switch	mov %rcx, %r15
264171.903577780:  ffffffff810d6059 trace_event_raw_event_sched_switch	sub $0x30, %rsp
264171.903577780:  ffffffff810d605d trace_event_raw_event_sched_switch	mov 0x48(%rdi), %rbx
264171.903577780:  ffffffff810d6061 trace_event_raw_event_sched_switch	test $0x80, %bl
264171.903577780:  ffffffff810d6064 trace_event_raw_event_sched_switch	jnz 0x810d608c
264171.903577780:  ffffffff810d6066 trace_event_raw_event_sched_switch	test $0x40, %bl
264171.903577780:  ffffffff810d6069 trace_event_raw_event_sched_switch	jnz trace_event_raw_event_sched_switch+216
264171.903577780:  ffffffff810d606f trace_event_raw_event_sched_switch	test $0x20, %bl
264171.903577780:  ffffffff810d6072 trace_event_raw_event_sched_switch	jz 0x810d6083
264171.903577780:  ffffffff810d6083 trace_event_raw_event_sched_switch	and $0x1, %bh
264171.903577780:  ffffffff810d6086 trace_event_raw_event_sched_switch	jnz trace_event_raw_event_sched_switch+237
264171.903578113:  ffffffff810d608c trace_event_raw_event_sched_switch	mov $0x40, %edx
264171.903578113:  ffffffff810d6091 trace_event_raw_event_sched_switch	mov %r12, %rsi
264171.903578113:  ffffffff810d6094 trace_event_raw_event_sched_switch	mov %rsp, %rdi
264171.903578113:  ffffffff810d6097 trace_event_raw_event_sched_switch	call trace_event_buffer_reserve
264171.903578113:  ffffffff8114f150 trace_event_buffer_reserve	test $0x1, 0x49(%rsi)
264171.903578113:  ffffffff8114f154 trace_event_buffer_reserve	push %rbp
264171.903578113:  ffffffff8114f155 trace_event_buffer_reserve	mov 0x10(%rsi), %r10
264171.903578113:  ffffffff8114f159 trace_event_buffer_reserve	mov %rsp, %rbp
264171.903578113:  ffffffff8114f15c trace_event_buffer_reserve	push %rbx
264171.903578113:  ffffffff8114f15d trace_event_buffer_reserve	jz 0x8114f17e
264171.903578113:  ffffffff8114f17e trace_event_buffer_reserve	mov %rdx, %rcx
264171.903578113:  ffffffff8114f181 trace_event_buffer_reserve	mov %rdi, %rbx
264171.903578113:  ffffffff8114f184 trace_event_buffer_reserve	pushfq 
264171.903578113:  ffffffff8114f185 trace_event_buffer_reserve	pop %r8
264171.903578113:  ffffffff8114f187 trace_event_buffer_reserve	mov %gs:0x7eebd2c1(%rip), %r9d
264171.903578113:  ffffffff8114f18f trace_event_buffer_reserve	and $0x7fffffff, %r9d
264171.903578113:  ffffffff8114f196 trace_event_buffer_reserve	mov %r8, 0x20(%rdi)
264171.903578113:  ffffffff8114f19a trace_event_buffer_reserve	mov %rsi, 0x10(%rdi)
264171.903578113:  ffffffff8114f19e trace_event_buffer_reserve	mov %r9d, 0x28(%rdi)
264171.903578113:  ffffffff8114f1a2 trace_event_buffer_reserve	mov 0x40(%r10), %edx
264171.903578113:  ffffffff8114f1a6 trace_event_buffer_reserve	call trace_event_buffer_lock_reserve
264171.903578113:  ffffffff81142210 trace_event_buffer_lock_reserve	push %rbp
264171.903578113:  ffffffff81142211 trace_event_buffer_lock_reserve	mov %rsp, %rbp
264171.903578113:  ffffffff81142214 trace_event_buffer_lock_reserve	push %r15
264171.903578113:  ffffffff81142216 trace_event_buffer_lock_reserve	push %r14
264171.903578113:  ffffffff81142218 trace_event_buffer_lock_reserve	push %r13
264171.903578113:  ffffffff8114221a trace_event_buffer_lock_reserve	push %r12
264171.903578113:  ffffffff8114221c trace_event_buffer_lock_reserve	mov %rdi, %r14
264171.903578113:  ffffffff8114221f trace_event_buffer_lock_reserve	push %rbx
264171.903578113:  ffffffff81142220 trace_event_buffer_lock_reserve	mov %edx, %r12d
264171.903578113:  ffffffff81142223 trace_event_buffer_lock_reserve	mov %rsi, %rbx
264171.903578113:  ffffffff81142226 trace_event_buffer_lock_reserve	mov %rcx, %r13
264171.903578113:  ffffffff81142229 trace_event_buffer_lock_reserve	mov %r9d, %r15d
264171.903578113:  ffffffff8114222c trace_event_buffer_lock_reserve	sub $0x10, %rsp
264171.903578113:  ffffffff81142230 trace_event_buffer_lock_reserve	mov 0x28(%rsi), %rax
264171.903578113:  ffffffff81142234 trace_event_buffer_lock_reserve	mov %r8, -0x30(%rbp)
264171.903578113:  ffffffff81142238 trace_event_buffer_lock_reserve	mov 0x20(%rax), %rdi
264171.903578113:  ffffffff8114223c trace_event_buffer_lock_reserve	mov %rdi, (%r14)
264171.903578113:  ffffffff8114223f trace_event_buffer_lock_reserve	test $0x24, 0x48(%rsi)
264171.903578113:  ffffffff81142243 trace_event_buffer_lock_reserve	jz 0x8114226d
264171.903578113:  ffffffff8114226d trace_event_buffer_lock_reserve	mov -0x30(%rbp), %rcx
264171.903578113:  ffffffff81142271 trace_event_buffer_lock_reserve	mov %r15d, %r8d
264171.903578113:  ffffffff81142274 trace_event_buffer_lock_reserve	mov %r13, %rdx
264171.903578113:  ffffffff81142277 trace_event_buffer_lock_reserve	mov %r12d, %esi
264171.903578113:  ffffffff8114227a trace_event_buffer_lock_reserve	call trace_buffer_lock_reserve
264171.903578113:  ffffffff811421c0 trace_buffer_lock_reserve	push %rbp
264171.903578113:  ffffffff811421c1 trace_buffer_lock_reserve	mov %rsp, %rbp
264171.903578113:  ffffffff811421c4 trace_buffer_lock_reserve	push %r14
264171.903578113:  ffffffff811421c6 trace_buffer_lock_reserve	push %r13
264171.903578113:  ffffffff811421c8 trace_buffer_lock_reserve	push %r12
264171.903578113:  ffffffff811421ca trace_buffer_lock_reserve	push %rbx
264171.903578113:  ffffffff811421cb trace_buffer_lock_reserve	mov %esi, %r12d
264171.903578113:  ffffffff811421ce trace_buffer_lock_reserve	mov %rdx, %rsi
264171.903578113:  ffffffff811421d1 trace_buffer_lock_reserve	mov %rcx, %r13
264171.903578113:  ffffffff811421d4 trace_buffer_lock_reserve	mov %r8d, %r14d
264171.903578113:  ffffffff811421d7 trace_buffer_lock_reserve	call ring_buffer_lock_reserve
264171.903578113:  ffffffff8113d950 ring_buffer_lock_reserve	mov 0x8(%rdi), %eax
264171.903578113:  ffffffff8113d953 ring_buffer_lock_reserve	test %eax, %eax
264171.903578113:  ffffffff8113d955 ring_buffer_lock_reserve	jnz ring_buffer_lock_reserve+166
264171.903578113:  ffffffff8113d95b ring_buffer_lock_reserve	mov %gs:0x7eecc826(%rip), %eax
264171.903578113:  ffffffff8113d962 ring_buffer_lock_reserve	mov %eax, %ecx
264171.903578113:  ffffffff8113d964 ring_buffer_lock_reserve	bt %rcx, 0x10(%rdi)
264171.903578113:  ffffffff8113d969 ring_buffer_lock_reserve	setb %cl
264171.903578113:  ffffffff8113d96c ring_buffer_lock_reserve	test %cl, %cl
264171.903578113:  ffffffff8113d96e ring_buffer_lock_reserve	jz ring_buffer_lock_reserve+166
264171.903578113:  ffffffff8113d974 ring_buffer_lock_reserve	mov 0x60(%rdi), %rdx
264171.903578113:  ffffffff8113d978 ring_buffer_lock_reserve	push %rbp
264171.903578113:  ffffffff8113d979 ring_buffer_lock_reserve	cdqe 
264171.903578113:  ffffffff8113d97b ring_buffer_lock_reserve	mov %rsp, %rbp
264171.903578113:  ffffffff8113d97e ring_buffer_lock_reserve	push %rbx
264171.903578113:  ffffffff8113d97f ring_buffer_lock_reserve	mov (%rdx,%rax,8), %rbx
264171.903578113:  ffffffff8113d983 ring_buffer_lock_reserve	mov 0x4(%rbx), %eax
264171.903578113:  ffffffff8113d986 ring_buffer_lock_reserve	test %eax, %eax
264171.903578113:  ffffffff8113d988 ring_buffer_lock_reserve	jnz 0x8113d9f1
264171.903578113:  ffffffff8113d98a ring_buffer_lock_reserve	cmp $0xfe8, %rsi
264171.903578113:  ffffffff8113d991 ring_buffer_lock_reserve	ja 0x8113d9f1
264171.903578113:  ffffffff8113d993 ring_buffer_lock_reserve	mov %gs:0x7eeceab6(%rip), %edx
264171.903578113:  ffffffff8113d99a ring_buffer_lock_reserve	test $0x1fff00, %edx
264171.903578113:  ffffffff8113d9a0 ring_buffer_lock_reserve	mov 0x20(%rbx), %ecx
264171.903578113:  ffffffff8113d9a3 ring_buffer_lock_reserve	mov $0x8, %eax
264171.903578113:  ffffffff8113d9a8 ring_buffer_lock_reserve	jnz 0x8113d9c6
264171.903578113:  ffffffff8113d9aa ring_buffer_lock_reserve	test %eax, %ecx
264171.903578113:  ffffffff8113d9ac ring_buffer_lock_reserve	jnz 0x8113d9f1
264171.903578113:  ffffffff8113d9ae ring_buffer_lock_reserve	or %ecx, %eax
264171.903578113:  ffffffff8113d9b0 ring_buffer_lock_reserve	mov %rsi, %rdx
264171.903578113:  ffffffff8113d9b3 ring_buffer_lock_reserve	mov %rbx, %rsi
264171.903578113:  ffffffff8113d9b6 ring_buffer_lock_reserve	mov %eax, 0x20(%rbx)
264171.903578113:  ffffffff8113d9b9 ring_buffer_lock_reserve	call rb_reserve_next_event
264171.903578113:  ffffffff8113d610 rb_reserve_next_event	inc 0x88(%rsi)
264171.903578113:  ffffffff8113d617 rb_reserve_next_event	inc 0x90(%rsi)
264171.903578113:  ffffffff8113d61e rb_reserve_next_event	mov 0x8(%rsi), %rax
264171.903578113:  ffffffff8113d622 rb_reserve_next_event	cmp %rdi, %rax
264171.903578113:  ffffffff8113d625 rb_reserve_next_event	jnz rb_reserve_next_event+678
264171.903578113:  ffffffff8113d62b rb_reserve_next_event	push %rbp
264171.903578113:  ffffffff8113d62c rb_reserve_next_event	mov %edx, %eax
264171.903578113:  ffffffff8113d62e rb_reserve_next_event	mov $0x8, %ecx
264171.903578113:  ffffffff8113d633 rb_reserve_next_event	mov %rsp, %rbp
264171.903578113:  ffffffff8113d636 rb_reserve_next_event	push %r15
264171.903578113:  ffffffff8113d638 rb_reserve_next_event	push %r14
264171.903578113:  ffffffff8113d63a rb_reserve_next_event	push %r13
264171.903578113:  ffffffff8113d63c rb_reserve_next_event	push %r12
264171.903578113:  ffffffff8113d63e rb_reserve_next_event	push %rbx
264171.903578113:  ffffffff8113d63f rb_reserve_next_event	lea 0x88(%rsi), %rbx
264171.903578113:  ffffffff8113d646 rb_reserve_next_event	sub $0x50, %rsp
264171.903578113:  ffffffff8113d64a rb_reserve_next_event	test %edx, %edx
264171.903578113:  ffffffff8113d64c rb_reserve_next_event	jnz rb_reserve_next_event+430
264171.903578113:  ffffffff8113d7be rb_reserve_next_event	cmp $0x70, %edx
264171.903578113:  ffffffff8113d7c1 rb_reserve_next_event	jbe 0x8113d7c6
264171.903578113:  ffffffff8113d7c6 rb_reserve_next_event	add $0x7, %eax
264171.903578113:  ffffffff8113d7c9 rb_reserve_next_event	mov $0x10, %ecx
264171.903578113:  ffffffff8113d7ce rb_reserve_next_event	and $0xfffffffc, %eax
264171.903578113:  ffffffff8113d7d1 rb_reserve_next_event	mov %eax, %edx
264171.903578113:  ffffffff8113d7d3 rb_reserve_next_event	cmp $0xc, %eax
264171.903578113:  ffffffff8113d7d6 rb_reserve_next_event	cmovnz %rdx, %rcx
264171.903578113:  ffffffff8113d7da rb_reserve_next_event	jmp rb_reserve_next_event+66
264171.903578113:  ffffffff8113d652 rb_reserve_next_event	lea -0x50(%rbp), %rax
264171.903578113:  ffffffff8113d656 rb_reserve_next_event	lea 0xa8(%rsi), %r12
264171.903578113:  ffffffff8113d65d rb_reserve_next_event	mov %rsi, %r13
264171.903578113:  ffffffff8113d660 rb_reserve_next_event	mov %rcx, -0x40(%rbp)
264171.903578113:  ffffffff8113d664 rb_reserve_next_event	mov $0x0, -0x30(%rbp)
264171.903578113:  ffffffff8113d66b rb_reserve_next_event	lea 0x18(%rax), %r15
264171.903578113:  ffffffff8113d66f rb_reserve_next_event	lea 0x10(%rax), %r14
264171.903578113:  ffffffff8113d673 rb_reserve_next_event	mov $0x0, -0x48(%rbp)
264171.903578113:  ffffffff8113d67b rb_reserve_next_event	mov $0x3e8, -0x74(%rbp)
264171.903578113:  ffffffff8113d682 rb_reserve_next_event	mov 0x8(%r13), %rax
264171.903578113:  ffffffff8113d686 rb_reserve_next_event	call 0x80(%rax)
264171.903578113:  ffffffff81134520 trace_clock_local	push %rbp
264171.903578113:  ffffffff81134521 trace_clock_local	mov %rsp, %rbp
264171.903578113:  ffffffff81134524 trace_clock_local	call native_sched_clock
264171.903578113:  ffffffff81078270 native_sched_clock	push %rbp
264171.903578113:  ffffffff81078271 native_sched_clock	mov %rsp, %rbp
264171.903578113:  ffffffff81078274 native_sched_clock	and $0xfffffffffffffff0, %rsp
264171.903578113:  ffffffff81078278 native_sched_clock	nop (%rax,%rax)
264171.903578113:  ffffffff8107827d native_sched_clock	rdtsc 
264171.903578113:  ffffffff8107827f native_sched_clock	shl $0x20, %rdx
264171.903578113:  ffffffff81078283 native_sched_clock	or %rdx, %rax
264171.903578113:  ffffffff81078286 native_sched_clock	mov %gs:0x7ef9cea2(%rip), %rsi
264171.903578113:  ffffffff8107828e native_sched_clock	mov %gs:0x7ef9cea2(%rip), %rdx
264171.903578113:  ffffffff81078296 native_sched_clock	cmp %rdx, %rsi
264171.903578113:  ffffffff81078299 native_sched_clock	jnz 0x810782d1
264171.903578113:  ffffffff8107829b native_sched_clock	mov (%rsi), %edx
264171.903578113:  ffffffff8107829d native_sched_clock	mov 0x4(%rsi), %ecx
264171.903578113:  ffffffff810782a0 native_sched_clock	mul %rdx
264171.903578113:  ffffffff810782a3 native_sched_clock	shrd %cl, %rdx, %rax
264171.903578113:  ffffffff810782a7 native_sched_clock	shr %cl, %rdx
264171.903578113:  ffffffff810782aa native_sched_clock	test $0x40, %cl
264171.903578113:  ffffffff810782ad native_sched_clock	cmovnz %rdx, %rax
264171.903578113:  ffffffff810782b1 native_sched_clock	add 0x8(%rsi), %rax
264171.903578113:  ffffffff810782b5 native_sched_clock	leave 
264171.903578113:  ffffffff810782b6 native_sched_clock	ret 
264171.903578113:  ffffffff81134529 trace_clock_local	pop %rbp
264171.903578113:  ffffffff8113452a trace_clock_local	ret 
264171.903578113:  ffffffff8113d68c rb_reserve_next_event	mov %rax, -0x50(%rbp)
264171.903578113:  ffffffff8113d690 rb_reserve_next_event	sub 0xa8(%r13), %rax
264171.903578113:  ffffffff8113d697 rb_reserve_next_event	mov 0xa8(%r13), %rcx
264171.903578113:  ffffffff8113d69e rb_reserve_next_event	cmp %rcx, -0x50(%rbp)
264171.903578113:  ffffffff8113d6a2 rb_reserve_next_event	jb 0x8113d6b4
264171.903578113:  ffffffff8113d6a4 rb_reserve_next_event	test $0xfffffffff8000000, %rax
264171.903578113:  ffffffff8113d6aa rb_reserve_next_event	mov %rax, -0x48(%rbp)
264171.903578113:  ffffffff8113d6ae rb_reserve_next_event	jnz rb_reserve_next_event+476
264171.903578113:  ffffffff8113d6b4 rb_reserve_next_event	mov -0x30(%rbp), %esi
264171.903578113:  ffffffff8113d6b7 rb_reserve_next_event	test %esi, %esi
264171.903578113:  ffffffff8113d6b9 rb_reserve_next_event	jnz rb_reserve_next_event+718

[toc] | [prev] | [next] | [standalone]

Page 1 of 2  [1] 2  Next page →

Back to top | Article view | linux.kernel

csiph-web