Re: [patch V2 24/24] cpu/hotplug: Convert hotplug locking to percpu rwsem

[Michael Ellerman]

Thomas Gleixner  writes:

> On Wed, 10 May 2017, Michael Ellerman wrote:
>
>> Thomas Gleixner  writes:
>> 
>> > @@ -130,6 +130,7 @@ void __static_key_slow_inc(struct static
>> > * the all CPUs, for that to be serialized against CPU hot-plug
>> > * we need to avoid CPUs coming online.
>> > */
>> > +  lockdep_assert_hotplug_held();
>> >jump_label_lock();
>> >if (atomic_read(>enabled) == 0) {
>> >atomic_set(>enabled, -1);
>> 
>> I seem to be hitting this assert from the ftrace event selftests,
>> enabled at boot with CONFIG_FTRACE_STARTUP_TEST=y, using next-20170509
>> (on powerpc).
>> 
>> The stupidly obvious (or perhaps obviously stupid) patch below fixes it:
>
> Kinda. There is more horror in that area lurking and I'm still trying to
> figure out all the convoluted call pathes.

OK thanks.

cheers

Re: [patch V2 24/24] cpu/hotplug: Convert hotplug locking to percpu rwsem

[Michael Ellerman]

Thomas Gleixner  writes:

> On Wed, 10 May 2017, Michael Ellerman wrote:
>
>> Thomas Gleixner  writes:
>> 
>> > @@ -130,6 +130,7 @@ void __static_key_slow_inc(struct static
>> > * the all CPUs, for that to be serialized against CPU hot-plug
>> > * we need to avoid CPUs coming online.
>> > */
>> > +  lockdep_assert_hotplug_held();
>> >jump_label_lock();
>> >if (atomic_read(>enabled) == 0) {
>> >atomic_set(>enabled, -1);
>> 
>> I seem to be hitting this assert from the ftrace event selftests,
>> enabled at boot with CONFIG_FTRACE_STARTUP_TEST=y, using next-20170509
>> (on powerpc).
>> 
>> The stupidly obvious (or perhaps obviously stupid) patch below fixes it:
>
> Kinda. There is more horror in that area lurking and I'm still trying to
> figure out all the convoluted call pathes.

OK thanks.

cheers

Re: [patch V2 24/24] cpu/hotplug: Convert hotplug locking to percpu rwsem

[Steven Rostedt]

On Wed, 10 May 2017 12:30:57 -0400
Steven Rostedt  wrote:

 
> I finally got some time to look at this. I'm looking at your commit:
> 
> commit b53e5129c4c7ab47ec4f709fd8f5784ca45fb46d
> Author: Thomas Gleixner 
> Date:   Sun Apr 23 12:17:13 2017 +0200
> 
> trace/perf: Cure hotplug lock ordering issues
> 
> What were the circular locking dependencies that were uncovered.
> 
> event_mutex could possibly be broken up, if that helps. It sorta became
> a catch all for various modifications to tracing.
> 

I checked out the commit before this and started playing with it. I see
some of the issues now. I'll look more into it.

-- Steve

Re: [patch V2 24/24] cpu/hotplug: Convert hotplug locking to percpu rwsem

[Steven Rostedt]

On Wed, 10 May 2017 12:30:57 -0400
Steven Rostedt  wrote:

 
> I finally got some time to look at this. I'm looking at your commit:
> 
> commit b53e5129c4c7ab47ec4f709fd8f5784ca45fb46d
> Author: Thomas Gleixner 
> Date:   Sun Apr 23 12:17:13 2017 +0200
> 
> trace/perf: Cure hotplug lock ordering issues
> 
> What were the circular locking dependencies that were uncovered.
> 
> event_mutex could possibly be broken up, if that helps. It sorta became
> a catch all for various modifications to tracing.
> 

I checked out the commit before this and started playing with it. I see
some of the issues now. I'll look more into it.

-- Steve

Re: [patch V2 24/24] cpu/hotplug: Convert hotplug locking to percpu rwsem

[Steven Rostedt]

On Wed, 10 May 2017 10:49:09 +0200 (CEST)
Thomas Gleixner  wrote:

> On Wed, 10 May 2017, Michael Ellerman wrote:
> 
> > Thomas Gleixner  writes:
> >   
> > > @@ -130,6 +130,7 @@ void __static_key_slow_inc(struct static
> > >* the all CPUs, for that to be serialized against CPU hot-plug
> > >* we need to avoid CPUs coming online.
> > >*/
> > > + lockdep_assert_hotplug_held();
> > >   jump_label_lock();
> > >   if (atomic_read(>enabled) == 0) {
> > >   atomic_set(>enabled, -1);  
> > 
> > I seem to be hitting this assert from the ftrace event selftests,
> > enabled at boot with CONFIG_FTRACE_STARTUP_TEST=y, using next-20170509
> > (on powerpc).
> > 
> > The stupidly obvious (or perhaps obviously stupid) patch below fixes it:  
> 
> Kinda. There is more horror in that area lurking and I'm still trying to
> figure out all the convoluted call pathes.

I finally got some time to look at this. I'm looking at your commit:

commit b53e5129c4c7ab47ec4f709fd8f5784ca45fb46d
Author: Thomas Gleixner 
Date:   Sun Apr 23 12:17:13 2017 +0200

trace/perf: Cure hotplug lock ordering issues

What were the circular locking dependencies that were uncovered.

event_mutex could possibly be broken up, if that helps. It sorta became
a catch all for various modifications to tracing.

-- Steve


> 
> Thanks,
> 
>   tglx
> 
> > diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
> > index daefdee9411a..5531f7ce8fa6 100644
> > --- a/kernel/trace/trace_events.c
> > +++ b/kernel/trace/trace_events.c
> > @@ -3241,9 +3241,19 @@ static __init void event_trace_self_tests(void)
> > continue;
> > }
> >  
> > +   get_online_cpus();
> > +   mutex_lock(_mutex);
> > ftrace_event_enable_disable(file, 1);
> > +   mutex_unlock(_mutex);
> > +   put_online_cpus();
> > +
> > event_test_stuff();
> > +
> > +   get_online_cpus();
> > +   mutex_lock(_mutex);
> > ftrace_event_enable_disable(file, 0);
> > +   mutex_unlock(_mutex);
> > +   put_online_cpus();
> >  
> > pr_cont("OK\n");
> > }
> > 
> > cheers
> >   

Re: [patch V2 24/24] cpu/hotplug: Convert hotplug locking to percpu rwsem

[Steven Rostedt]

On Wed, 10 May 2017 10:49:09 +0200 (CEST)
Thomas Gleixner  wrote:

> On Wed, 10 May 2017, Michael Ellerman wrote:
> 
> > Thomas Gleixner  writes:
> >   
> > > @@ -130,6 +130,7 @@ void __static_key_slow_inc(struct static
> > >* the all CPUs, for that to be serialized against CPU hot-plug
> > >* we need to avoid CPUs coming online.
> > >*/
> > > + lockdep_assert_hotplug_held();
> > >   jump_label_lock();
> > >   if (atomic_read(>enabled) == 0) {
> > >   atomic_set(>enabled, -1);  
> > 
> > I seem to be hitting this assert from the ftrace event selftests,
> > enabled at boot with CONFIG_FTRACE_STARTUP_TEST=y, using next-20170509
> > (on powerpc).
> > 
> > The stupidly obvious (or perhaps obviously stupid) patch below fixes it:  
> 
> Kinda. There is more horror in that area lurking and I'm still trying to
> figure out all the convoluted call pathes.

I finally got some time to look at this. I'm looking at your commit:

commit b53e5129c4c7ab47ec4f709fd8f5784ca45fb46d
Author: Thomas Gleixner 
Date:   Sun Apr 23 12:17:13 2017 +0200

trace/perf: Cure hotplug lock ordering issues

What were the circular locking dependencies that were uncovered.

event_mutex could possibly be broken up, if that helps. It sorta became
a catch all for various modifications to tracing.

-- Steve


> 
> Thanks,
> 
>   tglx
> 
> > diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
> > index daefdee9411a..5531f7ce8fa6 100644
> > --- a/kernel/trace/trace_events.c
> > +++ b/kernel/trace/trace_events.c
> > @@ -3241,9 +3241,19 @@ static __init void event_trace_self_tests(void)
> > continue;
> > }
> >  
> > +   get_online_cpus();
> > +   mutex_lock(_mutex);
> > ftrace_event_enable_disable(file, 1);
> > +   mutex_unlock(_mutex);
> > +   put_online_cpus();
> > +
> > event_test_stuff();
> > +
> > +   get_online_cpus();
> > +   mutex_lock(_mutex);
> > ftrace_event_enable_disable(file, 0);
> > +   mutex_unlock(_mutex);
> > +   put_online_cpus();
> >  
> > pr_cont("OK\n");
> > }
> > 
> > cheers
> >   

Re: [patch V2 24/24] cpu/hotplug: Convert hotplug locking to percpu rwsem

[Thomas Gleixner]

On Wed, 10 May 2017, Michael Ellerman wrote:

> Thomas Gleixner  writes:
> 
> > @@ -130,6 +130,7 @@ void __static_key_slow_inc(struct static
> >  * the all CPUs, for that to be serialized against CPU hot-plug
> >  * we need to avoid CPUs coming online.
> >  */
> > +   lockdep_assert_hotplug_held();
> > jump_label_lock();
> > if (atomic_read(>enabled) == 0) {
> > atomic_set(>enabled, -1);
> 
> I seem to be hitting this assert from the ftrace event selftests,
> enabled at boot with CONFIG_FTRACE_STARTUP_TEST=y, using next-20170509
> (on powerpc).
> 
> The stupidly obvious (or perhaps obviously stupid) patch below fixes it:

Kinda. There is more horror in that area lurking and I'm still trying to
figure out all the convoluted call pathes.

Thanks,

tglx

> diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
> index daefdee9411a..5531f7ce8fa6 100644
> --- a/kernel/trace/trace_events.c
> +++ b/kernel/trace/trace_events.c
> @@ -3241,9 +3241,19 @@ static __init void event_trace_self_tests(void)
>   continue;
>   }
>  
> + get_online_cpus();
> + mutex_lock(_mutex);
>   ftrace_event_enable_disable(file, 1);
> + mutex_unlock(_mutex);
> + put_online_cpus();
> +
>   event_test_stuff();
> +
> + get_online_cpus();
> + mutex_lock(_mutex);
>   ftrace_event_enable_disable(file, 0);
> + mutex_unlock(_mutex);
> + put_online_cpus();
>  
>   pr_cont("OK\n");
>   }
> 
> cheers
> 

Re: [patch V2 24/24] cpu/hotplug: Convert hotplug locking to percpu rwsem

[Thomas Gleixner]

On Wed, 10 May 2017, Michael Ellerman wrote:

> Thomas Gleixner  writes:
> 
> > @@ -130,6 +130,7 @@ void __static_key_slow_inc(struct static
> >  * the all CPUs, for that to be serialized against CPU hot-plug
> >  * we need to avoid CPUs coming online.
> >  */
> > +   lockdep_assert_hotplug_held();
> > jump_label_lock();
> > if (atomic_read(>enabled) == 0) {
> > atomic_set(>enabled, -1);
> 
> I seem to be hitting this assert from the ftrace event selftests,
> enabled at boot with CONFIG_FTRACE_STARTUP_TEST=y, using next-20170509
> (on powerpc).
> 
> The stupidly obvious (or perhaps obviously stupid) patch below fixes it:

Kinda. There is more horror in that area lurking and I'm still trying to
figure out all the convoluted call pathes.

Thanks,

tglx

> diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
> index daefdee9411a..5531f7ce8fa6 100644
> --- a/kernel/trace/trace_events.c
> +++ b/kernel/trace/trace_events.c
> @@ -3241,9 +3241,19 @@ static __init void event_trace_self_tests(void)
>   continue;
>   }
>  
> + get_online_cpus();
> + mutex_lock(_mutex);
>   ftrace_event_enable_disable(file, 1);
> + mutex_unlock(_mutex);
> + put_online_cpus();
> +
>   event_test_stuff();
> +
> + get_online_cpus();
> + mutex_lock(_mutex);
>   ftrace_event_enable_disable(file, 0);
> + mutex_unlock(_mutex);
> + put_online_cpus();
>  
>   pr_cont("OK\n");
>   }
> 
> cheers
> 

Re: [patch V2 24/24] cpu/hotplug: Convert hotplug locking to percpu rwsem

[Michael Ellerman]

Thomas Gleixner  writes:

> @@ -130,6 +130,7 @@ void __static_key_slow_inc(struct static
>* the all CPUs, for that to be serialized against CPU hot-plug
>* we need to avoid CPUs coming online.
>*/
> + lockdep_assert_hotplug_held();
>   jump_label_lock();
>   if (atomic_read(>enabled) == 0) {
>   atomic_set(>enabled, -1);

I seem to be hitting this assert from the ftrace event selftests,
enabled at boot with CONFIG_FTRACE_STARTUP_TEST=y, using next-20170509
(on powerpc).

[  842.691191] Testing event rpc_call_status: 
[  842.691209] [ cut here ]
[  842.691399] WARNING: CPU: 6 PID: 1 at ../kernel/cpu.c:234 
lockdep_assert_hotplug_held+0x5c/0x70
[  842.691575] Modules linked in:
[  842.691675] CPU: 6 PID: 1 Comm: swapper/0 Tainted: GW   
4.11.0-gcc-5.4.1-next-20170509 #218
[  842.691865] task: c001fe78 task.stack: c001fe80
[  842.692003] NIP: c00ff3dc LR: c00ff3d0 CTR: c0218650
[  842.692166] REGS: c001fe8036e0 TRAP: 0700   Tainted: GW
(4.11.0-gcc-5.4.1-next-20170509)
[  842.692343] MSR: 80029033 
[  842.692491]   CR: 2800  XER: 2000
[  842.692689] CFAR: c0171530 SOFTE: 1 
   GPR00: c00ff3d0 c001fe803960 c12b7600 
 
   GPR04:   c000fc10c0e8 
 
   GPR08:    
c000f8180008 
   GPR12: 2200 cfd42100 c000e218 
 
   GPR16:    
 
   GPR20:    
c000f9341610 
   GPR24: c127ee48 c0aa49d0 000a 
c000fc3c 
   GPR28: c117b148 c1264230  
c127ee48 
[  842.694287] NIP [c00ff3dc] lockdep_assert_hotplug_held+0x5c/0x70
[  842.694434] LR [c00ff3d0] lockdep_assert_hotplug_held+0x50/0x70
[  842.694577] Call Trace:
[  842.694658] [c001fe803960] [c00ff3d0] 
lockdep_assert_hotplug_held+0x50/0x70 (unreliable)
[  842.694876] [c001fe803980] [c02a3754] 
__static_key_slow_inc+0x104/0x170
[  842.695054] [c001fe8039f0] [c02176ac] 
tracepoint_probe_register_prio+0x2dc/0x390
[  842.695258] [c001fe803a60] [c024cf50] trace_event_reg+0xe0/0x130
[  842.695434] [c001fe803a80] [c024d5f0] 
__ftrace_event_enable_disable+0x270/0x3e0
[  842.695601] [c001fe803b10] [c0e20328] 
event_trace_self_tests+0x14c/0x350
[  842.695778] [c001fe803bc0] [c0e20774] 
event_trace_self_tests_init+0xc8/0xf4
[  842.695944] [c001fe803c30] [c000d87c] do_one_initcall+0x6c/0x1d0
[  842.696113] [c001fe803cf0] [c0df462c] 
kernel_init_freeable+0x304/0x3e4
[  842.696282] [c001fe803dc0] [c000e23c] kernel_init+0x2c/0x170
[  842.696460] [c001fe803e30] [c000bdec] 
ret_from_kernel_thread+0x5c/0x70
[  842.696662] Instruction dump:
[  842.696763] 409e0014 38210020 e8010010 7c0803a6 4e800020 3c62ffe6 3880 
38634808 
[  842.697009] 480720ed 6000 2fa3 409effd8 <0fe0> 38210020 e8010010 
7c0803a6 
[  842.697271] ---[ end trace f68728a0d30544a1 ]---


The stupidly obvious (or perhaps obviously stupid) patch below fixes it:

diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index daefdee9411a..5531f7ce8fa6 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -3241,9 +3241,19 @@ static __init void event_trace_self_tests(void)
continue;
}
 
+   get_online_cpus();
+   mutex_lock(_mutex);
ftrace_event_enable_disable(file, 1);
+   mutex_unlock(_mutex);
+   put_online_cpus();
+
event_test_stuff();
+
+   get_online_cpus();
+   mutex_lock(_mutex);
ftrace_event_enable_disable(file, 0);
+   mutex_unlock(_mutex);
+   put_online_cpus();
 
pr_cont("OK\n");
}

cheers

Re: [patch V2 24/24] cpu/hotplug: Convert hotplug locking to percpu rwsem

[Michael Ellerman]

Thomas Gleixner  writes:

> @@ -130,6 +130,7 @@ void __static_key_slow_inc(struct static
>* the all CPUs, for that to be serialized against CPU hot-plug
>* we need to avoid CPUs coming online.
>*/
> + lockdep_assert_hotplug_held();
>   jump_label_lock();
>   if (atomic_read(>enabled) == 0) {
>   atomic_set(>enabled, -1);

I seem to be hitting this assert from the ftrace event selftests,
enabled at boot with CONFIG_FTRACE_STARTUP_TEST=y, using next-20170509
(on powerpc).

[  842.691191] Testing event rpc_call_status: 
[  842.691209] [ cut here ]
[  842.691399] WARNING: CPU: 6 PID: 1 at ../kernel/cpu.c:234 
lockdep_assert_hotplug_held+0x5c/0x70
[  842.691575] Modules linked in:
[  842.691675] CPU: 6 PID: 1 Comm: swapper/0 Tainted: GW   
4.11.0-gcc-5.4.1-next-20170509 #218
[  842.691865] task: c001fe78 task.stack: c001fe80
[  842.692003] NIP: c00ff3dc LR: c00ff3d0 CTR: c0218650
[  842.692166] REGS: c001fe8036e0 TRAP: 0700   Tainted: GW
(4.11.0-gcc-5.4.1-next-20170509)
[  842.692343] MSR: 80029033 
[  842.692491]   CR: 2800  XER: 2000
[  842.692689] CFAR: c0171530 SOFTE: 1 
   GPR00: c00ff3d0 c001fe803960 c12b7600 
 
   GPR04:   c000fc10c0e8 
 
   GPR08:    
c000f8180008 
   GPR12: 2200 cfd42100 c000e218 
 
   GPR16:    
 
   GPR20:    
c000f9341610 
   GPR24: c127ee48 c0aa49d0 000a 
c000fc3c 
   GPR28: c117b148 c1264230  
c127ee48 
[  842.694287] NIP [c00ff3dc] lockdep_assert_hotplug_held+0x5c/0x70
[  842.694434] LR [c00ff3d0] lockdep_assert_hotplug_held+0x50/0x70
[  842.694577] Call Trace:
[  842.694658] [c001fe803960] [c00ff3d0] 
lockdep_assert_hotplug_held+0x50/0x70 (unreliable)
[  842.694876] [c001fe803980] [c02a3754] 
__static_key_slow_inc+0x104/0x170
[  842.695054] [c001fe8039f0] [c02176ac] 
tracepoint_probe_register_prio+0x2dc/0x390
[  842.695258] [c001fe803a60] [c024cf50] trace_event_reg+0xe0/0x130
[  842.695434] [c001fe803a80] [c024d5f0] 
__ftrace_event_enable_disable+0x270/0x3e0
[  842.695601] [c001fe803b10] [c0e20328] 
event_trace_self_tests+0x14c/0x350
[  842.695778] [c001fe803bc0] [c0e20774] 
event_trace_self_tests_init+0xc8/0xf4
[  842.695944] [c001fe803c30] [c000d87c] do_one_initcall+0x6c/0x1d0
[  842.696113] [c001fe803cf0] [c0df462c] 
kernel_init_freeable+0x304/0x3e4
[  842.696282] [c001fe803dc0] [c000e23c] kernel_init+0x2c/0x170
[  842.696460] [c001fe803e30] [c000bdec] 
ret_from_kernel_thread+0x5c/0x70
[  842.696662] Instruction dump:
[  842.696763] 409e0014 38210020 e8010010 7c0803a6 4e800020 3c62ffe6 3880 
38634808 
[  842.697009] 480720ed 6000 2fa3 409effd8 <0fe0> 38210020 e8010010 
7c0803a6 
[  842.697271] ---[ end trace f68728a0d30544a1 ]---


The stupidly obvious (or perhaps obviously stupid) patch below fixes it:

diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index daefdee9411a..5531f7ce8fa6 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -3241,9 +3241,19 @@ static __init void event_trace_self_tests(void)
continue;
}
 
+   get_online_cpus();
+   mutex_lock(_mutex);
ftrace_event_enable_disable(file, 1);
+   mutex_unlock(_mutex);
+   put_online_cpus();
+
event_test_stuff();
+
+   get_online_cpus();
+   mutex_lock(_mutex);
ftrace_event_enable_disable(file, 0);
+   mutex_unlock(_mutex);
+   put_online_cpus();
 
pr_cont("OK\n");
}

cheers