Skip to contentSkip to conversation

Oops in find_busiest_group(): 2.6.8-rc1-mm1

DISCUSSION Dave Hansen 5 participants 9 messages Jul 15, 2004 – Jul 29, 2004

lore
Share & tools
lore
#0 lore raw

Looks like 'find_busiest_group()::this' is null:

cpu 0x1: Vector: 380 (Data SLB Access) at [c0000002ffe0b420]

    pc: c000000000046644: .find_busiest_group+0x24c/0x470
    lr: c00000000004681c: .find_busiest_group+0x424/0x470
    sp: c0000002ffe0b6a0

msr: 8000000000001032
dar: 10
current = 0xc0000002fff70da0
paca = 0xc00000000033c900
pid = 0, comm = swapper
...
1:mon> r

R00 = 0000000000000080   R16 = 0000000000000080
R01 = c0000002ffe0b6a0   R17 = 0000000000000080
R02 = c0000000004a5470   R18 = 0000000000000080
R03 = 0000000000000046   R19 = c00000000adfb408
R04 = c00000000050dd27   R20 = 0000000000000001
R05 = c00000000052dd50   R21 = 0000000000000000
R06 = c0000000003b7828   R22 = 0000000000000000
R07 = fffffffffffe0cb8   R23 = c0000002ffe0b710
R08 = c00000000050d180   R24 = c0000000004a2008
R09 = c00000000050d918   R25 = c000000000330c38
R10 = 0000000000000000   R26 = c000000000330c38
R11 = 0000000000000001   R27 = 0000000000000001
R12 = 0000000000000010   R28 = c00000000050d198
R13 = c00000000033c900   R29 = 0000000000000080
R14 = 0000000000000000   R30 = c0000000003c29e8
R15 = c000000000330c38   R31 = c0000002ffe0b6a0

pc = c000000000046644 .find_busiest_group+0x24c/0x470 lr = c00000000004681c .find_busiest_group+0x424/0x470
msr = 8000000000001032 cr = 88428428
ctr = c0000000001527a8 xer = 0000000000000000 trap = 380

I put a little printk in:

        /* How much load to actually move to equalise the imbalance */
        if (!busiest || !this)
                printk("%s() busiest: %p this: %p\n", __func__, busiest, this);
        *imbalance = (*imbalance * min(busiest->cpu_power, this->cpu_power))
                                / SCHED_LOAD_SCALE;

And sure enough, this showed up on the console:

find_busiest_group() busiest: c00000000050d180 this: 0000000000000000

This code also looks funny to begin with:

Quoted 11 lines
                if (local_group) {
                        this_load = avg_load;
                        this = group;
                        goto nextgroup;
                } else if (avg_load > max_load) {
                        max_load = avg_load;
                        busiest = group;
                }
nextgroup:
                group = group->next;
        } while (group != sd->groups);

Why bother with the 'goto nextgroup;'? Shouldn't the first if block just fall through to the target of the goto anyway?

-- Dave

#1 lore raw
Quoted 42 lines · Dave Hansen

Looks like 'find_busiest_group()::this' is null:

cpu 0x1: Vector: 380 (Data SLB Access) at [c0000002ffe0b420]

    pc: c000000000046644: .find_busiest_group+0x24c/0x470
    lr: c00000000004681c: .find_busiest_group+0x424/0x470
    sp: c0000002ffe0b6a0

msr: 8000000000001032
dar: 10
current = 0xc0000002fff70da0
paca = 0xc00000000033c900
pid = 0, comm = swapper
...
1:mon> r

R00 = 0000000000000080   R16 = 0000000000000080
R01 = c0000002ffe0b6a0   R17 = 0000000000000080
R02 = c0000000004a5470   R18 = 0000000000000080
R03 = 0000000000000046   R19 = c00000000adfb408
R04 = c00000000050dd27   R20 = 0000000000000001
R05 = c00000000052dd50   R21 = 0000000000000000
R06 = c0000000003b7828   R22 = 0000000000000000
R07 = fffffffffffe0cb8   R23 = c0000002ffe0b710
R08 = c00000000050d180   R24 = c0000000004a2008
R09 = c00000000050d918   R25 = c000000000330c38
R10 = 0000000000000000   R26 = c000000000330c38
R11 = 0000000000000001   R27 = 0000000000000001
R12 = 0000000000000010   R28 = c00000000050d198
R13 = c00000000033c900   R29 = 0000000000000080
R14 = 0000000000000000   R30 = c0000000003c29e8
R15 = c000000000330c38   R31 = c0000002ffe0b6a0

pc = c000000000046644 .find_busiest_group+0x24c/0x470 lr = c00000000004681c .find_busiest_group+0x424/0x470
msr = 8000000000001032 cr = 88428428
ctr = c0000000001527a8 xer = 0000000000000000 trap = 380

I put a little printk in:

        /* How much load to actually move to equalise the imbalance */
        if (!busiest || !this)
                printk("%s() busiest: %p this: %p\n", __func__, busiest, this);
        *imbalance = (*imbalance * min(busiest->cpu_power, this->cpu_power))
                                / SCHED_LOAD_SCALE;
Quoted 4 lines

And sure enough, this showed up on the console:

find_busiest_group() busiest: c00000000050d180 this: 0000000000000000

OK, it is overdue for a bit of an audit anyway, so I'll see if I can see what is going wrong.

Quoted 16 lines

This code also looks funny to begin with:

Quoted 11 lines
               if (local_group) {
                       this_load = avg_load;
                       this = group;
                       goto nextgroup;
               } else if (avg_load > max_load) {
                       max_load = avg_load;
                       busiest = group;
               }
nextgroup:
               group = group->next;
       } while (group != sd->groups);
Quoted 3 lines

Why bother with the 'goto nextgroup;'? Shouldn't the first if block just fall through to the target of the goto anyway?

It was there for a good reason once... obviously no point to it now. Thanks for the report.

#2 lore raw
In reply to Dave Hansen

I just hit what might be the same oops.

I had not upgraded my working kernel for a month, and just now, when I upgraded to 2.6.8-rc2-mm1, running sn2_defconfig on a small SN2 system, it fails to boot everytime, ending with an Oops that starts out with:

======================================================
Freeing unused kernel memory: 320kB freed

Unable to handle kernel NULL pointer dereference (address 0000000000000008)
swapper[0]: Oops 8813272891392 [1]
Modules linked in:

Pid: 0, CPU 0, comm: swapper
psr : 0000101008022018 ifs : 8000000000000e20 ip : [<a0000001000bd710>] Not tainted
ip is at find_busiest_group+0xb0/0x640
======================================================

I added a conditional printk_ratelimit'ed print at the top of find_busiest_group() whenever group is NULL, just before the first dereference of group in the line:

	local_group = cpu_isset(this_cpu, group->cpumask);

That print fires about 20,480 times each 5 second suppression window.

But it boots, if I also add code to break out of the "do { ... } while (group != sd->groups)" loop, whenever group goes NULL.

Signature · 3 lines
                          I won't rest till it's the best ...
                          Programmer, Linux Scalability
                          Paul Jackson <[email protected]> 1.650.933.1373
#3 lore raw
Quoted 21 lines · Paul Jackson

I just hit what might be the same oops.

I had not upgraded my working kernel for a month, and just now, when I upgraded to 2.6.8-rc2-mm1, running sn2_defconfig on a small SN2 system, it fails to boot everytime, ending with an Oops that starts out with:

======================================================
Freeing unused kernel memory: 320kB freed

Unable to handle kernel NULL pointer dereference (address 0000000000000008)
swapper[0]: Oops 8813272891392 [1]
Modules linked in:

Pid: 0, CPU 0, comm: swapper
psr : 0000101008022018 ifs : 8000000000000e20 ip : [<a0000001000bd710>] Not tainted
ip is at find_busiest_group+0xb0/0x640
======================================================

I added a conditional printk_ratelimit'ed print at the top of find_busiest_group() whenever group is NULL, just before the first dereference of group in the line:

Quoted 8 lines
	local_group = cpu_isset(this_cpu, group->cpumask);

That print fires about 20,480 times each 5 second suppression window.

But it boots, if I also add code to break out of the "do { ... } while (group != sd->groups)" loop, whenever group goes NULL.

OK, I still can't work out why this is happening. Can you try with 2.6.8-rc2-mm1? Does it happen continually after the system has booted? If it happens in 2.6.8-rc2-mm1, comment out the call to cpu_attach_domain in kernel/sched.c (so you'll only be using the dummy boot-up domain). Does that fix it?

#4 lore raw
Quoted 1 line · Nick

Can you try with 2.6.8-rc2-mm1?

This _is_ with 2.6.8-rc2-mm1.

Quoted 1 line

Does it happen continually after the system has booted?

Yes - nonstop - 4 times per millisecond, for at least as long as the machine has been up (I'm rebooting every few minutes, for other reasons ...).

Quoted 1 line

comment out the call to cpu_attach_domain ... Does that fix it?

Yes - that fixes it. My ratelimited printks on NULL group cease.

Signature · 3 lines
                          I won't rest till it's the best ...
                          Programmer, Linux Scalability
                          Paul Jackson <[email protected]> 1.650.933.1373
#5 lore raw
Quoted 16 lines · Paul Jackson
Quoted 1 line · Nick

Can you try with 2.6.8-rc2-mm1?

This _is_ with 2.6.8-rc2-mm1.

Quoted 1 line

Does it happen continually after the system has booted?

Yes - nonstop - 4 times per millisecond, for at least as long as the machine has been up (I'm rebooting every few minutes, for other reasons ...).

Quoted 5 lines
Quoted 1 line

comment out the call to cpu_attach_domain ... Does that fix it?

Yes - that fixes it. My ratelimited printks on NULL group cease.

Hmm, nothing else seems to be oopsing. Maybe it is the ia64 domain setup code that Jesse did? The domains/groups must not have been built properly somewhere.

#7 lore raw
In reply to Nick Piggin
Quoted 3 lines · Nick Piggin

Hmm, nothing else seems to be oopsing. Maybe it is the ia64 domain setup code that Jesse did? The domains/groups must not have been built properly somewhere.

Here's a patch to 2.6.8-rc2-mm1 that allows things to work:

sched.c 2004-07-29 10:27:58.000000000 -0500 renamed from sched.c.old 2004-07-29 10:11:00.000000000 -0500 +0 -2
@@ -3770,8 +3770,6 @@ __init static void arch_init_sched_domai
                cpumask_t nodemask = node_to_cpumask(cpu_to_node(i));
 
 #ifdef CONFIG_NUMA
-               if (i != first_cpu(sd->groups->cpumask))
-                       continue;
                sd = &per_cpu(node_domains, i);
                group = cpu_to_node_group(i);
                *sd = SD_NODE_INIT;
#8 lore raw

sched.c 2004-07-29 10:27:58.000000000 -0500 __init static void arch_init_sched_domai · line 3775

Quoted 13 lines · Dimitri Sivanich

Here's a patch to 2.6.8-rc2-mm1 that allows things to work:

sched.c 2004-07-29 10:27:58.000000000 -0500 renamed from sched.c.old 2004-07-29 10:11:00.000000000 -0500 +0 -2
@@ -3770,8 +3770,6 @@ __init static void arch_init_sched_domai
                cpumask_t nodemask = node_to_cpumask(cpu_to_node(i));
 
 #ifdef CONFIG_NUMA
-               if (i != first_cpu(sd->groups->cpumask))
-                       continue;
                sd = &per_cpu(node_domains, i);
                group = cpu_to_node_group(i);
                *sd = SD_NODE_INIT;

Yep, this was a merge error. I posted it as the first reply (f1rst p0st!) to Andrew's 2.6.8-rc2-mm1 announcement. Sorry for the trouble, my last patch didn't include it, but there was some confusion since there were several fixes to the scheduler code posted to Nick's 'consolidate sched domains' thread.

Jesse