sched: spinlock recursion in migrate_swap_stop

sched: spinlock recursion in migrate_swap_stop

[Sasha Levin]

Hi all,

While fuzzing with trinity inside a KVM tools guest running the latest -next
kernel I've stumbled on the following spew:

[ 1738.758667] BUG: spinlock recursion on CPU#23, migration/23/328
[ 1738.761291]  lock: 0xffff8801f93b0c30, .magic: dead4ead, .owner: migration/23/328, .owner_cpu: 23
[ 1738.762733] CPU: 23 PID: 328 Comm: migration/23 Not tainted 3.15.0-rc5-next-20140512-sasha-00019-ga20bc00-dirty #456
[ 1738.764081]  ffff8801f93b0c30 ffff8805505efbc8 ffffffff9453e1ec 0000000000000004
[ 1738.764914]  ffff8805505cb000 ffff8805505efbe8 ffffffff94531095 ffff8801f93b0c30
[ 1738.765120]  ffffffff9583485e ffff8805505efc08 ffffffff945310c0 ffff8801f93b0c30
[ 1738.765120] Call Trace:
[ 1738.768386] dump_stack (lib/dump_stack.c:52)
[ 1738.768386] spin_dump (kernel/locking/spinlock_debug.c:68 (discriminator 6))
[ 1738.768386] spin_bug (kernel/locking/spinlock_debug.c:76)
[ 1738.768386] do_raw_spin_lock (kernel/locking/spinlock_debug.c:84 kernel/locking/spinlock_debug.c:135)
[ 1738.768386] _raw_spin_lock_nested (kernel/locking/spinlock.c:362 (discriminator 2))
[ 1738.768386] ? migrate_swap_stop (arch/x86/include/asm/paravirt.h:804 kernel/sched/sched.h:1406 kernel/sched/core.c:1099)
[ 1738.768386] ? _raw_spin_lock (kernel/locking/spinlock.c:152)
[ 1738.768386] ? migrate_swap_stop (kernel/sched/sched.h:1393 kernel/sched/core.c:1097)
[ 1738.768386] migrate_swap_stop (arch/x86/include/asm/paravirt.h:804 kernel/sched/sched.h:1406 kernel/sched/core.c:1099)
[ 1738.768386] ? queue_stop_cpus_work (include/linux/cpumask.h:108 include/linux/cpumask.h:174 kernel/stop_machine.c:375)
[ 1738.768386] multi_cpu_stop (kernel/stop_machine.c:225)
[ 1738.768386] ? queue_stop_cpus_work (kernel/stop_machine.c:171)
[ 1738.768386] cpu_stopper_thread (kernel/stop_machine.c:498)
[ 1738.768386] ? put_lock_stats.isra.12 (arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254)
[ 1738.768386] ? _raw_spin_unlock_irqrestore (arch/x86/include/asm/paravirt.h:809 include/linux/spinlock_api_smp.h:160 kernel/locking/spinlock.c:191)
[ 1738.768386] ? __this_cpu_preempt_check (lib/smp_processor_id.c:63)
[ 1738.768386] ? trace_hardirqs_on_caller (kernel/locking/lockdep.c:2557 kernel/locking/lockdep.c:2599)
[ 1738.768386] smpboot_thread_fn (kernel/smpboot.c:160)
[ 1738.768386] ? __smpboot_create_thread (kernel/smpboot.c:105)
[ 1738.768386] kthread (kernel/kthread.c:210)
[ 1738.768386] ? complete (kernel/sched/completion.c:35)
[ 1738.768386] ? kthread_create_on_node (kernel/kthread.c:176)
[ 1738.768386] ret_from_fork (arch/x86/kernel/entry_64.S:553)
[ 1738.768386] ? kthread_create_on_node (kernel/kthread.c:176)


Thanks,
Sasha

Re: sched: spinlock recursion in migrate_swap_stop

[Sasha Levin]

ping? It seems to be easy enough to reproduce on -next, I'd be happy to try
debug patches/fixes.


Thanks,
Sasha

On 05/12/2014 02:25 PM, Sasha Levin wrote:
> Hi all,
> 
> While fuzzing with trinity inside a KVM tools guest running the latest -next
> kernel I've stumbled on the following spew:
> 
> [ 1738.758667] BUG: spinlock recursion on CPU#23, migration/23/328
> [ 1738.761291]  lock: 0xffff8801f93b0c30, .magic: dead4ead, .owner: migration/23/328, .owner_cpu: 23
> [ 1738.762733] CPU: 23 PID: 328 Comm: migration/23 Not tainted 3.15.0-rc5-next-20140512-sasha-00019-ga20bc00-dirty #456
> [ 1738.764081]  ffff8801f93b0c30 ffff8805505efbc8 ffffffff9453e1ec 0000000000000004
> [ 1738.764914]  ffff8805505cb000 ffff8805505efbe8 ffffffff94531095 ffff8801f93b0c30
> [ 1738.765120]  ffffffff9583485e ffff8805505efc08 ffffffff945310c0 ffff8801f93b0c30
> [ 1738.765120] Call Trace:
> [ 1738.768386] dump_stack (lib/dump_stack.c:52)
> [ 1738.768386] spin_dump (kernel/locking/spinlock_debug.c:68 (discriminator 6))
> [ 1738.768386] spin_bug (kernel/locking/spinlock_debug.c:76)
> [ 1738.768386] do_raw_spin_lock (kernel/locking/spinlock_debug.c:84 kernel/locking/spinlock_debug.c:135)
> [ 1738.768386] _raw_spin_lock_nested (kernel/locking/spinlock.c:362 (discriminator 2))
> [ 1738.768386] ? migrate_swap_stop (arch/x86/include/asm/paravirt.h:804 kernel/sched/sched.h:1406 kernel/sched/core.c:1099)
> [ 1738.768386] ? _raw_spin_lock (kernel/locking/spinlock.c:152)
> [ 1738.768386] ? migrate_swap_stop (kernel/sched/sched.h:1393 kernel/sched/core.c:1097)
> [ 1738.768386] migrate_swap_stop (arch/x86/include/asm/paravirt.h:804 kernel/sched/sched.h:1406 kernel/sched/core.c:1099)
> [ 1738.768386] ? queue_stop_cpus_work (include/linux/cpumask.h:108 include/linux/cpumask.h:174 kernel/stop_machine.c:375)
> [ 1738.768386] multi_cpu_stop (kernel/stop_machine.c:225)
> [ 1738.768386] ? queue_stop_cpus_work (kernel/stop_machine.c:171)
> [ 1738.768386] cpu_stopper_thread (kernel/stop_machine.c:498)
> [ 1738.768386] ? put_lock_stats.isra.12 (arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254)
> [ 1738.768386] ? _raw_spin_unlock_irqrestore (arch/x86/include/asm/paravirt.h:809 include/linux/spinlock_api_smp.h:160 kernel/locking/spinlock.c:191)
> [ 1738.768386] ? __this_cpu_preempt_check (lib/smp_processor_id.c:63)
> [ 1738.768386] ? trace_hardirqs_on_caller (kernel/locking/lockdep.c:2557 kernel/locking/lockdep.c:2599)
> [ 1738.768386] smpboot_thread_fn (kernel/smpboot.c:160)
> [ 1738.768386] ? __smpboot_create_thread (kernel/smpboot.c:105)
> [ 1738.768386] kthread (kernel/kthread.c:210)
> [ 1738.768386] ? complete (kernel/sched/completion.c:35)
> [ 1738.768386] ? kthread_create_on_node (kernel/kthread.c:176)
> [ 1738.768386] ret_from_fork (arch/x86/kernel/entry_64.S:553)
> [ 1738.768386] ? kthread_create_on_node (kernel/kthread.c:176)
> 
> 
> Thanks,
> Sasha
> 

Re: sched: spinlock recursion in migrate_swap_stop

[Peter Zijlstra]

On Mon, May 19, 2014 at 10:05:31PM -0400, Sasha Levin wrote:
> ping? It seems to be easy enough to reproduce on -next, I'd be happy to try
> debug patches/fixes.

Does this fuzzing you do also include hotplug? If so, does disabling
that make this problem go away?

Re: sched: spinlock recursion in migrate_swap_stop

[Sasha Levin]

On 05/20/2014 07:04 AM, Peter Zijlstra wrote:
> On Mon, May 19, 2014 at 10:05:31PM -0400, Sasha Levin wrote:
>> ping? It seems to be easy enough to reproduce on -next, I'd be happy to try
>> debug patches/fixes.
> 
> Does this fuzzing you do also include hotplug? If so, does disabling
> that make this problem go away?
> 

There were no hotplug operations going on when this happens, so it seems
unrelated.


Thanks,
Sasha

Re: sched: spinlock recursion in migrate_swap_stop

[Sasha Levin]

On 05/20/2014 09:03 AM, Sasha Levin wrote:
> On 05/20/2014 07:04 AM, Peter Zijlstra wrote:
>> > On Mon, May 19, 2014 at 10:05:31PM -0400, Sasha Levin wrote:
>>> >> ping? It seems to be easy enough to reproduce on -next, I'd be happy to try
>>> >> debug patches/fixes.
>> > 
>> > Does this fuzzing you do also include hotplug? If so, does disabling
>> > that make this problem go away?
>> > 
> There were no hotplug operations going on when this happens, so it seems
> unrelated.

I've added a small test:

diff --git a/kernel/sched/core.c b/kernel/sched/core.c
index 927fa33..b5e11c7 100644
--- a/kernel/sched/core.c
+++ b/kernel/sched/core.c
@@ -1154,6 +1156,7 @@ int migrate_swap(struct task_struct *cur, struct task_struct *p)
                goto out;

        trace_sched_swap_numa(cur, arg.src_cpu, p, arg.dst_cpu);
+       BUG_ON(cur == p);
        ret = stop_two_cpus(arg.dst_cpu, arg.src_cpu, migrate_swap_stop, &arg);

 out:


Which seems to get hit. This sounds like a race with task moving to
other cpu maybe?


Thanks,
Sasha

Re: sched: spinlock recursion in migrate_swap_stop

[Peter Zijlstra]

On Wed, May 21, 2014 at 09:08:26AM -0400, Sasha Levin wrote:
> On 05/20/2014 09:03 AM, Sasha Levin wrote:
> > On 05/20/2014 07:04 AM, Peter Zijlstra wrote:
> >> > On Mon, May 19, 2014 at 10:05:31PM -0400, Sasha Levin wrote:
> >>> >> ping? It seems to be easy enough to reproduce on -next, I'd be happy to try
> >>> >> debug patches/fixes.
> >> > 
> >> > Does this fuzzing you do also include hotplug? If so, does disabling
> >> > that make this problem go away?
> >> > 
> > There were no hotplug operations going on when this happens, so it seems
> > unrelated.
> 
> I've added a small test:
> 
> diff --git a/kernel/sched/core.c b/kernel/sched/core.c
> index 927fa33..b5e11c7 100644
> --- a/kernel/sched/core.c
> +++ b/kernel/sched/core.c
> @@ -1154,6 +1156,7 @@ int migrate_swap(struct task_struct *cur, struct task_struct *p)
>                 goto out;
> 
>         trace_sched_swap_numa(cur, arg.src_cpu, p, arg.dst_cpu);
> +       BUG_ON(cur == p);
>         ret = stop_two_cpus(arg.dst_cpu, arg.src_cpu, migrate_swap_stop, &arg);
> 
>  out:
> 
> 
> Which seems to get hit. This sounds like a race with task moving to
> other cpu maybe?

Oi, good call that, lemme go stare.

Re: sched: spinlock recursion in migrate_swap_stop

[Peter Zijlstra]

On Wed, May 21, 2014 at 03:19:48PM +0200, Peter Zijlstra wrote:
> On Wed, May 21, 2014 at 09:08:26AM -0400, Sasha Levin wrote:

> > +++ b/kernel/sched/core.c
> > @@ -1154,6 +1156,7 @@ int migrate_swap(struct task_struct *cur, struct task_struct *p)
> >                 goto out;
> > 
> >         trace_sched_swap_numa(cur, arg.src_cpu, p, arg.dst_cpu);
> > +       BUG_ON(cur == p);
> >         ret = stop_two_cpus(arg.dst_cpu, arg.src_cpu, migrate_swap_stop, &arg);
> > 
> >  out:
> > 
> > 
> > Which seems to get hit. This sounds like a race with task moving to
> > other cpu maybe?
> 
> Oi, good call that, lemme go stare.

I think something simple like this should be sufficient to avoid the
problem of selecting oneself as a flip target.

---
 kernel/sched/fair.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
index 28ccf502c63c..28ba71d815ee 100644
--- a/kernel/sched/fair.c
+++ b/kernel/sched/fair.c
@@ -1115,6 +1115,8 @@ static void task_numa_compare(struct task_numa_env *env,
 	cur = ACCESS_ONCE(dst_rq->curr);
 	if (cur->pid == 0) /* idle */
 		cur = NULL;
+	if (cur == env->p)
+		goto unlock;
 
 	/*
 	 * "imp" is the fault differential for the source task between the

Re: sched: spinlock recursion in migrate_swap_stop

[Sasha Levin]

On 05/21/2014 12:49 PM, Peter Zijlstra wrote:
> On Wed, May 21, 2014 at 03:19:48PM +0200, Peter Zijlstra wrote:
>> > On Wed, May 21, 2014 at 09:08:26AM -0400, Sasha Levin wrote:
>>> > > +++ b/kernel/sched/core.c
>>> > > @@ -1154,6 +1156,7 @@ int migrate_swap(struct task_struct *cur, struct task_struct *p)
>>> > >                 goto out;
>>> > > 
>>> > >         trace_sched_swap_numa(cur, arg.src_cpu, p, arg.dst_cpu);
>>> > > +       BUG_ON(cur == p);
>>> > >         ret = stop_two_cpus(arg.dst_cpu, arg.src_cpu, migrate_swap_stop, &arg);
>>> > > 
>>> > >  out:
>>> > > 
>>> > > 
>>> > > Which seems to get hit. This sounds like a race with task moving to
>>> > > other cpu maybe?
>> > 
>> > Oi, good call that, lemme go stare.
> I think something simple like this should be sufficient to avoid the
> problem of selecting oneself as a flip target.

Why would that happen in the first place?


Thanks,
Sasha

Re: sched: spinlock recursion in migrate_swap_stop

[Srikar Dronamraju]

> diff --git a/kernel/sched/core.c b/kernel/sched/core.c
> index 927fa33..b5e11c7 100644
> --- a/kernel/sched/core.c
> +++ b/kernel/sched/core.c
> @@ -1154,6 +1156,7 @@ int migrate_swap(struct task_struct *cur, struct task_struct *p)
>                 goto out;
>
>         trace_sched_swap_numa(cur, arg.src_cpu, p, arg.dst_cpu);
> +       BUG_ON(cur == p);

I am not sure how this check can ever be successful because at the start
of this function migrate_swap() we have

  if (arg.src_cpu == arg.dst_cpu)
	  goto out;


if cur is actually p; then should the above condition should always be
successul right?

Or am I missing something?

>         ret = stop_two_cpus(arg.dst_cpu, arg.src_cpu, migrate_swap_stop, &arg);
>
>  out:
>
>
> Which seems to get hit. This sounds like a race with task moving to
> other cpu maybe?
>

--
Thanks and Regards
Srikar Dronamraju

Re: sched: spinlock recursion in migrate_swap_stop

[Peter Zijlstra]

[-- Attachment #1: Type: text/plain, Size: 1272 bytes --]

On Wed, May 21, 2014 at 10:34:44PM -0400, Sasha Levin wrote:
> On 05/21/2014 12:49 PM, Peter Zijlstra wrote:
> > On Wed, May 21, 2014 at 03:19:48PM +0200, Peter Zijlstra wrote:
> >> > On Wed, May 21, 2014 at 09:08:26AM -0400, Sasha Levin wrote:
> >>> > > +++ b/kernel/sched/core.c
> >>> > > @@ -1154,6 +1156,7 @@ int migrate_swap(struct task_struct *cur, struct task_struct *p)
> >>> > >                 goto out;
> >>> > > 
> >>> > >         trace_sched_swap_numa(cur, arg.src_cpu, p, arg.dst_cpu);
> >>> > > +       BUG_ON(cur == p);
> >>> > >         ret = stop_two_cpus(arg.dst_cpu, arg.src_cpu, migrate_swap_stop, &arg);
> >>> > > 
> >>> > >  out:
> >>> > > 
> >>> > > 
> >>> > > Which seems to get hit. This sounds like a race with task moving to
> >>> > > other cpu maybe?
> >> > 
> >> > Oi, good call that, lemme go stare.
> > I think something simple like this should be sufficient to avoid the
> > problem of selecting oneself as a flip target.
> 
> Why would that happen in the first place?

We do all that with preemption enabled, because its big and expensive,
so its entirely possible that current (env->p) got moved around while we
were doing it, at which point we'll look at it as a possible dst, while
its already our src.



[-- Attachment #2: Type: application/pgp-signature, Size: 836 bytes --]

Re: sched: spinlock recursion in migrate_swap_stop

[Peter Zijlstra]

[-- Attachment #1: Type: text/plain, Size: 843 bytes --]

On Thu, May 22, 2014 at 11:05:40AM +0530, Srikar Dronamraju wrote:
> > diff --git a/kernel/sched/core.c b/kernel/sched/core.c
> > index 927fa33..b5e11c7 100644
> > --- a/kernel/sched/core.c
> > +++ b/kernel/sched/core.c
> > @@ -1154,6 +1156,7 @@ int migrate_swap(struct task_struct *cur, struct task_struct *p)
> >                 goto out;
> >
> >         trace_sched_swap_numa(cur, arg.src_cpu, p, arg.dst_cpu);
> > +       BUG_ON(cur == p);
> 
> I am not sure how this check can ever be successful because at the start
> of this function migrate_swap() we have
> 
>   if (arg.src_cpu == arg.dst_cpu)
> 	  goto out;
> 
> 
> if cur is actually p; then should the above condition should always be
> successul right?
> 
> Or am I missing something?

Yeah, current might have migrated while we were looking for a target.

[-- Attachment #2: Type: application/pgp-signature, Size: 836 bytes --]

Re: sched: spinlock recursion in migrate_swap_stop

[Sasha Levin]

On 05/22/2014 02:59 AM, Peter Zijlstra wrote:
> On Wed, May 21, 2014 at 10:34:44PM -0400, Sasha Levin wrote:
>> On 05/21/2014 12:49 PM, Peter Zijlstra wrote:
>>> On Wed, May 21, 2014 at 03:19:48PM +0200, Peter Zijlstra wrote:
>>>>> On Wed, May 21, 2014 at 09:08:26AM -0400, Sasha Levin wrote:
>>>>>>> +++ b/kernel/sched/core.c
>>>>>>> @@ -1154,6 +1156,7 @@ int migrate_swap(struct task_struct *cur, struct task_struct *p)
>>>>>>>                 goto out;
>>>>>>>
>>>>>>>         trace_sched_swap_numa(cur, arg.src_cpu, p, arg.dst_cpu);
>>>>>>> +       BUG_ON(cur == p);
>>>>>>>         ret = stop_two_cpus(arg.dst_cpu, arg.src_cpu, migrate_swap_stop, &arg);
>>>>>>>
>>>>>>>  out:
>>>>>>>
>>>>>>>
>>>>>>> Which seems to get hit. This sounds like a race with task moving to
>>>>>>> other cpu maybe?
>>>>>
>>>>> Oi, good call that, lemme go stare.
>>> I think something simple like this should be sufficient to avoid the
>>> problem of selecting oneself as a flip target.
>>
>> Why would that happen in the first place?
> 
> We do all that with preemption enabled, because its big and expensive,
> so its entirely possible that current (env->p) got moved around while we
> were doing it, at which point we'll look at it as a possible dst, while
> its already our src.

Seems to be working fine now, thanks!


Thanks,
Sasha