Tracking down exception in sched.c

Tracking down exception in sched.c

[Mark E Mason]

[Cross-posted from LKML]
 
Hello all,
 
Working from the linux-mip.org repository (which just recently merged
from the kernel.org repository), we've been getting exceptions on
several different processors due to NULL pointer dereferences in
sched.c.  These happen on SMP systems only (but both 32 and 64-bit
systems trigger this problem).
 
The Oops output and surrounding text (w/ backtrace) is below.  What I've
traced is down to so far is that enqueue_task() gets called with a ready
queue (rq) where (rq->active == NULL).

Backtracing a bit, the following patch triggers an earlier, slightly
more controlled failure:

[mason@hawaii linux.git]$ git diff kernel/sched.c diff --git
a/kernel/sched.c b/kernel/sched.c
--- a/kernel/sched.c
+++ b/kernel/sched.c
@@ -1264,6 +1264,7 @@ static int try_to_wake_up(task_t *p, uns  #endif

        rq = task_rq_lock(p, &flags);
+       BUG_ON(rq->active == NULL);
        old_state = p->state;
        if (!(old_state & state))
                goto out;


My question is, is the above assert valid (ie. Should rq->active always
be non-NULL at this point)?  It seems like it should be, but I'm pretty
new to this code, and thought I should double-check before going off
into the weeds.

If anyone has any ideas about where specifically to look for the
underlying problem, I'd appreciate it.

Thanks (very much) in advance,
Mark Mason
mason@broadcom.com
Newberg, Oregon
 
CPU revision is: 03040102
Primary instruction cache 32kB, 4-way, linesize 32 bytes.
Primary data cache 32kB, 4-way, linesize 32 bytes.
Synthesized TLB refill handler (40 instructions).
CPU 0 Unable to handle kernel paging request at virtual address
0000000000000028, epc == ffffffff80129840, ra == ffffffff8010Oops[#1]:
Cpu 0
$ 0   : 0000000000000000 ffffffff804202e0 0000000000000020
0000000000000000
$ 4   : a80000000fe00668 0000000000000000 0000000000000000
0000000000000001
$ 8   : ffffffff80427da0 ffffffff8fef7bc0 ffffffff803ef108
0000000000000000
$12   : ffffffffffffffff ffffffff8024e048 a80000000fe97630
ffffffffffffffff
$16   : 0000000000000000 a80000000fe00668 a800000001385ca0
0000000000000000
$20   : 0000000000000000 a800000001385ca0 0000000000000001
ffffffff804202e0
$24   : 0000000000000000 ffffffff8fe9e3cc
$28   : a80000000fe04000 a80000000fe07e20 a80000000fe07e30
ffffffff80129cc0
Hi    : 00000000000026cc
Lo    : cccccccccc6f7000
epc   : ffffffff80129840 enqueue_task+0x18/0x88     Not tainted
ra    : ffffffff80129cc0 activate_task+0xe0/0x158
Status: 14001fe2    KX SX UX KERNEL EXL
Cause : 00808008
BadVA : 0000000000000028
PrId  : 01040102
Modules linked in:
Process swapper (pid: 1, threadinfo=a80000000fe04000,
task=a80000000fe018c8) Stack : a80000000fe07e30 ffffffff80427400
a800000001385ca0 ffffffff804202e0
        a80000000fe00668 0000000000000001 a80000000fe07e60
ffffffff8012ae80
        0000000014001fe1 0000000000000000 0000000000000000
0000000000000000
        ffffffffffffffff 000000000000000f 0000000000000000
ffffffffffffffff
        ffffffff803a6dc8 0000000000000001 0000000000000001
ffffffff80427d78
        0000000000000000 0000000000000000 0000000000000000
0000000000000000
        a80000000fe07ef0 ffffffff80130dd0 a80000000fe24000
a80000000fe27fe0
        ffffffff803a6dc8 0000000000000001 0000000000000002
ffffffff80427d78
        0000000000000000 0000000000000000 0000000000000000
0000000000000000
        0000000000000000 ffffffff8014c768 0000000000000001
0000000000000001
        ...
Call Trace:
 [<ffffffff8012ae80>] try_to_wake_up+0x530/0x600  [<ffffffff80130dd0>]
migration_call+0x210/0x228  [<ffffffff8014c768>]
notifier_call_chain+0x38/0x78  [<ffffffff8015c404>] cpu_up+0x13c/0x1c8
[<ffffffff80100cf0>] init+0x810/0xb20  [<ffffffff80100568>]
init+0x88/0xb20  [<ffffffff80104c40>] kernel_thread_helper+0x10/0x18
[<ffffffff80104c30>] kernel_thread_helper+0x0/0x18
 

 

Re: Tracking down exception in sched.c

[Rojhalat Ibrahim]

Hi,

I tracked this one down to 88a2a4ac6b671a4b0dd5d2d762418904c05f4104
(percpu data: only iterate over possible CPUs). I don't know if this
is the correct way to fix this, but the following patch makes the
problem go away for me.

--- a/kernel/sched.c
+++ b/kernel/sched.c
@@ -6021,7 +6021,7 @@ void __init sched_init(void)
        runqueue_t *rq;
        int i, j, k;

-       for_each_cpu(i) {
+       for (i = 0; i < NR_CPUS; i++) {
                prio_array_t *array;

                rq = cpu_rq(i);

Any other suggestions, how to fix this?

Thanks,
Rojhalat Ibrahim


Mark E Mason wrote:
> [Cross-posted from LKML]
>  
> Hello all,
>  
> Working from the linux-mip.org repository (which just recently merged
> from the kernel.org repository), we've been getting exceptions on
> several different processors due to NULL pointer dereferences in
> sched.c.  These happen on SMP systems only (but both 32 and 64-bit
> systems trigger this problem).
>  
> The Oops output and surrounding text (w/ backtrace) is below.  What I've
> traced is down to so far is that enqueue_task() gets called with a ready
> queue (rq) where (rq->active == NULL).
> 
> Backtracing a bit, the following patch triggers an earlier, slightly
> more controlled failure:
> 
> [mason@hawaii linux.git]$ git diff kernel/sched.c diff --git
> a/kernel/sched.c b/kernel/sched.c
> --- a/kernel/sched.c
> +++ b/kernel/sched.c
> @@ -1264,6 +1264,7 @@ static int try_to_wake_up(task_t *p, uns  #endif
> 
>         rq = task_rq_lock(p, &flags);
> +       BUG_ON(rq->active == NULL);
>         old_state = p->state;
>         if (!(old_state & state))
>                 goto out;
> 
> 
> My question is, is the above assert valid (ie. Should rq->active always
> be non-NULL at this point)?  It seems like it should be, but I'm pretty
> new to this code, and thought I should double-check before going off
> into the weeds.
> 
> If anyone has any ideas about where specifically to look for the
> underlying problem, I'd appreciate it.
> 
> Thanks (very much) in advance,
> Mark Mason
> mason@broadcom.com
> Newberg, Oregon
>  

Re: Tracking down exception in sched.c

[Kevin D. Kissell]

The "for" loop is what used to be there, but if you use it in
a system with "hot-pluggable" CPUs, I could imagine that there
would be problems.  While for_each_cpu is pathetically inefficient
as it gets expanded and compiled for MIPS, if your phys_cpu_present_map
(which is by default what gets used in MIPS as cpu_possible_map
for the purposes of sched.c) is being properly initialized and
maintained, the behavior of the two loops should be the same.
Have you double-checked that?  Secondary CPUs turn generally
set their bits in that mask in prom_build_cpu_map().

		Regards,

		Kevin K.

Rojhalat Ibrahim wrote:
> Hi,
> 
> I tracked this one down to 88a2a4ac6b671a4b0dd5d2d762418904c05f4104
> (percpu data: only iterate over possible CPUs). I don't know if this
> is the correct way to fix this, but the following patch makes the
> problem go away for me.
> 
> --- a/kernel/sched.c
> +++ b/kernel/sched.c
> @@ -6021,7 +6021,7 @@ void __init sched_init(void)
>         runqueue_t *rq;
>         int i, j, k;
> 
> -       for_each_cpu(i) {
> +       for (i = 0; i < NR_CPUS; i++) {
>                 prio_array_t *array;
> 
>                 rq = cpu_rq(i);
> 
> Any other suggestions, how to fix this?
> 
> Thanks,
> Rojhalat Ibrahim
> 
> 
> Mark E Mason wrote:
>> [Cross-posted from LKML]
>>  
>> Hello all,
>>  
>> Working from the linux-mip.org repository (which just recently merged
>> from the kernel.org repository), we've been getting exceptions on
>> several different processors due to NULL pointer dereferences in
>> sched.c.  These happen on SMP systems only (but both 32 and 64-bit
>> systems trigger this problem).
>>  
>> The Oops output and surrounding text (w/ backtrace) is below.  What I've
>> traced is down to so far is that enqueue_task() gets called with a ready
>> queue (rq) where (rq->active == NULL).
>>
>> Backtracing a bit, the following patch triggers an earlier, slightly
>> more controlled failure:
>>
>> [mason@hawaii linux.git]$ git diff kernel/sched.c diff --git
>> a/kernel/sched.c b/kernel/sched.c
>> --- a/kernel/sched.c
>> +++ b/kernel/sched.c
>> @@ -1264,6 +1264,7 @@ static int try_to_wake_up(task_t *p, uns  #endif
>>
>>         rq = task_rq_lock(p, &flags);
>> +       BUG_ON(rq->active == NULL);
>>         old_state = p->state;
>>         if (!(old_state & state))
>>                 goto out;
>>
>>
>> My question is, is the above assert valid (ie. Should rq->active always
>> be non-NULL at this point)?  It seems like it should be, but I'm pretty
>> new to this code, and thought I should double-check before going off
>> into the weeds.
>>
>> If anyone has any ideas about where specifically to look for the
>> underlying problem, I'd appreciate it.
>>
>> Thanks (very much) in advance,
>> Mark Mason
>> mason@broadcom.com
>> Newberg, Oregon
>>  
> 

Re: Tracking down exception in sched.c

[Rojhalat Ibrahim]

Kevin D. Kissell wrote:
> The "for" loop is what used to be there, but if you use it in
> a system with "hot-pluggable" CPUs, I could imagine that there
> would be problems.  While for_each_cpu is pathetically inefficient
> as it gets expanded and compiled for MIPS, if your phys_cpu_present_map
> (which is by default what gets used in MIPS as cpu_possible_map
> for the purposes of sched.c) is being properly initialized and
> maintained, the behavior of the two loops should be the same.
> Have you double-checked that?  Secondary CPUs turn generally
> set their bits in that mask in prom_build_cpu_map().
> 

The behavior of the two loops is not the same because sched_init
is called long before smp_prepare_cpus. Therefore for_each_cpu
only loops once for CPU 0. I know this is not a great fix.
I simply reverted the code to what's worked before.

Rojhalat Ibrahim

Re: Tracking down exception in sched.c

[Kevin D. Kissell]

> The behavior of the two loops is not the same because sched_init
> is called long before smp_prepare_cpus. Therefore for_each_cpu
> only loops once for CPU 0. I know this is not a great fix.
> I simply reverted the code to what's worked before.

It's certainly the code that I'm still using!  ;o)  So prom_build_cpu_map
needs to be called earlier (as in maybe from smp_prepare_boot_cpu?).
Either that, or each secondary needs to take responsibility for initializing 
its own run queue, but I find the thought of having the system up and
running SMP with some run queues not yet initialized makes me nervous.

        Regards,

        Kevin K.

Re: Tracking down exception in sched.c

[Kevin D. Kissell]

> The behavior of the two loops is not the same because sched_init
> is called long before smp_prepare_cpus. Therefore for_each_cpu
> only loops once for CPU 0. I know this is not a great fix.
> I simply reverted the code to what's worked before.

It's certainly the code that I'm still using!  ;o)  So prom_build_cpu_map
needs to be called earlier (as in maybe from smp_prepare_boot_cpu?).
Either that, or each secondary needs to take responsibility for initializing 
its own run queue, but I find the thought of having the system up and
running SMP with some run queues not yet initialized makes me nervous.

        Regards,

        Kevin K.

Re: Tracking down exception in sched.c

[Kevin D. Kissell]

Kevin D. Kissell wrote:
>> The behavior of the two loops is not the same because sched_init
>> is called long before smp_prepare_cpus. Therefore for_each_cpu
>> only loops once for CPU 0. I know this is not a great fix.
>> I simply reverted the code to what's worked before.
> 
> It's certainly the code that I'm still using!  ;o)  So prom_build_cpu_map
> needs to be called earlier (as in maybe from smp_prepare_boot_cpu?).

OK, when I wrote the above, I was blinded by the fact that I'm personally
doing my SMP (SMTC) work on a downrev development tree, where prom_build_cpu_map()
is still invoked explicitly from smp_prepare_cpus(), just before prom_prepare_cpus().
In those sources, I was able to do what I describe and have the for_each_cpu()
in sched_init() work fine.

But apparently current sources no longer even invoke prom_build_cpu_map(),
having merged that functionality with prom_prepare_cpus(). It looks to me
as if calling prom_prepare_cpus() from smp_prepare_boot_cpu() as in the
patch below, should do the right thing in all current cases, but it *is*
standing the SMP  startup  logic a bit on its head.  Maybe this is why
prom_build_cpu_map() had a separate existence in the first place...

		Regards,

		Kevin K.

diff --git a/arch/mips/kernel/smp.c b/arch/mips/kernel/smp.c
index 5e18986..7ec9579 100644
--- a/arch/mips/kernel/smp.c
+++ b/arch/mips/kernel/smp.c
@@ -236,7 +236,6 @@ void __init smp_prepare_cpus(unsigned in
         init_new_context(current, &init_mm);
         current_thread_info()->cpu = 0;
         smp_tune_scheduling();
-       prom_prepare_cpus(max_cpus);
  }

  /* preload SMP state for boot cpu */
@@ -251,6 +250,8 @@ void __devinit smp_prepare_boot_cpu(void
         cpu_set(0, phys_cpu_present_map);
         cpu_set(0, cpu_online_map);
         cpu_set(0, cpu_callin_map);
+       /* This is done early to populate phys_cpu_present_map for sched_init */
+       prom_prepare_cpus(max_cpus);
  }

  /*

Re: Tracking down exception in sched.c

[Ralf Baechle]

On Mon, Feb 20, 2006 at 09:27:39PM +0100, Kevin D. Kissell wrote:

> But apparently current sources no longer even invoke prom_build_cpu_map(),
> having merged that functionality with prom_prepare_cpus(). It looks to me
> as if calling prom_prepare_cpus() from smp_prepare_boot_cpu() as in the
> patch below, should do the right thing in all current cases, but it *is*
> standing the SMP  startup  logic a bit on its head.  Maybe this is why
> prom_build_cpu_map() had a separate existence in the first place...

Primarily historic reasons actuall.  In 2.4 mips and mips64 used to be
separate and evolution did diverge a bit in the SMP area and this is the
radioactive fallout from it ;-)

> @@ -251,6 +250,8 @@ void __devinit smp_prepare_boot_cpu(void
>         cpu_set(0, phys_cpu_present_map);
>         cpu_set(0, cpu_online_map);
>         cpu_set(0, cpu_callin_map);
> +       /* This is done early to populate phys_cpu_present_map for 
> sched_init */
> +       prom_prepare_cpus(max_cpus);
>  }

Which won't compile because smp_prepare_boot_cpu doesn't define max_cpus.

Anyway, prom_prepare_cpus was running very late and in the past that
was causing problems with firmware which relies on it's mappings still
being alive while the machine had already been taken over by Linux.  The
patch which I cooked up - and haven't yet been able to test yet since my
barrel of midnight oil is about to run out - is calling it from
setup_arch().

  Ralf

Re: Tracking down exception in sched.c

[Kevin D. Kissell]

>... if your phys_cpu_present_map
> (which is by default what gets used in MIPS as cpu_possible_map
> for the purposes of sched.c) is being properly initialized and
> maintained, the behavior of the two loops should be the same.
> Have you double-checked that?  Secondary CPUs turn generally
> set their bits in that mask in prom_build_cpu_map().

Correction.  I misremembered this.  prom_build_cpu_map()
is called only by the primary/boot CPU, prior to SMP initialization.
It's still the place where phys_cpu_present gets set up, but it
can't be set up by the secondaries.

            Regards,

            Kevin K.

Re: Tracking down exception in sched.c

[Kevin D. Kissell]

>... if your phys_cpu_present_map
> (which is by default what gets used in MIPS as cpu_possible_map
> for the purposes of sched.c) is being properly initialized and
> maintained, the behavior of the two loops should be the same.
> Have you double-checked that?  Secondary CPUs turn generally
> set their bits in that mask in prom_build_cpu_map().

Correction.  I misremembered this.  prom_build_cpu_map()
is called only by the primary/boot CPU, prior to SMP initialization.
It's still the place where phys_cpu_present gets set up, but it
can't be set up by the secondaries.

            Regards,

            Kevin K.

Re: Tracking down exception in sched.c

[Ralf Baechle]

On Mon, Feb 20, 2006 at 01:09:12PM +0100, Rojhalat Ibrahim wrote:

> I tracked this one down to 88a2a4ac6b671a4b0dd5d2d762418904c05f4104
> (percpu data: only iterate over possible CPUs). I don't know if this
> is the correct way to fix this, but the following patch makes the
> problem go away for me.
> 
> --- a/kernel/sched.c
> +++ b/kernel/sched.c
> @@ -6021,7 +6021,7 @@ void __init sched_init(void)
>         runqueue_t *rq;
>         int i, j, k;
> 
> -       for_each_cpu(i) {
> +       for (i = 0; i < NR_CPUS; i++) {
>                 prio_array_t *array;
> 
>                 rq = cpu_rq(i);
> 
> Any other suggestions, how to fix this?

Almost certainly wrong - like almost any loop iterating over 0..NR_CPUS.
I'm looking into this now.  Part of what is blowing up is this piece of
legacy code

  #define cpu_possible_map        phys_cpu_present_map

in include/asm-mips/smp.h.  Time to clean that and I fear it's not going
to be pretty ...

  Ralf

Re: Tracking down exception in sched.c

[Kevin D. Kissell]

> > Any other suggestions, how to fix this?
> 
> Almost certainly wrong - like almost any loop iterating over 0..NR_CPUS.
> I'm looking into this now.  Part of what is blowing up is this piece of
> legacy code
> 
>   #define cpu_possible_map        phys_cpu_present_map
> 
> in include/asm-mips/smp.h.  Time to clean that and I fear it's not going
> to be pretty ...

I don't think anything's necessarily broken there except for a lack of 
documentation. That #define will presumably go away once hot-plug support 
is fully in, but the fact that the boot code sets up a phys_cpu_present_map 
is perfectly reasonable, and equating that to cpu_possible_map for the purposes 
of sched.c is simple and efficient.  Whatever name it has, if the platform code 
doesn't correctly initialize and maintain the map, Bad Things will clearly happen. 
I'm not sure how we can actually prevent this.  It pretty much has to be
platform-specific code that determines whether a given CPU is present
in a hardware configuration.

            Regards,

            Kevin K.

Re: Tracking down exception in sched.c

[Kevin D. Kissell]

> > Any other suggestions, how to fix this?
> 
> Almost certainly wrong - like almost any loop iterating over 0..NR_CPUS.
> I'm looking into this now.  Part of what is blowing up is this piece of
> legacy code
> 
>   #define cpu_possible_map        phys_cpu_present_map
> 
> in include/asm-mips/smp.h.  Time to clean that and I fear it's not going
> to be pretty ...

I don't think anything's necessarily broken there except for a lack of 
documentation. That #define will presumably go away once hot-plug support 
is fully in, but the fact that the boot code sets up a phys_cpu_present_map 
is perfectly reasonable, and equating that to cpu_possible_map for the purposes 
of sched.c is simple and efficient.  Whatever name it has, if the platform code 
doesn't correctly initialize and maintain the map, Bad Things will clearly happen. 
I'm not sure how we can actually prevent this.  It pretty much has to be
platform-specific code that determines whether a given CPU is present
in a hardware configuration.

            Regards,

            Kevin K.