2011-06-10 13:17:50

by Andrew Theurer

[permalink] [raw]
Subject: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

Looks like commit d72bce0e67e8afc6eb959f656013cbb577426f1e breaks my
boot:

BUG: unable to handle kernel NULL pointer dereference at
0000000000000004
IP: [<ffffffff8104e8b1>] find_lowest_rq+0xa1/0x150
PGD 0
Oops: 0000 [#1] SMP
CPU 0
Modules linked in:

Pid: 1, comm: swapper Not tainted 3.0.0-rc1-00001-gd72bce0 #32 IBM
-[7145AC1]-/Node 1, Processor Card
RIP: 0010:[<ffffffff8104e8b1>] [<ffffffff8104e8b1>] find_lowest_rq
+0xa1/0x150
RSP: 0018:ffff883732925ca0 EFLAGS: 00010002
RAX: 0000000000000020 RBX: 0000000000000020 RCX: 0000000000000050
RDX: 00000000ffffffff RSI: 0000000000000050 RDI: 0000000000000050
RBP: ffff883732925cd0 R08: ffff883732774d38 R09: 0000000000000000
R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000012ac0
FS: 0000000000000000(0000) GS:ffff88387f800000(0000)
knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 0000000000000004 CR3: 0000000001a03000 CR4: 00000000000006f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process swapper (pid: 1, threadinfo ffff883732924000, task
ffff8837329234c0)
Stack:
ffff883732925cf0 0000000000000020 0000000000000020 ffff883732775300
0000000000000000 0000000000000286 ffff883732925cf0 ffffffff8104e9da
0000000000000022 ffff883732774b40 ffff883732925d40 ffffffff8105ae11
Call Trace:
[<ffffffff8104e9da>] select_task_rq_rt+0x7a/0x90
[<ffffffff8105ae11>] try_to_wake_up+0x111/0x280
[<ffffffff8105afd5>] wake_up_process+0x15/0x20
[<ffffffff814cc5c9>] rcu_cpu_notify+0xd6/0x196
[<ffffffff814d6625>] notifier_call_chain+0x55/0x80
[<ffffffff8108a77e>] __raw_notifier_call_chain+0xe/0x10
[<ffffffff81064560>] __cpu_notify+0x20/0x40
[<ffffffff814caf88>] _cpu_up+0xc7/0x10e
[<ffffffff814cb0a6>] cpu_up+0xd7/0xea
[<ffffffff81c41cab>] smp_init+0x41/0x96
[<ffffffff81c227d4>] kernel_init+0x1d6/0x262
[<ffffffff814dbc04>] kernel_thread_helper+0x4/0x10
[<ffffffff81c225fe>] ? do_basic_setup+0x5c/0x5c
[<ffffffff814dbc00>] ? gs_change+0x13/0x13
Code: 2a 01 00 48 89 fe 48 8b 04 c5 40 a3 bf 81 4c 89 e2 49 8b 84 07 88
08 00 00 48 83 c0 38 48 89 c7 e8 b5 74 0a 00 85 c0 74 ae 89 d8
0f a3 1c 24 19 d2 85 d2 75 a6 45 0f a3 2c 24 19 c0 41 be ff
RIP [<ffffffff8104e8b1>] find_lowest_rq+0xa1/0x150
RSP <ffff883732925ca0>
CR2: 0000000000000004
---[ end trace 6afdf060c90559fd ]---
Kernel panic - not syncing: Attempted to kill init!
Pid: 1, comm: swapper Tainted: G D 3.0.0-rc1-00001-gd72bce0 #32
Call Trace:
[<ffffffff814cfcd8>] panic+0x91/0x1a8
[<ffffffff81065fdb>] forget_original_parent+0x32b/0x330
[<ffffffff81065ffb>] exit_notify+0x1b/0x190
[<ffffffff810666ed>] do_exit+0x1fd/0x430
[<ffffffff814d3c4b>] oops_end+0xab/0xf0
[<ffffffff8103d91c>] no_context+0xfc/0x190
[<ffffffff8103dad5>] __bad_area_nosemaphore+0x125/0x1e0
[<ffffffff8123b0a9>] ? put_dec+0x59/0x60
[<ffffffff8103dba3>] bad_area_nosemaphore+0x13/0x20
[<ffffffff814d6488>] do_page_fault+0x328/0x470
[<ffffffff812f4cbe>] ? notify_update+0x2e/0x30
[<ffffffff812f6aa8>] ? vt_console_print+0x2a8/0x390
[<ffffffff810f7741>] ? __perf_event_task_sched_out+0x31/0x50
[<ffffffff8105b503>] ? perf_event_task_sched_out+0x33/0xa0
[<ffffffff814d2f95>] page_fault+0x25/0x30
[<ffffffff8104e8b1>] ? find_lowest_rq+0xa1/0x150
[<ffffffff8104e9da>] select_task_rq_rt+0x7a/0x90
[<ffffffff8105ae11>] try_to_wake_up+0x111/0x280
[<ffffffff8105afd5>] wake_up_process+0x15/0x20
[<ffffffff814cc5c9>] rcu_cpu_notify+0xd6/0x196
[<ffffffff814d6625>] notifier_call_chain+0x55/0x80
[<ffffffff8108a77e>] __raw_notifier_call_chain+0xe/0x10
[<ffffffff81064560>] __cpu_notify+0x20/0x40
[<ffffffff814caf88>] _cpu_up+0xc7/0x10e
[<ffffffff814cb0a6>] cpu_up+0xd7/0xea
[<ffffffff81c41cab>] smp_init+0x41/0x96
[<ffffffff81c227d4>] kernel_init+0x1d6/0x262
[<ffffffff814dbc04>] kernel_thread_helper+0x4/0x10
[<ffffffff81c225fe>] ? do_basic_setup+0x5c/0x5c
[<ffffffff814dbc00>] ? gs_change+0x13/0x13



This is on a Westmere-EX (4 socket, 40 cores)

-Andrew



2011-06-10 14:11:41

by Peter Zijlstra

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Fri, 2011-06-10 at 08:17 -0500, Andrew Theurer wrote:
> Looks like commit d72bce0e67e8afc6eb959f656013cbb577426f1e breaks my
> boot:
>
> BUG: unable to handle kernel NULL pointer dereference at
> 0000000000000004
> IP: [<ffffffff8104e8b1>] find_lowest_rq+0xa1/0x150
> PGD 0
> Oops: 0000 [#1] SMP
> CPU 0
> Modules linked in:
>
> Pid: 1, comm: swapper Not tainted 3.0.0-rc1-00001-gd72bce0 #32 IBM
> -[7145AC1]-/Node 1, Processor Card
> RIP: 0010:[<ffffffff8104e8b1>] [<ffffffff8104e8b1>] find_lowest_rq
> +0xa1/0x150
> RSP: 0018:ffff883732925ca0 EFLAGS: 00010002
> RAX: 0000000000000020 RBX: 0000000000000020 RCX: 0000000000000050
> RDX: 00000000ffffffff RSI: 0000000000000050 RDI: 0000000000000050
> RBP: ffff883732925cd0 R08: ffff883732774d38 R09: 0000000000000000
> R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000
> R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000012ac0
> FS: 0000000000000000(0000) GS:ffff88387f800000(0000)
> knlGS:0000000000000000
> CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> CR2: 0000000000000004 CR3: 0000000001a03000 CR4: 00000000000006f0
> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> Process swapper (pid: 1, threadinfo ffff883732924000, task
> ffff8837329234c0)
> Stack:
> ffff883732925cf0 0000000000000020 0000000000000020 ffff883732775300
> 0000000000000000 0000000000000286 ffff883732925cf0 ffffffff8104e9da
> 0000000000000022 ffff883732774b40 ffff883732925d40 ffffffff8105ae11
> Call Trace:
> [<ffffffff8104e9da>] select_task_rq_rt+0x7a/0x90
> [<ffffffff8105ae11>] try_to_wake_up+0x111/0x280
> [<ffffffff8105afd5>] wake_up_process+0x15/0x20
> [<ffffffff814cc5c9>] rcu_cpu_notify+0xd6/0x196
> [<ffffffff814d6625>] notifier_call_chain+0x55/0x80
> [<ffffffff8108a77e>] __raw_notifier_call_chain+0xe/0x10
> [<ffffffff81064560>] __cpu_notify+0x20/0x40
> [<ffffffff814caf88>] _cpu_up+0xc7/0x10e
> [<ffffffff814cb0a6>] cpu_up+0xd7/0xea
> [<ffffffff81c41cab>] smp_init+0x41/0x96
> [<ffffffff81c227d4>] kernel_init+0x1d6/0x262
> [<ffffffff814dbc04>] kernel_thread_helper+0x4/0x10
> [<ffffffff81c225fe>] ? do_basic_setup+0x5c/0x5c
> [<ffffffff814dbc00>] ? gs_change+0x13/0x13
> Code: 2a 01 00 48 89 fe 48 8b 04 c5 40 a3 bf 81 4c 89 e2 49 8b 84 07 88
> 08 00 00 48 83 c0 38 48 89 c7 e8 b5 74 0a 00 85 c0 74 ae 89 d8
> 0f a3 1c 24 19 d2 85 d2 75 a6 45 0f a3 2c 24 19 c0 41 be ff
> RIP [<ffffffff8104e8b1>] find_lowest_rq+0xa1/0x150
> RSP <ffff883732925ca0>
> CR2: 0000000000000004
> ---[ end trace 6afdf060c90559fd ]---

>
> This is on a Westmere-EX (4 socket, 40 cores)

Hmm, how often does that happen? my wsm-ep (2*6*2) doesn't seem to
suffer said problem. I'll try and see if I can spot the boo-boo. Also,
happen to have a .config handy?

2011-06-10 14:46:12

by Peter Zijlstra

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Fri, 2011-06-10 at 16:11 +0200, Peter Zijlstra wrote:
> On Fri, 2011-06-10 at 08:17 -0500, Andrew Theurer wrote:
> > Looks like commit d72bce0e67e8afc6eb959f656013cbb577426f1e breaks my
> > boot:
> >
> > BUG: unable to handle kernel NULL pointer dereference at
> > 0000000000000004
> > IP: [<ffffffff8104e8b1>] find_lowest_rq+0xa1/0x150
> > PGD 0
> > Oops: 0000 [#1] SMP
> > CPU 0
> > Modules linked in:
> >
> > Pid: 1, comm: swapper Not tainted 3.0.0-rc1-00001-gd72bce0 #32 IBM
> > -[7145AC1]-/Node 1, Processor Card
> > RIP: 0010:[<ffffffff8104e8b1>] [<ffffffff8104e8b1>] find_lowest_rq
> > +0xa1/0x150
> > RSP: 0018:ffff883732925ca0 EFLAGS: 00010002
> > RAX: 0000000000000020 RBX: 0000000000000020 RCX: 0000000000000050
> > RDX: 00000000ffffffff RSI: 0000000000000050 RDI: 0000000000000050
> > RBP: ffff883732925cd0 R08: ffff883732774d38 R09: 0000000000000000
> > R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000
> > R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000012ac0
> > FS: 0000000000000000(0000) GS:ffff88387f800000(0000)
> > knlGS:0000000000000000
> > CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> > CR2: 0000000000000004 CR3: 0000000001a03000 CR4: 00000000000006f0
> > DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> > Process swapper (pid: 1, threadinfo ffff883732924000, task
> > ffff8837329234c0)
> > Stack:
> > ffff883732925cf0 0000000000000020 0000000000000020 ffff883732775300
> > 0000000000000000 0000000000000286 ffff883732925cf0 ffffffff8104e9da
> > 0000000000000022 ffff883732774b40 ffff883732925d40 ffffffff8105ae11
> > Call Trace:
> > [<ffffffff8104e9da>] select_task_rq_rt+0x7a/0x90
> > [<ffffffff8105ae11>] try_to_wake_up+0x111/0x280
> > [<ffffffff8105afd5>] wake_up_process+0x15/0x20
> > [<ffffffff814cc5c9>] rcu_cpu_notify+0xd6/0x196
> > [<ffffffff814d6625>] notifier_call_chain+0x55/0x80
> > [<ffffffff8108a77e>] __raw_notifier_call_chain+0xe/0x10
> > [<ffffffff81064560>] __cpu_notify+0x20/0x40
> > [<ffffffff814caf88>] _cpu_up+0xc7/0x10e
> > [<ffffffff814cb0a6>] cpu_up+0xd7/0xea
> > [<ffffffff81c41cab>] smp_init+0x41/0x96
> > [<ffffffff81c227d4>] kernel_init+0x1d6/0x262
> > [<ffffffff814dbc04>] kernel_thread_helper+0x4/0x10
> > [<ffffffff81c225fe>] ? do_basic_setup+0x5c/0x5c
> > [<ffffffff814dbc00>] ? gs_change+0x13/0x13
> > Code: 2a 01 00 48 89 fe 48 8b 04 c5 40 a3 bf 81 4c 89 e2 49 8b 84 07 88
> > 08 00 00 48 83 c0 38 48 89 c7 e8 b5 74 0a 00 85 c0 74 ae 89 d8
> > 0f a3 1c 24 19 d2 85 d2 75 a6 45 0f a3 2c 24 19 c0 41 be ff
> > RIP [<ffffffff8104e8b1>] find_lowest_rq+0xa1/0x150
> > RSP <ffff883732925ca0>
> > CR2: 0000000000000004
> > ---[ end trace 6afdf060c90559fd ]---
>
> >
> > This is on a Westmere-EX (4 socket, 40 cores)
>
> Hmm, how often does that happen? my wsm-ep (2*6*2) doesn't seem to
> suffer said problem. I'll try and see if I can spot the boo-boo. Also,
> happen to have a .config handy?

Does the below cure things?

---
kernel/Makefile | 1 +
kernel/sched.c | 39 +++++++++++++++++++++++----------------
2 files changed, 24 insertions(+), 16 deletions(-)

diff --git a/kernel/Makefile b/kernel/Makefile
index 2d64cfc..65eff6c 100644
--- a/kernel/Makefile
+++ b/kernel/Makefile
@@ -80,6 +80,7 @@ obj-$(CONFIG_LOCKUP_DETECTOR) += watchdog.o
obj-$(CONFIG_GENERIC_HARDIRQS) += irq/
obj-$(CONFIG_SECCOMP) += seccomp.o
obj-$(CONFIG_RCU_TORTURE_TEST) += rcutorture.o
+obj-m += test.o
obj-$(CONFIG_TREE_RCU) += rcutree.o
obj-$(CONFIG_TREE_PREEMPT_RCU) += rcutree.o
obj-$(CONFIG_TREE_RCU_TRACE) += rcutree_trace.o
diff --git a/kernel/sched.c b/kernel/sched.c
index 5925275..a602e7e 100644
--- a/kernel/sched.c
+++ b/kernel/sched.c
@@ -6413,26 +6413,10 @@ migration_call(struct notifier_block *nfb, unsigned long action, void *hcpu)
rq->calc_load_update = calc_load_update;
break;

- case CPU_ONLINE:
- /* Update our root-domain */
- raw_spin_lock_irqsave(&rq->lock, flags);
- if (rq->rd) {
- BUG_ON(!cpumask_test_cpu(cpu, rq->rd->span));
-
- set_rq_online(rq);
- }
- raw_spin_unlock_irqrestore(&rq->lock, flags);
- break;
-
#ifdef CONFIG_HOTPLUG_CPU
case CPU_DYING:
sched_ttwu_pending();
- /* Update our root-domain */
raw_spin_lock_irqsave(&rq->lock, flags);
- if (rq->rd) {
- BUG_ON(!cpumask_test_cpu(cpu, rq->rd->span));
- set_rq_offline(rq);
- }
migrate_tasks(cpu);
BUG_ON(rq->nr_running != 1); /* the migration thread */
raw_spin_unlock_irqrestore(&rq->lock, flags);
@@ -6461,9 +6445,21 @@ static struct notifier_block __cpuinitdata migration_notifier = {
static int __cpuinit sched_cpu_active(struct notifier_block *nfb,
unsigned long action, void *hcpu)
{
+ int cpu = (long)hcpu;
+ unsigned long flags;
+ struct rq *rq = cpu_rq(cpu);
+
switch (action & ~CPU_TASKS_FROZEN) {
case CPU_ONLINE:
case CPU_DOWN_FAILED:
+ /* Update our root-domain */
+ raw_spin_lock_irqsave(&rq->lock, flags);
+ if (rq->rd) {
+ BUG_ON(!cpumask_test_cpu(cpu, rq->rd->span));
+
+ set_rq_online(rq);
+ }
+ raw_spin_unlock_irqrestore(&rq->lock, flags);
set_cpu_active((long)hcpu, true);
return NOTIFY_OK;
default:
@@ -6474,9 +6470,20 @@ static int __cpuinit sched_cpu_active(struct notifier_block *nfb,
static int __cpuinit sched_cpu_inactive(struct notifier_block *nfb,
unsigned long action, void *hcpu)
{
+ int cpu = (long)hcpu;
+ unsigned long flags;
+ struct rq *rq = cpu_rq(cpu);
+
switch (action & ~CPU_TASKS_FROZEN) {
case CPU_DOWN_PREPARE:
set_cpu_active((long)hcpu, false);
+ /* Update our root-domain */
+ raw_spin_lock_irqsave(&rq->lock, flags);
+ if (rq->rd) {
+ BUG_ON(!cpumask_test_cpu(cpu, rq->rd->span));
+ set_rq_offline(rq);
+ }
+ raw_spin_unlock_irqrestore(&rq->lock, flags);
return NOTIFY_OK;
default:
return NOTIFY_DONE;

2011-06-10 14:52:26

by Steven Rostedt

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Fri, 2011-06-10 at 16:45 +0200, Peter Zijlstra wrote:

> > >
> > > This is on a Westmere-EX (4 socket, 40 cores)
> >
> > Hmm, how often does that happen? my wsm-ep (2*6*2) doesn't seem to
> > suffer said problem. I'll try and see if I can spot the boo-boo. Also,
> > happen to have a .config handy?
>
> Does the below cure things?
>
> ---
> kernel/Makefile | 1 +
> kernel/sched.c | 39 +++++++++++++++++++++++----------------
> 2 files changed, 24 insertions(+), 16 deletions(-)
>
> diff --git a/kernel/Makefile b/kernel/Makefile
> index 2d64cfc..65eff6c 100644
> --- a/kernel/Makefile
> +++ b/kernel/Makefile
> @@ -80,6 +80,7 @@ obj-$(CONFIG_LOCKUP_DETECTOR) += watchdog.o
> obj-$(CONFIG_GENERIC_HARDIRQS) += irq/
> obj-$(CONFIG_SECCOMP) += seccomp.o
> obj-$(CONFIG_RCU_TORTURE_TEST) += rcutorture.o
> +obj-m += test.o

Did you mean to keep this?

-- Steve

> obj-$(CONFIG_TREE_RCU) += rcutree.o
> obj-$(CONFIG_TREE_PREEMPT_RCU) += rcutree.o
> obj-$(CONFIG_TREE_RCU_TRACE) += rcutree_trace.o

2011-06-10 14:59:29

by Peter Zijlstra

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Fri, 2011-06-10 at 10:52 -0400, Steven Rostedt wrote:
> > +obj-m += test.o
>
> Did you mean to keep this?

nope, not really.. silly me.

2011-06-10 15:13:17

by Andrew Theurer

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Fri, 2011-06-10 at 16:11 +0200, Peter Zijlstra wrote:
> On Fri, 2011-06-10 at 08:17 -0500, Andrew Theurer wrote:
> > Looks like commit d72bce0e67e8afc6eb959f656013cbb577426f1e breaks my
> > boot:
> >
> > BUG: unable to handle kernel NULL pointer dereference at
> > 0000000000000004
> > IP: [<ffffffff8104e8b1>] find_lowest_rq+0xa1/0x150
> > PGD 0
> > Oops: 0000 [#1] SMP
> > CPU 0
> > Modules linked in:
> >
> > Pid: 1, comm: swapper Not tainted 3.0.0-rc1-00001-gd72bce0 #32 IBM
> > -[7145AC1]-/Node 1, Processor Card
> > RIP: 0010:[<ffffffff8104e8b1>] [<ffffffff8104e8b1>] find_lowest_rq
> > +0xa1/0x150
> > RSP: 0018:ffff883732925ca0 EFLAGS: 00010002
> > RAX: 0000000000000020 RBX: 0000000000000020 RCX: 0000000000000050
> > RDX: 00000000ffffffff RSI: 0000000000000050 RDI: 0000000000000050
> > RBP: ffff883732925cd0 R08: ffff883732774d38 R09: 0000000000000000
> > R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000
> > R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000012ac0
> > FS: 0000000000000000(0000) GS:ffff88387f800000(0000)
> > knlGS:0000000000000000
> > CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> > CR2: 0000000000000004 CR3: 0000000001a03000 CR4: 00000000000006f0
> > DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> > Process swapper (pid: 1, threadinfo ffff883732924000, task
> > ffff8837329234c0)
> > Stack:
> > ffff883732925cf0 0000000000000020 0000000000000020 ffff883732775300
> > 0000000000000000 0000000000000286 ffff883732925cf0 ffffffff8104e9da
> > 0000000000000022 ffff883732774b40 ffff883732925d40 ffffffff8105ae11
> > Call Trace:
> > [<ffffffff8104e9da>] select_task_rq_rt+0x7a/0x90
> > [<ffffffff8105ae11>] try_to_wake_up+0x111/0x280
> > [<ffffffff8105afd5>] wake_up_process+0x15/0x20
> > [<ffffffff814cc5c9>] rcu_cpu_notify+0xd6/0x196
> > [<ffffffff814d6625>] notifier_call_chain+0x55/0x80
> > [<ffffffff8108a77e>] __raw_notifier_call_chain+0xe/0x10
> > [<ffffffff81064560>] __cpu_notify+0x20/0x40
> > [<ffffffff814caf88>] _cpu_up+0xc7/0x10e
> > [<ffffffff814cb0a6>] cpu_up+0xd7/0xea
> > [<ffffffff81c41cab>] smp_init+0x41/0x96
> > [<ffffffff81c227d4>] kernel_init+0x1d6/0x262
> > [<ffffffff814dbc04>] kernel_thread_helper+0x4/0x10
> > [<ffffffff81c225fe>] ? do_basic_setup+0x5c/0x5c
> > [<ffffffff814dbc00>] ? gs_change+0x13/0x13
> > Code: 2a 01 00 48 89 fe 48 8b 04 c5 40 a3 bf 81 4c 89 e2 49 8b 84 07 88
> > 08 00 00 48 83 c0 38 48 89 c7 e8 b5 74 0a 00 85 c0 74 ae 89 d8
> > 0f a3 1c 24 19 d2 85 d2 75 a6 45 0f a3 2c 24 19 c0 41 be ff
> > RIP [<ffffffff8104e8b1>] find_lowest_rq+0xa1/0x150
> > RSP <ffff883732925ca0>
> > CR2: 0000000000000004
> > ---[ end trace 6afdf060c90559fd ]---
>
> >
> > This is on a Westmere-EX (4 socket, 40 cores)
>
> Hmm, how often does that happen?

Every single boot so far.

> my wsm-ep (2*6*2) doesn't seem to
> suffer said problem. I'll try and see if I can spot the boo-boo. Also,
> happen to have a .config handy?

attached.

Thanks,

-Andrew




Attachments:
config-3.0-rc (109.68 kB)

2011-06-10 15:34:38

by Andrew Theurer

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Fri, 2011-06-10 at 16:45 +0200, Peter Zijlstra wrote:
> On Fri, 2011-06-10 at 16:11 +0200, Peter Zijlstra wrote:
> > On Fri, 2011-06-10 at 08:17 -0500, Andrew Theurer wrote:
> > > Looks like commit d72bce0e67e8afc6eb959f656013cbb577426f1e breaks my
> > > boot:
> > >
> > > BUG: unable to handle kernel NULL pointer dereference at
> > > 0000000000000004
> > > IP: [<ffffffff8104e8b1>] find_lowest_rq+0xa1/0x150
> > > PGD 0
> > > Oops: 0000 [#1] SMP
> > > CPU 0
> > > Modules linked in:

> >
> > >
> > > This is on a Westmere-EX (4 socket, 40 cores)
> >
> > Hmm, how often does that happen? my wsm-ep (2*6*2) doesn't seem to
> > suffer said problem. I'll try and see if I can spot the boo-boo. Also,
> > happen to have a .config handy?
>
> Does the below cure things?

I am afraid not:

Linux version 3.0.0-rc2-00251-g7f45e5c-dirty ([email protected]) (gcc version 4.4.5 20110214 (Red Hat 4.4.5-6) (GCC) ) #34 SMP Fri Jun 10 10:23:06 CDT 2011
Command line: initrd=vg-host/initramfs.img ro root=UUID=7e96e905-9ec4-45ab-abd4-77d1469d6e5a console=tty0 console=ttyS0,115200 rdshell BOOT_IMAGE=vg-host/vmlinuz
.
.
.
.
NMI watchdog enabled, takes one hw-pmu counter.
#23
NMI watchdog enabled, takes one hw-pmu counter.
#24
BUG: unable to handle kernel NULL pointer dereference at (null)
IP: [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
PGD 0
Oops: 0000 [#1] SMP
CPU 0
Modules linked in:

Pid: 1, comm: swapper Not tainted 3.0.0-rc2-00251-g7f45e5c-dirty #34 IBM -[7145AC1]-/Node 1, Processor Card
RIP: 0010:[<ffffffff8104e8c1>] [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
RSP: 0018:ffff883732925ca0 EFLAGS: 00010002
RAX: 0000000000000010 RBX: 0000000000000010 RCX: 0000000000000050
RDX: 00000000ffffffff RSI: 0000000000000050 RDI: 0000000000000050
RBP: ffff883732925cd0 R08: ffff8837325b4238 R09: 0000000000000000
R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000012ac0
FS: 0000000000000000(0000) GS:ffff88387f800000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 0000000000000000 CR3: 0000000001a03000 CR4: 00000000000006f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process swapper (pid: 1, threadinfo ffff883732924000, task ffff8837329234c0)
Stack:
ffff883732925cd0 0000000000000010 0000000000000010 ffff8837325b4800
0000000000000000 0000000000000286 ffff883732925cf0 ffffffff8104e9ea
ffff883732642040 ffff8837325b4040 ffff883732925d40 ffffffff8105ac79
Call Trace:
[<ffffffff8104e9ea>] select_task_rq_rt+0x7a/0x90
[<ffffffff8105ac79>] try_to_wake_up+0x119/0x2a0
[<ffffffff8105ae55>] wake_up_process+0x15/0x20
[<ffffffff814cc59f>] rcu_cpu_notify+0xd6/0x196
[<ffffffff814d65e5>] notifier_call_chain+0x55/0x80
[<ffffffff8108a7be>] __raw_notifier_call_chain+0xe/0x10
[<ffffffff81064590>] __cpu_notify+0x20/0x40
[<ffffffff814caf5e>] _cpu_up+0xc7/0x10e
[<ffffffff814cb07c>] cpu_up+0xd7/0xea
[<ffffffff81c41dfb>] smp_init+0x41/0x96
[<ffffffff81c227d4>] kernel_init+0x1d6/0x262
[<ffffffff814dbbc4>] kernel_thread_helper+0x4/0x10
[<ffffffff81c225fe>] ? do_basic_setup+0x5c/0x5c
[<ffffffff814dbbc0>] ? gs_change+0x13/0x13
Code: 2a 01 00 48 89 fe 48 8b 04 c5 40 a3 bf 81 4c 89 e2 49 8b 84 07 88 08 00 00 48 83 c0 38 48 89 c7 e8 85 75 0a 00 85 c0 74 ae 89 d8
0f a3 1c 24 19 d2 85 d2 75 a6 45 0f a3 2c 24 19 c0 41 be ff
RIP [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
RSP <ffff883732925ca0>
CR2: 0000000000000000
---[ end trace 050353be83bb766f ]---

-Andrew

2011-06-10 15:46:34

by Andrew Theurer

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Fri, 2011-06-10 at 10:34 -0500, Andrew Theurer wrote:
> On Fri, 2011-06-10 at 16:45 +0200, Peter Zijlstra wrote:
> > On Fri, 2011-06-10 at 16:11 +0200, Peter Zijlstra wrote:
> > > On Fri, 2011-06-10 at 08:17 -0500, Andrew Theurer wrote:
> > > > Looks like commit d72bce0e67e8afc6eb959f656013cbb577426f1e breaks my
> > > > boot:
> > > >
> > > > BUG: unable to handle kernel NULL pointer dereference at
> > > > 0000000000000004
> > > > IP: [<ffffffff8104e8b1>] find_lowest_rq+0xa1/0x150
> > > > PGD 0
> > > > Oops: 0000 [#1] SMP
> > > > CPU 0
> > > > Modules linked in:
>
> > >
> > > >
> > > > This is on a Westmere-EX (4 socket, 40 cores)
> > >
> > > Hmm, how often does that happen? my wsm-ep (2*6*2) doesn't seem to
> > > suffer said problem. I'll try and see if I can spot the boo-boo. Also,
> > > happen to have a .config handy?
> >
> > Does the below cure things?
>
> I am afraid not:

Forgot to mention, if I boot with maxcpus=1, the online the rest of the
CPUs later, I can avoid the problem.

>
> Linux version 3.0.0-rc2-00251-g7f45e5c-dirty ([email protected]) (gcc version 4.4.5 20110214 (Red Hat 4.4.5-6) (GCC) ) #34 SMP Fri Jun 10 10:23:06 CDT 2011
> Command line: initrd=vg-host/initramfs.img ro root=UUID=7e96e905-9ec4-45ab-abd4-77d1469d6e5a console=tty0 console=ttyS0,115200 rdshell BOOT_IMAGE=vg-host/vmlinuz
> .
> .
> .
> .
> NMI watchdog enabled, takes one hw-pmu counter.
> #23
> NMI watchdog enabled, takes one hw-pmu counter.
> #24
> BUG: unable to handle kernel NULL pointer dereference at (null)
> IP: [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
> PGD 0
> Oops: 0000 [#1] SMP
> CPU 0
> Modules linked in:
>
> Pid: 1, comm: swapper Not tainted 3.0.0-rc2-00251-g7f45e5c-dirty #34 IBM -[7145AC1]-/Node 1, Processor Card
> RIP: 0010:[<ffffffff8104e8c1>] [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
> RSP: 0018:ffff883732925ca0 EFLAGS: 00010002
> RAX: 0000000000000010 RBX: 0000000000000010 RCX: 0000000000000050
> RDX: 00000000ffffffff RSI: 0000000000000050 RDI: 0000000000000050
> RBP: ffff883732925cd0 R08: ffff8837325b4238 R09: 0000000000000000
> R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000
> R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000012ac0
> FS: 0000000000000000(0000) GS:ffff88387f800000(0000) knlGS:0000000000000000
> CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> CR2: 0000000000000000 CR3: 0000000001a03000 CR4: 00000000000006f0
> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> Process swapper (pid: 1, threadinfo ffff883732924000, task ffff8837329234c0)
> Stack:
> ffff883732925cd0 0000000000000010 0000000000000010 ffff8837325b4800
> 0000000000000000 0000000000000286 ffff883732925cf0 ffffffff8104e9ea
> ffff883732642040 ffff8837325b4040 ffff883732925d40 ffffffff8105ac79
> Call Trace:
> [<ffffffff8104e9ea>] select_task_rq_rt+0x7a/0x90
> [<ffffffff8105ac79>] try_to_wake_up+0x119/0x2a0
> [<ffffffff8105ae55>] wake_up_process+0x15/0x20
> [<ffffffff814cc59f>] rcu_cpu_notify+0xd6/0x196
> [<ffffffff814d65e5>] notifier_call_chain+0x55/0x80
> [<ffffffff8108a7be>] __raw_notifier_call_chain+0xe/0x10
> [<ffffffff81064590>] __cpu_notify+0x20/0x40
> [<ffffffff814caf5e>] _cpu_up+0xc7/0x10e
> [<ffffffff814cb07c>] cpu_up+0xd7/0xea
> [<ffffffff81c41dfb>] smp_init+0x41/0x96
> [<ffffffff81c227d4>] kernel_init+0x1d6/0x262
> [<ffffffff814dbbc4>] kernel_thread_helper+0x4/0x10
> [<ffffffff81c225fe>] ? do_basic_setup+0x5c/0x5c
> [<ffffffff814dbbc0>] ? gs_change+0x13/0x13
> Code: 2a 01 00 48 89 fe 48 8b 04 c5 40 a3 bf 81 4c 89 e2 49 8b 84 07 88 08 00 00 48 83 c0 38 48 89 c7 e8 85 75 0a 00 85 c0 74 ae 89 d8
> 0f a3 1c 24 19 d2 85 d2 75 a6 45 0f a3 2c 24 19 c0 41 be ff
> RIP [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
> RSP <ffff883732925ca0>
> CR2: 0000000000000000
> ---[ end trace 050353be83bb766f ]---
>
-Andrew

2011-06-10 16:09:59

by Peter Zijlstra

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Fri, 2011-06-10 at 10:13 -0500, Andrew Theurer wrote:
> > happen to have a .config handy?
>
> attached.

Just my luck, my machine boots fine until the root mount fails (which I
assume is past the point it fails for you). I'm having the most aweful
luck with reproduction the past few weeks..

2011-06-10 16:27:28

by Peter Zijlstra

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Fri, 2011-06-10 at 10:34 -0500, Andrew Theurer wrote:
> RIP: 0010:[<ffffffff8104e8c1>] [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150

If you've still got the vmlinux around, could you find out where in
find_lowest_rq that RIP is?

2011-06-13 15:06:50

by Andrew Theurer

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Fri, 2011-06-10 at 18:27 +0200, Peter Zijlstra wrote:
> On Fri, 2011-06-10 at 10:34 -0500, Andrew Theurer wrote:
> > RIP: 0010:[<ffffffff8104e8c1>] [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
>
> If you've still got the vmlinux around, could you find out where in
> find_lowest_rq that RIP is?

Does this help?


from objdump -d -S

ffffffff8104e820 <find_lowest_rq>:
ffffffff8104e820: 55 push %rbp
ffffffff8104e821: 48 89 e5 mov %rsp,%rbp
ffffffff8104e824: 48 83 ec 30 sub $0x30,%rsp
ffffffff8104e828: 48 89 5d d8 mov %rbx,-0x28(%rbp)
ffffffff8104e82c: 4c 89 65 e0 mov %r12,-0x20(%rbp)
ffffffff8104e830: 4c 89 6d e8 mov %r13,-0x18(%rbp)
ffffffff8104e834: 4c 89 75 f0 mov %r14,-0x10(%rbp)
ffffffff8104e838: 4c 89 7d f8 mov %r15,-0x8(%rbp)
ffffffff8104e83c: e8 3f bf 48 00 callq ffffffff814da780 <mcount>
ffffffff8104e841: 48 c7 c0 88 e8 00 00 mov $0xe888,%rax
ffffffff8104e848: 65 48 03 04 25 50 dc add %gs:0xdc50,%rax
ffffffff8104e84f: 00 00
ffffffff8104e851: 65 44 8b 2c 25 58 dc mov %gs:0xdc58,%r13d
ffffffff8104e858: 00 00
ffffffff8104e85a: 83 bf bc 01 00 00 01 cmpl $0x1,0x1bc(%rdi)
ffffffff8104e861: 4c 8b 20 mov (%rax),%r12
ffffffff8104e864: 48 8b 47 08 mov 0x8(%rdi),%rax
ffffffff8104e868: 8b 58 18 mov 0x18(%rax),%ebx
ffffffff8104e86b: 75 23 jne ffffffff8104e890 <find_lowest_rq+0x70>
ffffffff8104e86d: b8 ff ff ff ff mov $0xffffffff,%eax
ffffffff8104e872: 48 8b 5d d8 mov -0x28(%rbp),%rbx
ffffffff8104e876: 4c 8b 65 e0 mov -0x20(%rbp),%r12
ffffffff8104e87a: 4c 8b 6d e8 mov -0x18(%rbp),%r13
ffffffff8104e87e: 4c 8b 75 f0 mov -0x10(%rbp),%r14
ffffffff8104e882: 4c 8b 7d f8 mov -0x8(%rbp),%r15
ffffffff8104e886: c9 leaveq
ffffffff8104e887: c3 retq
ffffffff8104e888: 0f 1f 84 00 00 00 00 nopl 0x0(%rax,%rax,1)
ffffffff8104e88f: 00
ffffffff8104e890: 89 d8 mov %ebx,%eax
ffffffff8104e892: 49 c7 c7 c0 2a 01 00 mov $0x12ac0,%r15
ffffffff8104e899: 48 89 fe mov %rdi,%rsi
ffffffff8104e89c: 48 8b 04 c5 40 a3 bf mov -0x7e405cc0(,%rax,8),%rax
ffffffff8104e8a3: 81
ffffffff8104e8a4: 4c 89 e2 mov %r12,%rdx
ffffffff8104e8a7: 49 8b 84 07 88 08 00 mov 0x888(%r15,%rax,1),%rax
ffffffff8104e8ae: 00
ffffffff8104e8af: 48 83 c0 38 add $0x38,%rax
ffffffff8104e8b3: 48 89 c7 mov %rax,%rdi
ffffffff8104e8b6: e8 85 75 0a 00 callq ffffffff810f5e40 <cpupri_find>
ffffffff8104e8bb: 85 c0 test %eax,%eax
ffffffff8104e8bd: 74 ae je ffffffff8104e86d <find_lowest_rq+0x4d>
ffffffff8104e8bf: 89 d8 mov %ebx,%eax
ffffffff8104e8c1: 41 0f a3 1c 24 bt %ebx,(%r12)
ffffffff8104e8c6: 19 d2 sbb %edx,%edx
ffffffff8104e8c8: 85 d2 test %edx,%edx
ffffffff8104e8ca: 75 a6 jne ffffffff8104e872 <find_lowest_rq+0x52>
ffffffff8104e8cc: 45 0f a3 2c 24 bt %r13d,(%r12)
ffffffff8104e8d1: 19 c0 sbb %eax,%eax
ffffffff8104e8d3: 41 be ff ff ff ff mov $0xffffffff,%r14d
ffffffff8104e8d9: 85 c0 test %eax,%eax
ffffffff8104e8db: 48 63 db movslq %ebx,%rbx
ffffffff8104e8de: 45 0f 45 f5 cmovne %r13d,%r14d
ffffffff8104e8e2: 4c 03 3c dd 40 a3 bf add -0x7e405cc0(,%rbx,8),%r15
ffffffff8104e8e9: 81
ffffffff8104e8ea: 49 8b 9f 90 08 00 00 mov 0x890(%r15),%rbx
ffffffff8104e8f1: 48 85 db test %rbx,%rbx
ffffffff8104e8f4: 74 4c je ffffffff8104e942 <find_lowest_rq+0x122>
ffffffff8104e8f6: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
ffffffff8104e8fd: 00 00 00
ffffffff8104e900: f6 43 4c 20 testb $0x20,0x4c(%rbx)
ffffffff8104e904: 74 34 je ffffffff8104e93a <find_lowest_rq+0x11a>
ffffffff8104e906: 41 83 fe ff cmp $0xffffffffffffffff,%r14d
ffffffff8104e90a: 74 0e je ffffffff8104e91a <find_lowest_rq+0xfa>
ffffffff8104e90c: 44 0f a3 b3 20 01 00 bt %r14d,0x120(%rbx)
ffffffff8104e913: 00
ffffffff8104e914: 19 c0 sbb %eax,%eax
ffffffff8104e916: 85 c0 test %eax,%eax
ffffffff8104e918: 75 2e jne ffffffff8104e948 <find_lowest_rq+0x128>
ffffffff8104e91a: 48 8d 93 20 01 00 00 lea 0x120(%rbx),%rdx
ffffffff8104e921: 4c 89 e6 mov %r12,%rsi
ffffffff8104e924: bf ff ff ff ff mov $0xffffffff,%edi
ffffffff8104e929: e8 42 4e 1e 00 callq ffffffff81233770 <cpumask_next_and>
ffffffff8104e92e: 3b 05 14 78 bb 00 cmp 0xbb7814(%rip),%eax # ffffffff81c06148 <nr_cpu_ids>
ffffffff8104e934: 0f 8c 38 ff ff ff jl ffffffff8104e872 <find_lowest_rq+0x52>
ffffffff8104e93a: 48 8b 1b mov (%rbx),%rbx
ffffffff8104e93d: 48 85 db test %rbx,%rbx
ffffffff8104e940: 75 be jne ffffffff8104e900 <find_lowest_rq+0xe0>
ffffffff8104e942: 41 83 fe ff cmp $0xffffffffffffffff,%r14d
ffffffff8104e946: 74 08 je ffffffff8104e950 <find_lowest_rq+0x130>
ffffffff8104e948: 44 89 f0 mov %r14d,%eax
ffffffff8104e94b: e9 22 ff ff ff jmpq ffffffff8104e872 <find_lowest_rq+0x52>
ffffffff8104e950: 48 63 35 f1 77 bb 00 movslq 0xbb77f1(%rip),%rsi # ffffffff81c06148 <nr_cpu_ids>
ffffffff8104e957: 4c 89 e7 mov %r12,%rdi
ffffffff8104e95a: e8 d1 52 1e 00 callq ffffffff81233c30 <find_first_bit>
ffffffff8104e95f: 3b 05 e3 77 bb 00 cmp 0xbb77e3(%rip),%eax # ffffffff81c06148 <nr_cpu_ids>
ffffffff8104e965: 0f 8c 07 ff ff ff jl ffffffff8104e872 <find_lowest_rq+0x52>
ffffffff8104e96b: e9 fd fe ff ff jmpq ffffffff8104e86d <find_lowest_rq+0x4d>

[ 4.540584] BUG: unable to handle kernel NULL pointer dereference at 0000000000000004
[ 4.548779] IP: [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
[ 4.554824] PGD 0
[ 4.557044] Oops: 0000 [#1] SMP
[ 4.560558] CPU 0
[ 4.562457] Modules linked in:
[ 4.566042]
[ 4.567669] Pid: 1, comm: swapper Not tainted 3.0.0-rc2-00251-g7f45e5c #37 IBM -[7145AC1]-/Node 1, Processor Card
[ 4.578446] RIP: 0010:[<ffffffff8104e8c1>] [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
[ 4.586988] RSP: 0018:ffff883732925ca0 EFLAGS: 00010002
[ 4.592429] RAX: 0000000000000020 RBX: 0000000000000020 RCX: 0000000000000050
[ 4.599692] RDX: 00000000ffffffff RSI: 0000000000000050 RDI: 0000000000000050
[ 4.606954] RBP: ffff883732925cd0 R08: ffff883732774d38 R09: 0000000000000000
[ 4.614219] R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000
[ 4.621479] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000012ac0
[ 4.628739] FS: 0000000000000000(0000) GS:ffff88387f800000(0000) knlGS:0000000000000000
[ 4.637024] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 4.642897] CR2: 0000000000000004 CR3: 0000000001a03000 CR4: 00000000000006f0
[ 4.650159] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 4.657421] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[ 4.664684] Process swapper (pid: 1, threadinfo ffff883732924000, task ffff8837329234c0)
[ 4.672971] Stack:
[ 4.675117] ffff883732925cf0 0000000000000020 0000000000000020 ffff883732775300
[ 4.683022] 0000000000000000 0000000000000286 ffff883732925cf0 ffffffff8104e9ea
[ 4.690938] ffff88373279cb00 ffff883732774b40 ffff883732925d40 ffffffff8105ac79
[ 4.698851] Call Trace:
[ 4.701437] [<ffffffff8104e9ea>] select_task_rq_rt+0x7a/0x90
[ 4.707320] [<ffffffff8105ac79>] try_to_wake_up+0x119/0x2a0
[ 4.713114] [<ffffffff8105ae55>] wake_up_process+0x15/0x20
[ 4.718818] [<ffffffff814cc546>] rcu_cpu_notify+0xd6/0x196
[ 4.724524] [<ffffffff814d65a5>] notifier_call_chain+0x55/0x80
[ 4.730577] [<ffffffff8108a7be>] __raw_notifier_call_chain+0xe/0x10
[ 4.737061] [<ffffffff81064590>] __cpu_notify+0x20/0x40
[ 4.742504] [<ffffffff814caf05>] _cpu_up+0xc7/0x10e
[ 4.747599] [<ffffffff814cb023>] cpu_up+0xd7/0xea
[ 4.752527] [<ffffffff81c41dfa>] smp_init+0x41/0x96
[ 4.757627] [<ffffffff81c227d4>] kernel_init+0x1d6/0x262
[ 4.763165] [<ffffffff814dbb84>] kernel_thread_helper+0x4/0x10
[ 4.769221] [<ffffffff81c225fe>] ? do_basic_setup+0x5c/0x5c
[ 4.775008] [<ffffffff814dbb80>] ? gs_change+0x13/0x13
[ 4.780360] Code: 2a 01 00 48 89 fe 48 8b 04 c5 40 a3 bf 81 4c 89 e2 49 8b 84 07 88 08 00 00 48 83 c0 38 48 89 c7 e8 85 75 0a 00 85 c0 74 ae 89 d8
[ 4.796927] 0f a3 1c 24 19 d2 85 d2 75 a6 45 0f a3 2c 24 19 c0 41 be ff
[ 4.805820] RIP [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
[ 4.811946] RSP <ffff883732925ca0>
[ 4.815566] CR2: 0000000000000004
[ 4.819019] ---[ end trace ca2ec1f2e8037d5f ]---

-Andrew



2011-06-13 15:14:30

by Steven Rostedt

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Mon, 2011-06-13 at 10:06 -0500, Andrew Theurer wrote:
> On Fri, 2011-06-10 at 18:27 +0200, Peter Zijlstra wrote:
> > On Fri, 2011-06-10 at 10:34 -0500, Andrew Theurer wrote:
> > > RIP: 0010:[<ffffffff8104e8c1>] [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
> >
> > If you've still got the vmlinux around, could you find out where in
> > find_lowest_rq that RIP is?
>
> Does this help?

A little, but could you also do the following: (if you had DEBUG_INFO
compiled in)

$ gdb vmlinux
gdb> li *0xffffffff8104e8c1

And give the output of that?

Thanks,

-- Steve

2011-06-13 15:34:03

by Steven Rostedt

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Mon, 2011-06-13 at 10:06 -0500, Andrew Theurer wrote:
> On Fri, 2011-06-10 at 18:27 +0200, Peter Zijlstra wrote:
> > On Fri, 2011-06-10 at 10:34 -0500, Andrew Theurer wrote:
> > > RIP: 0010:[<ffffffff8104e8c1>] [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
> >
> > If you've still got the vmlinux around, could you find out where in
> > find_lowest_rq that RIP is?
>
> Does this help?

I take it back, it looks like this does help.

>
>
> from objdump -d -S
>
> ffffffff8104e820 <find_lowest_rq>:
> ffffffff8104e820: 55 push %rbp
> ffffffff8104e821: 48 89 e5 mov %rsp,%rbp
> ffffffff8104e824: 48 83 ec 30 sub $0x30,%rsp
> ffffffff8104e828: 48 89 5d d8 mov %rbx,-0x28(%rbp)
> ffffffff8104e82c: 4c 89 65 e0 mov %r12,-0x20(%rbp)
> ffffffff8104e830: 4c 89 6d e8 mov %r13,-0x18(%rbp)
> ffffffff8104e834: 4c 89 75 f0 mov %r14,-0x10(%rbp)
> ffffffff8104e838: 4c 89 7d f8 mov %r15,-0x8(%rbp)
> ffffffff8104e83c: e8 3f bf 48 00 callq ffffffff814da780 <mcount>
> ffffffff8104e841: 48 c7 c0 88 e8 00 00 mov $0xe888,%rax
> ffffffff8104e848: 65 48 03 04 25 50 dc add %gs:0xdc50,%rax
> ffffffff8104e84f: 00 00
> ffffffff8104e851: 65 44 8b 2c 25 58 dc mov %gs:0xdc58,%r13d
> ffffffff8104e858: 00 00
> ffffffff8104e85a: 83 bf bc 01 00 00 01 cmpl $0x1,0x1bc(%rdi)
> ffffffff8104e861: 4c 8b 20 mov (%rax),%r12
> ffffffff8104e864: 48 8b 47 08 mov 0x8(%rdi),%rax
> ffffffff8104e868: 8b 58 18 mov 0x18(%rax),%ebx
> ffffffff8104e86b: 75 23 jne ffffffff8104e890 <find_lowest_rq+0x70>
> ffffffff8104e86d: b8 ff ff ff ff mov $0xffffffff,%eax
> ffffffff8104e872: 48 8b 5d d8 mov -0x28(%rbp),%rbx
> ffffffff8104e876: 4c 8b 65 e0 mov -0x20(%rbp),%r12
> ffffffff8104e87a: 4c 8b 6d e8 mov -0x18(%rbp),%r13
> ffffffff8104e87e: 4c 8b 75 f0 mov -0x10(%rbp),%r14
> ffffffff8104e882: 4c 8b 7d f8 mov -0x8(%rbp),%r15
> ffffffff8104e886: c9 leaveq
> ffffffff8104e887: c3 retq
> ffffffff8104e888: 0f 1f 84 00 00 00 00 nopl 0x0(%rax,%rax,1)
> ffffffff8104e88f: 00
> ffffffff8104e890: 89 d8 mov %ebx,%eax
> ffffffff8104e892: 49 c7 c7 c0 2a 01 00 mov $0x12ac0,%r15
> ffffffff8104e899: 48 89 fe mov %rdi,%rsi
> ffffffff8104e89c: 48 8b 04 c5 40 a3 bf mov -0x7e405cc0(,%rax,8),%rax
> ffffffff8104e8a3: 81
> ffffffff8104e8a4: 4c 89 e2 mov %r12,%rdx
> ffffffff8104e8a7: 49 8b 84 07 88 08 00 mov 0x888(%r15,%rax,1),%rax
> ffffffff8104e8ae: 00
> ffffffff8104e8af: 48 83 c0 38 add $0x38,%rax
> ffffffff8104e8b3: 48 89 c7 mov %rax,%rdi
> ffffffff8104e8b6: e8 85 75 0a 00 callq ffffffff810f5e40 <cpupri_find>
> ffffffff8104e8bb: 85 c0 test %eax,%eax
> ffffffff8104e8bd: 74 ae je ffffffff8104e86d <find_lowest_rq+0x4d>
> ffffffff8104e8bf: 89 d8 mov %ebx,%eax
> ffffffff8104e8c1: 41 0f a3 1c 24 bt %ebx,(%r12)

Following the asm here, I figured we are here:

static int find_lowest_rq(struct task_struct *task)
{
struct sched_domain *sd;
struct cpumask *lowest_mask = __get_cpu_var(local_cpu_mask);
int this_cpu = smp_processor_id();
int cpu = task_cpu(task);

if (task->rt.nr_cpus_allowed == 1)
return -1; /* No other targets possible */

if (!cpupri_find(&task_rq(task)->rd->cpupri, task, lowest_mask))
return -1; /* No targets found */

/*
* At this point we have built a mask of cpus representing the
* lowest priority tasks in the system. Now we want to elect
* the best one based on our affinity and topology.
*
* We prioritize the last cpu that the task executed on since
* it is most likely cache-hot in that location.
*/
if (cpumask_test_cpu(cpu, lowest_mask)) <<<----------- HERE
return cpu;


Looks to me that lowest_mask is NULL???

Does this happen on boot up? Hmm, could be, by looking at Peter's patch,
he could be waking them up and we are getting into this code before
lowest_mask is defined.

Could you try this patch?

-- Steve

diff --git a/kernel/sched_rt.c b/kernel/sched_rt.c
index 88725c9..46e3e09 100644
--- a/kernel/sched_rt.c
+++ b/kernel/sched_rt.c
@@ -1239,6 +1239,10 @@ static int find_lowest_rq(struct task_struct *task)
int this_cpu = smp_processor_id();
int cpu = task_cpu(task);

+ /* Make sure everything is initialized first */
+ if (system_state != SYSTEM_RUNNING)
+ return -1;
+
if (task->rt.nr_cpus_allowed == 1)
return -1; /* No other targets possible */


2011-06-14 00:05:19

by Andrew Theurer

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Mon, 2011-06-13 at 11:33 -0400, Steven Rostedt wrote:
> On Mon, 2011-06-13 at 10:06 -0500, Andrew Theurer wrote:
> > On Fri, 2011-06-10 at 18:27 +0200, Peter Zijlstra wrote:
> > > On Fri, 2011-06-10 at 10:34 -0500, Andrew Theurer wrote:
> > > > RIP: 0010:[<ffffffff8104e8c1>] [<ffffffff8104e8c1>] find_lowest_rq+0xa1/0x150
> > >
> > > If you've still got the vmlinux around, could you find out where in
> > > find_lowest_rq that RIP is?
> >
> > Does this help?
>
> I take it back, it looks like this does help.
>
> >
> >
> > from objdump -d -S
> >
> > ffffffff8104e820 <find_lowest_rq>:
> > ffffffff8104e820: 55 push %rbp
> > ffffffff8104e821: 48 89 e5 mov %rsp,%rbp
> > ffffffff8104e824: 48 83 ec 30 sub $0x30,%rsp
> > ffffffff8104e828: 48 89 5d d8 mov %rbx,-0x28(%rbp)
> > ffffffff8104e82c: 4c 89 65 e0 mov %r12,-0x20(%rbp)
> > ffffffff8104e830: 4c 89 6d e8 mov %r13,-0x18(%rbp)
> > ffffffff8104e834: 4c 89 75 f0 mov %r14,-0x10(%rbp)
> > ffffffff8104e838: 4c 89 7d f8 mov %r15,-0x8(%rbp)
> > ffffffff8104e83c: e8 3f bf 48 00 callq ffffffff814da780 <mcount>
> > ffffffff8104e841: 48 c7 c0 88 e8 00 00 mov $0xe888,%rax
> > ffffffff8104e848: 65 48 03 04 25 50 dc add %gs:0xdc50,%rax
> > ffffffff8104e84f: 00 00
> > ffffffff8104e851: 65 44 8b 2c 25 58 dc mov %gs:0xdc58,%r13d
> > ffffffff8104e858: 00 00
> > ffffffff8104e85a: 83 bf bc 01 00 00 01 cmpl $0x1,0x1bc(%rdi)
> > ffffffff8104e861: 4c 8b 20 mov (%rax),%r12
> > ffffffff8104e864: 48 8b 47 08 mov 0x8(%rdi),%rax
> > ffffffff8104e868: 8b 58 18 mov 0x18(%rax),%ebx
> > ffffffff8104e86b: 75 23 jne ffffffff8104e890 <find_lowest_rq+0x70>
> > ffffffff8104e86d: b8 ff ff ff ff mov $0xffffffff,%eax
> > ffffffff8104e872: 48 8b 5d d8 mov -0x28(%rbp),%rbx
> > ffffffff8104e876: 4c 8b 65 e0 mov -0x20(%rbp),%r12
> > ffffffff8104e87a: 4c 8b 6d e8 mov -0x18(%rbp),%r13
> > ffffffff8104e87e: 4c 8b 75 f0 mov -0x10(%rbp),%r14
> > ffffffff8104e882: 4c 8b 7d f8 mov -0x8(%rbp),%r15
> > ffffffff8104e886: c9 leaveq
> > ffffffff8104e887: c3 retq
> > ffffffff8104e888: 0f 1f 84 00 00 00 00 nopl 0x0(%rax,%rax,1)
> > ffffffff8104e88f: 00
> > ffffffff8104e890: 89 d8 mov %ebx,%eax
> > ffffffff8104e892: 49 c7 c7 c0 2a 01 00 mov $0x12ac0,%r15
> > ffffffff8104e899: 48 89 fe mov %rdi,%rsi
> > ffffffff8104e89c: 48 8b 04 c5 40 a3 bf mov -0x7e405cc0(,%rax,8),%rax
> > ffffffff8104e8a3: 81
> > ffffffff8104e8a4: 4c 89 e2 mov %r12,%rdx
> > ffffffff8104e8a7: 49 8b 84 07 88 08 00 mov 0x888(%r15,%rax,1),%rax
> > ffffffff8104e8ae: 00
> > ffffffff8104e8af: 48 83 c0 38 add $0x38,%rax
> > ffffffff8104e8b3: 48 89 c7 mov %rax,%rdi
> > ffffffff8104e8b6: e8 85 75 0a 00 callq ffffffff810f5e40 <cpupri_find>
> > ffffffff8104e8bb: 85 c0 test %eax,%eax
> > ffffffff8104e8bd: 74 ae je ffffffff8104e86d <find_lowest_rq+0x4d>
> > ffffffff8104e8bf: 89 d8 mov %ebx,%eax
> > ffffffff8104e8c1: 41 0f a3 1c 24 bt %ebx,(%r12)
>
> Following the asm here, I figured we are here:
>
> static int find_lowest_rq(struct task_struct *task)
> {
> struct sched_domain *sd;
> struct cpumask *lowest_mask = __get_cpu_var(local_cpu_mask);
> int this_cpu = smp_processor_id();
> int cpu = task_cpu(task);
>
> if (task->rt.nr_cpus_allowed == 1)
> return -1; /* No other targets possible */
>
> if (!cpupri_find(&task_rq(task)->rd->cpupri, task, lowest_mask))
> return -1; /* No targets found */
>
> /*
> * At this point we have built a mask of cpus representing the
> * lowest priority tasks in the system. Now we want to elect
> * the best one based on our affinity and topology.
> *
> * We prioritize the last cpu that the task executed on since
> * it is most likely cache-hot in that location.
> */
> if (cpumask_test_cpu(cpu, lowest_mask)) <<<----------- HERE
> return cpu;
>
>
> Looks to me that lowest_mask is NULL???
>
> Does this happen on boot up? Hmm, could be, by looking at Peter's patch,
> he could be waking them up and we are getting into this code before
> lowest_mask is defined.
>
> Could you try this patch?

Yes, and it works! Thanks very much!
>
> -- Steve

-Andrew
>
> diff --git a/kernel/sched_rt.c b/kernel/sched_rt.c
> index 88725c9..46e3e09 100644
> --- a/kernel/sched_rt.c
> +++ b/kernel/sched_rt.c
> @@ -1239,6 +1239,10 @@ static int find_lowest_rq(struct task_struct *task)
> int this_cpu = smp_processor_id();
> int cpu = task_cpu(task);
>
> + /* Make sure everything is initialized first */
> + if (system_state != SYSTEM_RUNNING)
> + return -1;
> +
> if (task->rt.nr_cpus_allowed == 1)
> return -1; /* No other targets possible */
>
>
>

2011-06-14 00:35:46

by Steven Rostedt

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Mon, 2011-06-13 at 19:05 -0500, Andrew Theurer wrote:

> > Could you try this patch?
>
> Yes, and it works! Thanks very much!
> >
> >

Great! I'll make a patch up. Can I add your reported-by and tested-by
tags?

-- Steve

2011-06-14 00:52:24

by Andrew Theurer

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Mon, 2011-06-13 at 20:35 -0400, Steven Rostedt wrote:
> On Mon, 2011-06-13 at 19:05 -0500, Andrew Theurer wrote:
>
> > > Could you try this patch?
> >
> > Yes, and it works! Thanks very much!
> > >
> > >
>
> Great! I'll make a patch up. Can I add your reported-by and tested-by
> tags?

Yes, of course.

-Andrew
>
> -- Steve
>
>

2011-06-14 01:24:46

by Steven Rostedt

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Mon, 2011-06-13 at 19:05 -0500, Andrew Theurer wrote:

> > Could you try this patch?
>
> Yes, and it works! Thanks very much!

Could you try this patch instead? I don't like holding off migration for
the entire boot processes.

-- Steve

diff --git a/kernel/sched_rt.c b/kernel/sched_rt.c
index 88725c9..4505bfb 100644
--- a/kernel/sched_rt.c
+++ b/kernel/sched_rt.c
@@ -1239,6 +1239,10 @@ static int find_lowest_rq(struct task_struct *task)
int this_cpu = smp_processor_id();
int cpu = task_cpu(task);

+ /* Make sure the mask is initialized first */
+ if (unlikely(!lowest_mask))
+ return -1;
+
if (task->rt.nr_cpus_allowed == 1)
return -1; /* No other targets possible */


2011-06-14 02:30:06

by Andrew Theurer

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Mon, 2011-06-13 at 21:24 -0400, Steven Rostedt wrote:
> On Mon, 2011-06-13 at 19:05 -0500, Andrew Theurer wrote:
>
> > > Could you try this patch?
> >
> > Yes, and it works! Thanks very much!
>
> Could you try this patch instead? I don't like holding off migration for
> the entire boot processes.

Sure, just tested this one, and it works fine as well.

-Andrew
>
> -- Steve
>
> diff --git a/kernel/sched_rt.c b/kernel/sched_rt.c
> index 88725c9..4505bfb 100644
> --- a/kernel/sched_rt.c
> +++ b/kernel/sched_rt.c
> @@ -1239,6 +1239,10 @@ static int find_lowest_rq(struct task_struct *task)
> int this_cpu = smp_processor_id();
> int cpu = task_cpu(task);
>
> + /* Make sure the mask is initialized first */
> + if (unlikely(!lowest_mask))
> + return -1;
> +
> if (task->rt.nr_cpus_allowed == 1)
> return -1; /* No other targets possible */
>
>
>

2011-06-14 11:02:30

by Peter Zijlstra

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Mon, 2011-06-13 at 21:24 -0400, Steven Rostedt wrote:
> On Mon, 2011-06-13 at 19:05 -0500, Andrew Theurer wrote:
>
> > > Could you try this patch?
> >
> > Yes, and it works! Thanks very much!
>
> Could you try this patch instead? I don't like holding off migration for
> the entire boot processes.

Great, thanks Steve!, will you be sending this Ingo-wards?

> diff --git a/kernel/sched_rt.c b/kernel/sched_rt.c
> index 88725c9..4505bfb 100644
> --- a/kernel/sched_rt.c
> +++ b/kernel/sched_rt.c
> @@ -1239,6 +1239,10 @@ static int find_lowest_rq(struct task_struct *task)
> int this_cpu = smp_processor_id();
> int cpu = task_cpu(task);
>
> + /* Make sure the mask is initialized first */
> + if (unlikely(!lowest_mask))
> + return -1;
> +
> if (task->rt.nr_cpus_allowed == 1)
> return -1; /* No other targets possible */
>
>
>

2011-06-14 12:25:51

by Steven Rostedt

[permalink] [raw]
Subject: Re: BUG on 3.0-rc on commit d72bce0e67e8afc6eb959f656013cbb577426f1e

On Tue, 2011-06-14 at 13:02 +0200, Peter Zijlstra wrote:
> On Mon, 2011-06-13 at 21:24 -0400, Steven Rostedt wrote:
> > On Mon, 2011-06-13 at 19:05 -0500, Andrew Theurer wrote:
> >
> > > > Could you try this patch?
> > >
> > > Yes, and it works! Thanks very much!
> >
> > Could you try this patch instead? I don't like holding off migration for
> > the entire boot processes.
>
> Great, thanks Steve!, will you be sending this Ingo-wards?
>

Yeah, I'll send it off. I have another small scheduling patch to send
for 3.0.

-- Steve