preempt_count corruption across H_CEDE call with CONFIG_PREEMPT on pseries

The following patch is most certainly not correct, but it does eliminate the situation on mainline 100% of the time (there is still a 25% reproduction rate on PREEMPT_RT). Can someone comment on:

Also of interest is that this path cpu_idle()->cpu_die()->pseries_mach_cpu_die() to start_secondary() enters with a preempt_count=1 if it wasn't corrupted across the hcall.

The early boot path from _start however appears to call start_secondary() with a preempt_count of 0.

The following patch is most certainly not correct, but it does eliminate

the situation on mainline 100% of the time (there is still a 25% reproduction rate on PREEMPT_RT).

2) Should we call preempt_enable() in cpu_idle() prior to cpu_die() ?

Quoted 3 lines · Darren Hart

Also of interest is that this path cpu_idle()->cpu_die()->pseries_mach_cpu_die() to start_secondary() enters with a preempt_count=1 if it wasn't corrupted across the hcall.

That triggers the problem as well. preempt_count needs to be 0 when entering start_secondary(). So I really wonder how that ever worked.

Quoted 2 lines

The early boot path from _start however appears to call start_secondary() with a preempt_count of 0.

Which is correct.

Quoted 1 line

The following patch is most certainly not correct, but it does eliminate

It is correct, but i think it is incomplete as other portions of the thread_info on the stack might be in some weird state as well.

1) How can the preempt_count() get mangled across the H_CEDE hcall?
2) Should we call preempt_enable() in cpu_idle() prior to cpu_die() ?

Quoted 3 lines · Darren Hart

1) How can the preempt_count() get mangled across the H_CEDE hcall?
2) Should we call preempt_enable() in cpu_idle() prior to cpu_die() ?

The preempt count is on the thread info at the bottom of the stack.

Can you check the stack pointers ?

Quoted 8 lines · Benjamin Herrenschmidt

Quoted 3 lines · Darren Hart

1) How can the preempt_count() get mangled across the H_CEDE hcall?
2) Should we call preempt_enable() in cpu_idle() prior to cpu_die() ?

The preempt count is on the thread info at the bottom of the stack.

Can you check the stack pointers ?

Hi Ben, thanks for looking.

I instrumented the area around extended_cede_processor() as follows (please confirm I'm getting the stack pointer correctly).

while (get_preferred_offline_state(cpu) == CPU_STATE_INACTIVE) {
	asm("mr %0,1" : "=r" (sp));
	printk("before H_CEDE current->stack: %lx, pcnt: %x\n", sp, preempt_count());
	extended_cede_processor(cede_latency_hint);
	asm("mr %0,1" : "=r" (sp));
	printk("after H_CEDE current->stack: %lx, pcnt: %x\n", sp, preempt_count());

}

On Mainline (2.6.33.6, CONFIG_PREEMPT=y) I see this:

Jul 22 18:37:08 igoort1 kernel: before H_CEDE current->stack: c00000010e9e3ce0, pcnt: 1
Jul 22 18:37:08 igoort1 kernel: after H_CEDE current->stack:  c00000010e9e3ce0, pcnt: 1

This surprised me as preempt_count is 1 before and after, so no corruption appears to occur on mainline. This makes the pcnt of 65 I see without the preempt_count()=0 hack very strange. I ran several hundred off/on cycles. The issue of preempt_count being 1 is still addressed by this patch however.

On PREEMPT_RT (2.6.33.5-rt23 - tglx, sorry, rt/2.6.33 next time, promise):

Jul 22 18:51:11 igoort1 kernel: before H_CEDE current->stack: c000000089bcfcf0, pcnt: 1
Jul 22 18:51:11 igoort1 kernel: after H_CEDE current->stack:  c000000089bcfcf0, pcnt: ffffffff

In both cases the stack pointer appears unchanged.

Note: there is a BUG triggered in between these statements as the preempt_count causes the printk to trigger:
Badness at kernel/sched.c:5572

Quoted 35 lines · Darren Hart

Quoted 8 lines · Benjamin Herrenschmidt

Quoted 3 lines · Darren Hart

1) How can the preempt_count() get mangled across the H_CEDE hcall?
2) Should we call preempt_enable() in cpu_idle() prior to cpu_die() ?

The preempt count is on the thread info at the bottom of the stack.

Can you check the stack pointers ?

Hi Ben, thanks for looking.

I instrumented the area around extended_cede_processor() as follows (please confirm I'm getting the stack pointer correctly).

while (get_preferred_offline_state(cpu) == CPU_STATE_INACTIVE) {
	asm("mr %0,1" : "=r" (sp));
	printk("before H_CEDE current->stack: %lx, pcnt: %x\n", sp, preempt_count());
	extended_cede_processor(cede_latency_hint);
	asm("mr %0,1" : "=r" (sp));
	printk("after H_CEDE current->stack: %lx, pcnt: %x\n", sp, preempt_count());

}

On Mainline (2.6.33.6, CONFIG_PREEMPT=y) I see this:

Jul 22 18:37:08 igoort1 kernel: before H_CEDE current->stack: c00000010e9e3ce0, pcnt: 1
Jul 22 18:37:08 igoort1 kernel: after H_CEDE current->stack:  c00000010e9e3ce0, pcnt: 1

This surprised me as preempt_count is 1 before and after, so no corruption appears to occur on mainline. This makes the pcnt of 65 I see without the preempt_count()=0 hack very strange. I ran several hundred off/on cycles. The issue of preempt_count being 1 is still addressed by this patch however.

On PREEMPT_RT (2.6.33.5-rt23 - tglx, sorry, rt/2.6.33 next time, promise):

Quoted 8 lines

Jul 22 18:51:11 igoort1 kernel: before H_CEDE current->stack: c000000089bcfcf0, pcnt: 1
Jul 22 18:51:11 igoort1 kernel: after H_CEDE current->stack:  c000000089bcfcf0, pcnt: ffffffff

In both cases the stack pointer appears unchanged.

Note: there is a BUG triggered in between these statements as the preempt_count causes the printk to trigger:
Badness at kernel/sched.c:5572

At Steven's suggestion I updated the instrumentation to display the local_save_flags and irqs_disabled_flags:

while (get_preferred_offline_state(cpu) == CPU_STATE_INACTIVE) {
        local_save_flags(flags);
        printk("local flags: %lx, irqs disabled: %d\n", flags, irqs_disabled_flags(flags));
        asm("mr %0,1" : "=r" (sp));
        printk("before H_CEDE current->stack: %lx, pcnt: %x\n", sp, preempt_count());
        extended_cede_processor(cede_latency_hint);
        asm("mr %0,1" : "=r" (sp));
        printk("after H_CEDE current->stack: %lx, pcnt: %x\n", sp, preempt_count());
}

Jul 22 23:36:58 igoort1 kernel: local flags: 0, irqs disabled: 1
Jul 22 23:36:58 igoort1 kernel: before H_CEDE current->stack: c00000010e9e3ce0, pcnt: 1
Jul 22 23:36:58 igoort1 kernel: after H_CEDE current->stack: c00000010e9e3ce0, pcnt: 1

I'm not sure if I'm reading that right, but I believe interrupts are intended to be disabled here. If accomplished via the spin_lock_irqsave() this would behave differently on RT. However, this path disables the interrupts handled by xics, all but the IPIs anyway. On RT I disabled the decrementer as well.

Is it possible for RT to be receiving other interrupts here?

Yes. extended_cede_processor() will return with interrupts enabled in the cpu. (This is done by the hypervisor). Under normal cases we cannot be interrupted because no IO interrupts are routed to us after xics_teardown_cpu() and since the CPU is out of the map, nobody will send us IPIs.

Though H_CEDE will return with interrupts enabled, it is unlikely that an interrupt can be delivered in this context.

Quoted 5 lines · Vaidyanathan Srinivasan

Yes. extended_cede_processor() will return with interrupts enabled in the cpu. (This is done by the hypervisor). Under normal cases we cannot be interrupted because no IO interrupts are routed to us after xics_teardown_cpu() and since the CPU is out of the map, nobody will send us IPIs.

What about decrementer ?

Quoted 2 lines

Though H_CEDE will return with interrupts enabled, it is unlikely that an interrupt can be delivered in this context.

Well, if interrupts are soft-disabled, even if one occurs, we will just mask and return, so that at least should be ok.

Quoted 7 lines · Benjamin Herrenschmidt

Quoted 5 lines · Vaidyanathan Srinivasan

Yes. extended_cede_processor() will return with interrupts enabled in the cpu. (This is done by the hypervisor). Under normal cases we cannot be interrupted because no IO interrupts are routed to us after xics_teardown_cpu() and since the CPU is out of the map, nobody will send us IPIs.

Quoted 1 line

What about decrementer ?

Decrementer expiry event handling is bit complex. The event as such may not bring back the extended_cede_processor() cpu, but may be marked pending when we get out of this state eventually. I will find more information on this event and update.

Quoted 6 lines

Quoted 3 lines

Though H_CEDE will return with interrupts enabled, it is unlikely that an interrupt can be delivered in this context.

Well, if interrupts are soft-disabled, even if one occurs, we will just mask and return, so that at least should be ok.

Yes. We will immediately return to the extended_cede_processor() in the while loop until the preferred_offline_state is changed.

--Vaidy

Quoted 11 lines · Vaidyanathan Srinivasan

Quoted 8 lines · Benjamin Herrenschmidt

Quoted 5 lines · Vaidyanathan Srinivasan

Yes. extended_cede_processor() will return with interrupts enabled in the cpu. (This is done by the hypervisor). Under normal cases we cannot be interrupted because no IO interrupts are routed to us after xics_teardown_cpu() and since the CPU is out of the map, nobody will send us IPIs.

What about decrementer ?

Quoted 4 lines

Decrementer expiry event handling is bit complex. The event as such may not bring back the extended_cede_processor() cpu, but may be marked pending when we get out of this state eventually. I will find more information on this event and update.

Hi Vaidy, have you been able to dig anything up about the decrementer expiry?

Quoted 17 lines · Darren Hart

Quoted 15 lines · Vaidyanathan Srinivasan

Quoted 8 lines · Benjamin Herrenschmidt

Quoted 5 lines · Vaidyanathan Srinivasan

Yes. extended_cede_processor() will return with interrupts enabled in the cpu. (This is done by the hypervisor). Under normal cases we cannot be interrupted because no IO interrupts are routed to us after xics_teardown_cpu() and since the CPU is out of the map, nobody will send us IPIs.

What about decrementer ?

Decrementer expiry event handling is bit complex. The event as such may not bring back the extended_cede_processor() cpu, but may be marked pending when we get out of this state eventually. I will find more information on this event and update.

Quoted 2 lines

Hi Vaidy, have you been able to dig anything up about the decrementer expiry?

Hi Darren,

Yes, it is possible that the cpu in extended_cede_processor() can be woken up by the decrementer. But the expectation is that we will return back to this context since we will not have any pending timers.

Our stack should not change even if we get the decrementer interrupts.

suggestion I updated the instrumentation to display the
local_save_flags and irqs_disabled_flags:

Jul 22 23:36:58 igoort1 kernel: local flags: 0, irqs disabled: 1
Jul 22 23:36:58 igoort1 kernel: before H_CEDE current->stack: c00000010e9e3ce0, pcnt: 1
Jul 22 23:36:58 igoort1 kernel: after H_CEDE current->stack: c00000010e9e3ce0, pcnt: 1

I'm not sure if I'm reading that right, but I believe interrupts are intended to be disabled here. If accomplished via the spin_lock_irqsave() this would behave differently on RT. However, this path disables the interrupts handled by xics, all but the IPIs anyway. On RT I disabled the decrementer as well.

Is it possible for RT to be receiving other interrupts here?

Quoted 13 lines · Darren Hart

suggestion I updated the instrumentation to display the
local_save_flags and irqs_disabled_flags:

Jul 22 23:36:58 igoort1 kernel: local flags: 0, irqs disabled: 1
Jul 22 23:36:58 igoort1 kernel: before H_CEDE current->stack: c00000010e9e3ce0, pcnt: 1
Jul 22 23:36:58 igoort1 kernel: after H_CEDE current->stack: c00000010e9e3ce0, pcnt: 1

I'm not sure if I'm reading that right, but I believe interrupts are intended to be disabled here. If accomplished via the spin_lock_irqsave() this would behave differently on RT. However, this path disables the interrupts handled by xics, all but the IPIs anyway. On RT I disabled the decrementer as well.

Quoted 1 line

Is it possible for RT to be receiving other interrupts here?

Also you may want to call hard_irq_disable() to -really- disable interrupts ... since we do lazy-disable on powerpc

Quoted 15 lines · Benjamin Herrenschmidt

Quoted 13 lines · Darren Hart

suggestion I updated the instrumentation to display the
local_save_flags and irqs_disabled_flags:

Jul 22 23:36:58 igoort1 kernel: local flags: 0, irqs disabled: 1
Jul 22 23:36:58 igoort1 kernel: before H_CEDE current->stack: c00000010e9e3ce0, pcnt: 1
Jul 22 23:36:58 igoort1 kernel: after H_CEDE current->stack: c00000010e9e3ce0, pcnt: 1

I'm not sure if I'm reading that right, but I believe interrupts are intended to be disabled here. If accomplished via the spin_lock_irqsave() this would behave differently on RT. However, this path disables the interrupts handled by xics, all but the IPIs anyway. On RT I disabled the decrementer as well.

Quoted 5 lines

Quoted 1 line

Is it possible for RT to be receiving other interrupts here?

Also you may want to call hard_irq_disable() to -really- disable interrupts ... since we do lazy-disable on powerpc

A quick update and request for direction wrt the cede hcall, interrupt handling, and the stack pointer.

I've added patches one at a time, eliminating bugs with preempt_rt (tip/rt/head). With my current patchset I have no crashes with a single run of random_online.sh (stress testing to hit the hang will sees is my todo for tomorrow).

Current patchset includes:
patches/0001-wms-fix01.patch # P7 lazy flushing thing

# next four are sent to / queued for mainline
patches/powerpc-increase-pseries_cpu_die-delay.patch
patches/powerpc-enable-preemption-before-cpu_die.patch
patches/powerpc-silence-__cpu_up-under-normal-operation.patch
patches/powerpc-silence-xics_migrate_irqs_away-during-cpu-offline.patch

# this one needs to be cleaned up and sent to mainline
patches/powerpc-wait-for-cpu-to-go-inactive.patch

patches/powerpc-disable-decrementer-on-offline.patch patches/powerpc-cpu_die-preempt-hack.patch # reset preempt_count to 0 after cede patches/powerpc-cede-processor-inst.patch # instrumentation patches/powerpc-hard_irq_disable.patch # hard_irq_disable before cede patches/powerpc-pad-thread_info.patch

I didn't include all the patches as the relevant bits are included below in code form.

With the instrumentation, it's clear the change to preempt_count() is targeted (since I added padding before and after preempt_count in the thread_info struct) and preempt_count is still changed. It is also clear that it isn't just a stray decrement since I set preempt_count() to 4 prior to calling cede and it still is 0xffffffff after the hcall. Also note that the stack pointer doesn't change across the cede call and neither does any other part of the thread_info structure.

Adding hard_irq_disable() did seem to affect things somewhat. Rather than a serialized list of before/after thread_info prints around cede, I see several befores then several afters. But the preempt_count is still modified.

The relevant code looks like this (from pseries_mach_cpu_die())

                        hard_irq_disable(); /* this doesn't fix things... but
			                       does change behavior a bit */
                        preempt_count() = 0x4; 
                        asm("mr %0,1" : "=r" (sp));  /* stack pointer is in R1 */
                        printk("before cede: sp=%lx pcnt=%x\n", sp, preempt_count()); 
                        print_thread_info(); 
                        extended_cede_processor(cede_latency_hint); 
                        asm("mr %0,1" : "=r" (sp)); 
                        printk("after cede: sp=%lx pcnt=%x\n", sp, preempt_count()); 
                        print_thread_info(); 
                        preempt_count() = 0; 

With these patches applied, the output across cede looks like:

before cede: sp=c000000000b57150 pcnt=4
*** current->thread_info ***
ti->task: c000000000aa1410
ti->exec_domain: c000000000a59958
ti->cpu: 0
ti->stomp_on_me: 57005 /* 0xDEAD - forgot to print in hex */ ti->preempt_count: 4
ti->stomp_on_me_too: 48879 /* 0xBEEF - forgot to print in hex */ ti->local_flags: 0
*** end thread_info ***
after cede: sp=c000000000b57150 pcnt=ffffffff
*** current->thread_info ***
ti->task: c000000000aa1410
ti->exec_domain: c000000000a59958
ti->cpu: 0

ti->stomp_on_me: 57005
ti->preempt_count: ffffffff
ti->stomp_on_me_too: 48879
ti->local_flags: 0

*** end thread_info ***

Are there any additional thoughts on what might be causing preempt_count to change? I was thinking that cede might somehow force it to 0 (or perhaps one of the preempt_count explicit value setters in irq.c) and then decrement it - but that dec should trigger an error in the dec_preempt_count() as I have CONFIG_DEBUG_PREEMPT=y.

Quoted 79 lines · Darren Hart

Quoted 15 lines · Benjamin Herrenschmidt

Quoted 13 lines · Darren Hart

suggestion I updated the instrumentation to display the
local_save_flags and irqs_disabled_flags:

Jul 22 23:36:58 igoort1 kernel: local flags: 0, irqs disabled: 1
Jul 22 23:36:58 igoort1 kernel: before H_CEDE current->stack: c00000010e9e3ce0, pcnt: 1
Jul 22 23:36:58 igoort1 kernel: after H_CEDE current->stack: c00000010e9e3ce0, pcnt: 1

I'm not sure if I'm reading that right, but I believe interrupts are intended to be disabled here. If accomplished via the spin_lock_irqsave() this would behave differently on RT. However, this path disables the interrupts handled by xics, all but the IPIs anyway. On RT I disabled the decrementer as well.

Quoted 5 lines

Quoted 1 line

Is it possible for RT to be receiving other interrupts here?

Also you may want to call hard_irq_disable() to -really- disable interrupts ... since we do lazy-disable on powerpc

A quick update and request for direction wrt the cede hcall, interrupt handling, and the stack pointer.

I've added patches one at a time, eliminating bugs with preempt_rt (tip/rt/head). With my current patchset I have no crashes with a single run of random_online.sh (stress testing to hit the hang will sees is my todo for tomorrow).

Current patchset includes:
patches/0001-wms-fix01.patch # P7 lazy flushing thing

# next four are sent to / queued for mainline
patches/powerpc-increase-pseries_cpu_die-delay.patch
patches/powerpc-enable-preemption-before-cpu_die.patch
patches/powerpc-silence-__cpu_up-under-normal-operation.patch
patches/powerpc-silence-xics_migrate_irqs_away-during-cpu-offline.patch

# this one needs to be cleaned up and sent to mainline
patches/powerpc-wait-for-cpu-to-go-inactive.patch

patches/powerpc-disable-decrementer-on-offline.patch patches/powerpc-cpu_die-preempt-hack.patch # reset preempt_count to 0 after cede patches/powerpc-cede-processor-inst.patch # instrumentation patches/powerpc-hard_irq_disable.patch # hard_irq_disable before cede patches/powerpc-pad-thread_info.patch

I didn't include all the patches as the relevant bits are included below in code form.

With the instrumentation, it's clear the change to preempt_count() is targeted (since I added padding before and after preempt_count in the thread_info struct) and preempt_count is still changed. It is also clear that it isn't just a stray decrement since I set preempt_count() to 4 prior to calling cede and it still is 0xffffffff after the hcall. Also note that the stack pointer doesn't change across the cede call and neither does any other part of the thread_info structure.

Adding hard_irq_disable() did seem to affect things somewhat. Rather than a serialized list of before/after thread_info prints around cede, I see several befores then several afters. But the preempt_count is still modified.

The relevant code looks like this (from pseries_mach_cpu_die())

                         hard_irq_disable(); /* this doesn't fix things... but
			                       does change behavior a bit */
                         preempt_count() = 0x4;
                         asm("mr %0,1" : "=r" (sp));  /* stack pointer is in R1 */
                         printk("before cede: sp=%lx pcnt=%x\n", sp, preempt_count());
                         print_thread_info();
                         extended_cede_processor(cede_latency_hint);
                         asm("mr %0,1" : "=r" (sp));
                         printk("after cede: sp=%lx pcnt=%x\n", sp, preempt_count());
                         print_thread_info();
                         preempt_count() = 0;

With these patches applied, the output across cede looks like:

Quoted 15 lines

before cede: sp=c000000000b57150 pcnt=4
*** current->thread_info ***
ti->task: c000000000aa1410
ti->exec_domain: c000000000a59958
ti->cpu: 0
ti->stomp_on_me: 57005 /* 0xDEAD - forgot to print in hex */ ti->preempt_count: 4
ti->stomp_on_me_too: 48879 /* 0xBEEF - forgot to print in hex */ ti->local_flags: 0
*** end thread_info ***
after cede: sp=c000000000b57150 pcnt=ffffffff
*** current->thread_info ***
ti->task: c000000000aa1410
ti->exec_domain: c000000000a59958
ti->cpu: 0

Is this print sufficient to prove that we did not jump CPU?

We agree that decrementer can possibly expire and we could have gone to the handler and come back just like we would do in an idle loop.

This will not happen always, but I could see a window of time during which this may happen. But that should not change the preempt_count unconditionally to -1 with the same stack pointer.

Quoted 4 lines

ti->stomp_on_me: 57005
ti->preempt_count: ffffffff
ti->stomp_on_me_too: 48879
ti->local_flags: 0

Is there a method to identify whether we had executed any of the interrupt handler while in this code?

Quoted 7 lines

*** end thread_info ***

Are there any additional thoughts on what might be causing preempt_count to change? I was thinking that cede might somehow force it to 0 (or perhaps one of the preempt_count explicit value setters in irq.c) and then decrement it - but that dec should trigger an error in the dec_preempt_count() as I have CONFIG_DEBUG_PREEMPT=y.

Decrementer is only the suspect, we have not yet proved that the dec handler is being executed. Can somebody be using our stack? The pointer is same.. but do we still own it? I cannot think of how somebody else could be using this cpu's stack... but just a thought to explain this anomaly.

--Vaidy

Subject

Re: [PATCH][RFC] preempt_count corruption across H_CEDE call with CONFIG_PREEMPT on pseries

Quoted 8 lines · Benjamin Herrenschmidt

Quoted 3 lines · Darren Hart

1) How can the preempt_count() get mangled across the H_CEDE hcall?
2) Should we call preempt_enable() in cpu_idle() prior to cpu_die() ?

The preempt count is on the thread info at the bottom of the stack.

Can you check the stack pointers ?

Hi Ben, thanks for looking.

I instrumented the area around extended_cede_processor() as follows (please confirm I'm getting the stack pointer correctly).

while (get_preferred_offline_state(cpu) == CPU_STATE_INACTIVE) {
   asm("mr %0,1" : "=r" (sp));
   printk("before H_CEDE current->stack: %lx, pcnt: %x\n", sp,
preempt_count());
   extended_cede_processor(cede_latency_hint);
   asm("mr %0,1" : "=r" (sp));
   printk("after H_CEDE current->stack: %lx, pcnt: %x\n", sp,

preempt_count());
}

On Mainline (2.6.33.6, CONFIG_PREEMPT=y) I see this:

Jul 22 18:37:08 igoort1 kernel: before H_CEDE current->stack:
c00000010e9e3ce0, pcnt: 1
Jul 22 18:37:08 igoort1 kernel: after H_CEDE current->stack:

c00000010e9e3ce0, pcnt: 1

This surprised me as preempt_count is 1 before and after, so no corruption appears to occur on mainline. This makes the pcnt of 65 I see without the preempt_count()=0 hack very strange. I ran several hundred off/on cycles. The issue of preempt_count being 1 is still addressed by this patch however.

On PREEMPT_RT (2.6.33.5-rt23 - tglx, sorry, rt/2.6.33 next time,

Jul 22 18:51:11 igoort1 kernel: before H_CEDE current->stack:
c000000089bcfcf0, pcnt: 1
Jul 22 18:51:11 igoort1 kernel: after H_CEDE current->stack:

c000000089bcfcf0, pcnt: ffffffff

In both cases the stack pointer appears unchanged.

Note: there is a BUG triggered in between these statements as the preempt_count causes the printk to trigger:
Badness at kernel/sched.c:5572

Thanks,

--
Darren Hart
IBM Linux Technology Center
Real-Time Linux Team

Quoted 3 lines · Darren Hart

1) How can the preempt_count() get mangled across the H_CEDE hcall?
2) Should we call preempt_enable() in cpu_idle() prior to cpu_die() ?

The preempt count is on the thread info at the bottom of the stack.

Can you check the stack pointers ?

With some instrumentation we were able to determine that the preempt_count() appears to change across the extended_cede_processor() call. Specifically across the plpar_hcall_norets(H_CEDE) call. On PREEMPT_RT we call this with preempt_count=1 and return with preempt_count=0xffffffff. On mainline with CONFIG_PREEMPT=y, the value is different (0x65) but is still incorrect.

Also of interest is that this path cpu_idle()->cpu_die()->pseries_mach_cpu_die() to start_secondary() enters with a preempt_count=1 if it wasn't corrupted across the hcall. The early boot path from _start however appears to call start_secondary() with a preempt_count of 0.

The following patch is most certainly not correct, but it does eliminate the situation on mainline 100% of the time (there is still a 25% reproduction rate on PREEMPT_RT). Can someone comment on:

1) How can the preempt_count() get mangled across the H_CEDE hcall?
2) Should we call preempt_enable() in cpu_idle() prior to cpu_die() ?

Hacked-up-by Darren Hart <[email protected]>

Index: linux-2.6.33.6/arch/powerpc/platforms/pseries/hotplug-cpu.c
===================================================================

arch/powerpc/platforms/pseries/hotplug-cpu.c +1 -0

@@ -138,6 +138,7 @@ static void pseries_mach_cpu_die(void)
 			 * Kernel stack will be reset and start_secondary()
 			 * will be called to continue the online operation.
 			 */
+			preempt_count() = 0;
 			start_secondary_resume();
 		}
 	}

Subject
Re: [PATCH][RFC] preempt_count corruption across H_CEDE call with CONFIG_PREEMPT on pseries

Hi Darren,

Quoted 7 lines · Darren Hart

With some instrumentation we were able to determine that the preempt_count() appears to change across the extended_cede_processor() call. Specifically across the plpar_hcall_norets(H_CEDE) call. On PREEMPT_RT we call this with preempt_count=1 and return with preempt_count=0xffffffff. On mainline with CONFIG_PREEMPT=y, the value is different (0x65) but is still incorrect.

I was trying to reproduce this issue on a 2.6.33.7-rt29 kernel. I could easily reproduce this on the RT kernel and not the non-RT kernel. However, I hit it every single time I did a cpu online operation. I also noticed that the issue persists even when I disable H_CEDE by passing the "cede_offline=0" kernel commandline parameter. Could you pl confirm if you observe the same in your setup ?

However, the issue still remains. Will spend few cycles looking into this issue.

Quoted 8 lines

Also of interest is that this path cpu_idle()->cpu_die()->pseries_mach_cpu_die() to start_secondary() enters with a preempt_count=1 if it wasn't corrupted across the hcall. The early boot path from _start however appears to call start_secondary() with a preempt_count of 0.

The following patch is most certainly not correct, but it does

Quoted 15 lines

the situation on mainline 100% of the time (there is still a 25% reproduction rate on PREEMPT_RT). Can someone comment on:

1) How can the preempt_count() get mangled across the H_CEDE hcall?
2) Should we call preempt_enable() in cpu_idle() prior to cpu_die() ?

Hacked-up-by Darren Hart <[email protected]>

Index: linux-2.6.33.6/arch/powerpc/platforms/pseries/hotplug-cpu.c
===================================================================

arch/powerpc/platforms/pseries/hotplug-cpu.c static void pseries_mach_cpu_die(void) · line 144

Quoted 7 lines

arch/powerpc/platforms/pseries/hotplug-cpu.c +1 -0

@@ -138,6 +138,7 @@ static void pseries_mach_cpu_die(void)
           * Kernel stack will be reset and start_secondary()
           * will be called to continue the online operation.
           */
+         preempt_count() = 0;
          start_secondary_resume();
       }
    }

--
Regards,
Ankita Garg ([email protected])
Linux Technology Center
IBM India Systems & Technology Labs,
Bangalore, India

Hi Darren,

Quoted 7 lines · Darren Hart

With some instrumentation we were able to determine that the preempt_count() appears to change across the extended_cede_processor() call. Specifically across the plpar_hcall_norets(H_CEDE) call. On PREEMPT_RT we call this with preempt_count=1 and return with preempt_count=0xffffffff. On mainline with CONFIG_PREEMPT=y, the value is different (0x65) but is still incorrect.

I was trying to reproduce this issue on a 2.6.33.7-rt29 kernel. I could easily reproduce this on the RT kernel and not the non-RT kernel. However, I hit it every single time I did a cpu online operation. I also noticed that the issue persists even when I disable H_CEDE by passing the "cede_offline=0" kernel commandline parameter. Could you pl confirm if you observe the same in your setup ?

However, the issue still remains. Will spend few cycles looking into this issue.

Quoted 30 lines

Also of interest is that this path cpu_idle()->cpu_die()->pseries_mach_cpu_die() to start_secondary() enters with a preempt_count=1 if it wasn't corrupted across the hcall. The early boot path from _start however appears to call start_secondary() with a preempt_count of 0.

The following patch is most certainly not correct, but it does eliminate the situation on mainline 100% of the time (there is still a 25% reproduction rate on PREEMPT_RT). Can someone comment on:

1) How can the preempt_count() get mangled across the H_CEDE hcall?
2) Should we call preempt_enable() in cpu_idle() prior to cpu_die() ?

Hacked-up-by Darren Hart<[email protected]>

Index: linux-2.6.33.6/arch/powerpc/platforms/pseries/hotplug-cpu.c
===================================================================

arch/powerpc/platforms/pseries/hotplug-cpu.c +1 -0

@@ -138,6 +138,7 @@ static void pseries_mach_cpu_die(void)
  			 * Kernel stack will be reset and start_secondary()
  			 * will be called to continue the online operation.
  			 */
+			preempt_count() = 0;
  			start_secondary_resume();
  		}
  	}

Hi Darren,

Quoted 7 lines · Darren Hart

With some instrumentation we were able to determine that the preempt_count() appears to change across the extended_cede_processor() call. Specifically across the plpar_hcall_norets(H_CEDE) call. On PREEMPT_RT we call this with preempt_count=1 and return with preempt_count=0xffffffff. On mainline with CONFIG_PREEMPT=y, the value is different (0x65) but is still incorrect.

I was trying to reproduce this issue on a 2.6.33.7-rt29 kernel. I could easily reproduce this on the RT kernel and not the non-RT kernel.

However, I hit it every single time I did a cpu online operation. I also noticed that the issue persists even when I disable H_CEDE by passing the "cede_offline=0" kernel commandline parameter. Could you pl confirm if you observe the same in your setup ?

However, the issue still remains. Will spend few cycles looking into this issue.

When running with the function plugin I had to stop the trace immediately before entering start_secondary after an online or my traces would not include the pseries_mach_cpu_die function, nor the tracing I added there (possibly buffer size, I am using 2048). The following trace was collected using "trace-cmd record -p function -e irq -e sched" and has been filtered to only show CPU [001] (the CPU undergoing the offline/online test, and the one seeing preempt_count (pcnt) go to ffffffff after cede. The function tracer does not indicate anything running on the CPU other than the HCALL - unless the __trace_hcall* commands might be to blame.

On Tue, 2010-08-31 at 00:12 -0700, Darren Hart wrote:
..

Quoted 11 lines

When running with the function plugin I had to stop the trace immediately before entering start_secondary after an online or my traces would not include the pseries_mach_cpu_die function, nor the tracing I added there (possibly buffer size, I am using 2048). The following trace was collected using "trace-cmd record -p function -e irq -e sched" and has been filtered to only show CPU [001] (the CPU undergoing the offline/online test, and the one seeing preempt_count (pcnt) go to ffffffff after cede. The function tracer does not indicate anything running on the CPU other than the HCALL - unless the __trace_hcall* commands might be to blame.

It's not impossible. Though normally they're disabled right, so the only reason they're running is because you're tracing. So if they are causing the bug then that doesn't explain why you see it normally.

Still, might be worth disabling just the hcall tracepoints just to be 100% sure.

Quoted 14 lines · Michael Ellerman

On Tue, 2010-08-31 at 00:12 -0700, Darren Hart wrote:
..

Quoted 11 lines

When running with the function plugin I had to stop the trace immediately before entering start_secondary after an online or my traces would not include the pseries_mach_cpu_die function, nor the tracing I added there (possibly buffer size, I am using 2048). The following trace was collected using "trace-cmd record -p function -e irq -e sched" and has been filtered to only show CPU [001] (the CPU undergoing the offline/online test, and the one seeing preempt_count (pcnt) go to ffffffff after cede. The function tracer does not indicate anything running on the CPU other than the HCALL - unless the __trace_hcall* commands might be to blame.

Quoted 6 lines

It's not impossible. Though normally they're disabled right, so the only reason they're running is because you're tracing. So if they are causing the bug then that doesn't explain why you see it normally.

Still, might be worth disabling just the hcall tracepoints just to be 100% sure.

A couple of updates. I was working from tip/rt/head, which has been stale for some months now. I switched to tip/rt/2.6.33 and the preempt_count() change over cede went away. I now see the live hang that Will has reported.

Before I dive into the live hang, I want to understand what fixed the preempt_count() change. That might start pointing us in the right direction for the live hang.

I did an inverted git bisect between tip/rt/head and tip/rt/2.6.33 to try and locate the fix. I've narrowed it down to the 2.6.33.6 merge:

# git show 7e1af1172bbd4109d09ac515c5d376f633da7cff
commit 7e1af1172bbd4109d09ac515c5d376f633da7cff
Merge: d8e94db 9666790
Author: Thomas Gleixner <[email protected]>
Date:   Tue Jul 13 16:01:16 2010 +0200

Merge
git://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-2.6.33.y

Conflicts:
Makefile

Signed-off-by Thomas Gleixner <[email protected]>

Visual inspection yields two patches of interest:

f8b67691828321f5c85bb853283aa101ae673130
powerpc/pseries: Make query-cpu-stopped callable outside hotplug cpu

aef40e87d866355ffd279ab21021de733242d0d5 powerpc/pseries: Only call start-cpu when a CPU is stopped

I'm going to try reverting these today and see if they addressed the issue indirectly.

from tip/rt/2.6.33 causes the preempt_count() to change across the cede call. This patch appears to prevents the proxy preempt_count assignment from happening. This non-local-cpu assignment to 0 would cause an underrun of preempt_count() if the local-cpu had disabled preemption prior to the assignment and then later tried to enable it. This appears to be the case with the stack of __trace_hcall* calls preceeding the return from extended_cede_processor() in the latency format trace-cmd report:

<idle>-0 1d.... 201.252737: function: .cpu_die

  <idle>-0       1d....   201.252738: function:                .pseries_mach_cpu_die
  <idle>-0       1d....   201.252740: function:                   .idle_task_exit
  <idle>-0       1d....   201.252741: function:                      .switch_slb
  <idle>-0       1d....   201.252742: function:                   .xics_teardown_cpu
  <idle>-0       1d....   201.252743: function:                      .xics_set_cpu_priority
  <idle>-0       1d....   201.252744: function:             .__trace_hcall_entry
  <idle>-0       1d..1.   201.252745: function:                .probe_hcall_entry

  <idle>-0       1d..1.   201.252746: function:             .__trace_hcall_exit
  <idle>-0       1d..2.   201.252747: function:                .probe_hcall_exit
  <idle>-0       1d....   201.252748: function:             .__trace_hcall_entry
  <idle>-0       1d..1.   201.252748: function:                .probe_hcall_entry
  <idle>-0       1d..1.   201.252750: function:             .__trace_hcall_exit
  <idle>-0       1d..2.   201.252751: function:                .probe_hcall_exit
  <idle>-0       1d....   201.252752: function:             .__trace_hcall_entry
  <idle>-0       1d..1.   201.252753: function:                .probe_hcall_entry

offon.sh-3684 6..... 201.466488: bprint: .smp_pSeries_kick_cpu : resetting pcnt to 0 for cpu 1

preempt_count() is reset from 1 to 0 by smp_startup_cpu() without the QCSS_NOT_STOPPED check from the patch above.

<idle>-0 1d.... 201.466503: function: .__trace_hcall_exit

<idle>-0 1d..1. 201.466505: function: .probe_hcall_exit

<idle>-0 1d.Hff. 201.466507: bprint: .pseries_mach_cpu_die : after cede: ffffffff

With the preempt_count() being one less than it should be, the final preempt_enable() in the trace_hcall path drops preempt_count to 0xffffffff, which of course is an illegal value and leads to a crash.

I don't know if the patch above is the "right fix" for this or not as don't yet understand why this occurs only with PREEMPT_RT and not in mainline. Once we sort that out, we may need a more specific fix.

Quoted 10 lines · Darren Hart

from tip/rt/2.6.33 causes the preempt_count() to change across the cede call. This patch appears to prevents the proxy preempt_count assignment from happening. This non-local-cpu assignment to 0 would cause an underrun of preempt_count() if the local-cpu had disabled preemption prior to the assignment and then later tried to enable it. This appears to be the case with the stack of __trace_hcall* calls preceeding the return from extended_cede_processor() in the latency format trace-cmd report:

<idle>-0 1d.... 201.252737: function: .cpu_die

Note, the above 1d.... is a series of values. The first being the CPU, the next if interrupts are disabled, the next if the NEED_RESCHED flag is set, the next is softirqs enabled or disabled, next the preempt_count, and finally the lockdepth count.

Here we only care about the preempt_count, which is zero when '.' and a number if it is something else. It is the second to last field in that list.

Quoted 7 lines

  <idle>-0       1d....   201.252738: function:                .pseries_mach_cpu_die
  <idle>-0       1d....   201.252740: function:                   .idle_task_exit
  <idle>-0       1d....   201.252741: function:                      .switch_slb
  <idle>-0       1d....   201.252742: function:                   .xics_teardown_cpu
  <idle>-0       1d....   201.252743: function:                      .xics_set_cpu_priority
  <idle>-0       1d....   201.252744: function:             .__trace_hcall_entry
  <idle>-0       1d..1.   201.252745: function:                .probe_hcall_entry

^
preempt_count set to 1

Quoted 8 lines

  <idle>-0       1d..1.   201.252746: function:             .__trace_hcall_exit
  <idle>-0       1d..2.   201.252747: function:                .probe_hcall_exit
  <idle>-0       1d....   201.252748: function:             .__trace_hcall_entry
  <idle>-0       1d..1.   201.252748: function:                .probe_hcall_entry
  <idle>-0       1d..1.   201.252750: function:             .__trace_hcall_exit
  <idle>-0       1d..2.   201.252751: function:                .probe_hcall_exit
  <idle>-0       1d....   201.252752: function:             .__trace_hcall_entry
  <idle>-0       1d..1.   201.252753: function:                .probe_hcall_entry

                   ^   ^
                  CPU  preempt_count

Entering the function probe_hcall_entry() the preempt_count is 1 (see below). But probe_hcall_entry does:

	h = &get_cpu_var(hcall_stats)[opcode / 4];

Without doing the put (which it does in probe_hcall_exit())

So exiting the probe_hcall_entry() the prempt_count is 2. The trace_hcall_entry() will do a preempt_enable() making it leave as 1.

Quoted 1 line

offon.sh-3684 6..... 201.466488: bprint: .smp_pSeries_kick_cpu : resetting pcnt to 0 for cpu 1

This is CPU 6, changing the preempt count from 1 to 0.

Quoted 5 lines

preempt_count() is reset from 1 to 0 by smp_startup_cpu() without the QCSS_NOT_STOPPED check from the patch above.

<idle>-0 1d.... 201.466503: function: .__trace_hcall_exit

Note: __trace_hcall_exit() and __trace_hcall_entry() basically do:

preempt_disable();
call probe();
preempt_enable();

Quoted 1 line

<idle>-0 1d..1. 201.466505: function: .probe_hcall_exit

The preempt_count of 1 entering the probe_hcall_exit() is because of the preempt_disable() shown above. It should have been entered as a 2.

But then it does:

	put_cpu_var(hcall_stats);

making preempt_count 0.

But the preempt_enable() in the trace_hcall_exit() causes this to be -1.

Quoted 5 lines

<idle>-0 1d.Hff. 201.466507: bprint: .pseries_mach_cpu_die : after cede: ffffffff

With the preempt_count() being one less than it should be, the final preempt_enable() in the trace_hcall path drops preempt_count to 0xffffffff, which of course is an illegal value and leads to a crash.

I'm confused to how this works in mainline?

Quoted 18 lines · Steven Rostedt

Quoted 10 lines · Darren Hart

from tip/rt/2.6.33 causes the preempt_count() to change across the cede call. This patch appears to prevents the proxy preempt_count assignment from happening. This non-local-cpu assignment to 0 would cause an underrun of preempt_count() if the local-cpu had disabled preemption prior to the assignment and then later tried to enable it. This appears to be the case with the stack of __trace_hcall* calls preceeding the return from extended_cede_processor() in the latency format trace-cmd report:

<idle>-0 1d.... 201.252737: function: .cpu_die

Note, the above 1d.... is a series of values. The first being the CPU, the next if interrupts are disabled, the next if the NEED_RESCHED flag is set, the next is softirqs enabled or disabled, next the preempt_count, and finally the lockdepth count.

Quoted 6 lines

Here we only care about the preempt_count, which is zero when '.' and a number if it is something else. It is the second to last field in that list.

Quoted 1 line

<idle>-0 1d.... 201.252738: function: .pseries_ma

Quoted 1 line

Quoted 1 line

<idle>-0 1d.... 201.252740: function: .idle_ta

Quoted 1 line

Quoted 1 line

<idle>-0 1d.... 201.252741: function: .swit

Quoted 1 line

Quoted 1 line

<idle>-0 1d.... 201.252742: function: .xics_te

Quoted 1 line

Quoted 1 line

<idle>-0 1d.... 201.252743: function: .xics

Quoted 1 line

Quoted 1 line

<idle>-0 1d.... 201.252744: function: .__trace_hcall

Quoted 1 line

Quoted 1 line

<idle>-0 1d..1. 201.252745: function: .probe_hcal

Quoted 5 lines

^
preempt_count set to 1

Quoted 1 line

<idle>-0 1d..1. 201.252746: function: .__trace_hcall

Quoted 1 line

Quoted 1 line

<idle>-0 1d..2. 201.252747: function: .probe_hcal

Quoted 1 line

Quoted 1 line

<idle>-0 1d.... 201.252748: function: .__trace_hcall

Quoted 1 line

Quoted 1 line

<idle>-0 1d..1. 201.252748: function: .probe_hcal

Quoted 1 line

Quoted 1 line

<idle>-0 1d..1. 201.252750: function: .__trace_hcall

Quoted 1 line

Quoted 1 line

<idle>-0 1d..2. 201.252751: function: .probe_hcal

Quoted 1 line

Quoted 1 line

<idle>-0 1d.... 201.252752: function: .__trace_hcall

Quoted 1 line

Quoted 1 line

<idle>-0 1d..1. 201.252753: function: .probe_hcal

Quoted 8 lines

                   ^   ^
                  CPU  preempt_count

Entering the function probe_hcall_entry() the preempt_count is 1 (see below). But probe_hcall_entry does:

	h = &get_cpu_var(hcall_stats)[opcode / 4];

Quoted 7 lines

Without doing the put (which it does in probe_hcall_exit())

So exiting the probe_hcall_entry() the prempt_count is 2. The trace_hcall_entry() will do a preempt_enable() making it leave as 1.

Quoted 1 line

offon.sh-3684 6..... 201.466488: bprint: .smp_pSeries_k

Quoted 8 lines

This is CPU 6, changing the preempt count from 1 to 0.

Quoted 5 lines

preempt_count() is reset from 1 to 0 by smp_startup_cpu() without the QCSS_NOT_STOPPED check from the patch above.

<idle>-0 1d.... 201.466503: function: .__trace_hcall

Quoted 9 lines

Note: __trace_hcall_exit() and __trace_hcall_entry() basically do:

preempt_disable();
call probe();
preempt_enable();

Quoted 1 line

<idle>-0 1d..1. 201.466505: function: .probe_hcal

Quoted 7 lines

The preempt_count of 1 entering the probe_hcall_exit() is because of the preempt_disable() shown above. It should have been entered as a 2.

But then it does:

Quoted 8 lines

	put_cpu_var(hcall_stats);

making preempt_count 0.

But the preempt_enable() in the trace_hcall_exit() causes this to be -1.

Quoted 1 line

<idle>-0 1d.Hff. 201.466507: bprint: .pseries_mach

Quoted 6 lines

Quoted 4 lines

With the preempt_count() being one less than it should be, the final preempt_enable() in the trace_hcall path drops preempt_count to 0xffffffff, which of course is an illegal value and leads to a crash.

I'm confused to how this works in mainline?

Turns out it didn't. 2.6.33.5 with CONFIG_PREEMPT=y sees this exact same behavior. The following, part of the 2.6.33.6 stable release, prevents this from happening:

aef40e87d866355ffd279ab21021de733242d0d5 powerpc/pseries: Only call start-cpu when a CPU is stopped

arch/powerpc/platforms/pseries/smp.c +6 -0

@@ -82,6 +82,12 @@ static inline int __devinit smp_startup_cpu(unsigned
 int lcpu)
 
        pcpu = get_hard_smp_processor_id(lcpu);
 
+       /* Check to see if the CPU out of FW already for kexec */
+       if (smp_query_cpu_stopped(pcpu) == QCSS_NOT_STOPPED){
+               cpu_set(lcpu, of_spin_map);
+               return 1;
+       }
+
        /* Fixup atomic count: it exited inside IRQ handler. */
        task_thread_info(paca[lcpu].__current)->preempt_count   = 0;

The question is now, Is this the right fix? If so, perhaps we can update the comment to be a bit more clear and not refer solely to kexec.

Michael Neuling, can you offer any thoughts here? We hit this EVERY TIME, which makes me wonder if the offline/online path could do this without calling smp_startup_cpu at all.

We need to call smp_startup_cpu on boot when we the cpus are still in FW. smp_startup_cpu does this for us on boot.

I'm wondering if we just need to move the test down a bit to make sure the preempt_count is set. I've not been following this thread, but maybe this might work?

Untested patch below...

Mikey

arch/powerpc/platforms/pseries/smp.c +0 -0

index 0317cce..3afaba4 100644
@@ -104,18 +104,18 @@ static inline int __devinit smp_startup_cpu(unsigned int lcpu)
 

arch/powerpc/platforms/pseries/smp.c +6 -0

 	if (get_cpu_current_state(lcpu) == CPU_STATE_INACTIVE)
 		goto out;
 
+	/* Check to see if the CPU out of FW already for kexec */
+	if (smp_query_cpu_stopped(pcpu) == QCSS_NOT_STOPPED){
+		cpumask_set_cpu(lcpu, of_spin_mask);
+		return 1;
+	}
+
 	/* 
 	 * If the RTAS start-cpu token does not exist then presume the
 	 * cpu is already spinning.
 

Quoted 6 lines · Michael Neuling

We need to call smp_startup_cpu on boot when we the cpus are still in FW. smp_startup_cpu does this for us on boot.

I'm wondering if we just need to move the test down a bit to make sure the preempt_count is set. I've not been following this thread, but maybe this might work?

Egad no! Setting the preempt_count to zero _is_ the bug. I think Darren even said that adding the exit prevented the bug (although now he's hitting a hard lockup someplace else). The original code he was using did not have the condition to return for kexec. It was just a coincidence that this code helped in bringing a CPU back online.

Quoted 11 lines

Untested patch below...

Mikey

arch/powerpc/platforms/pseries/smp.c +0 -0

index 0317cce..3afaba4 100644
@@ -104,18 +104,18 @@ static inline int __devinit smp_startup_cpu(unsigned int lcpu)
 

arch/powerpc/platforms/pseries/smp.c static inline int __devinit smp_startup_cpu(unsigned int lcpu) · line 108

Quoted 10 lines

arch/powerpc/platforms/pseries/smp.c +0 -6

 	pcpu = get_hard_smp_processor_id(lcpu);
 
-	/* Check to see if the CPU out of FW already for kexec */
-	if (smp_query_cpu_stopped(pcpu) == QCSS_NOT_STOPPED){
-		cpumask_set_cpu(lcpu, of_spin_mask);
-		return 1;
-	}
-
 	/* Fixup atomic count: it exited inside IRQ handler. */
 	task_thread_info(paca[lcpu].__current)->preempt_count	= 0;

We DON'T want to do the above. It's nasty! This is one CPU's task touching an intimate part of another CPU's task. It's equivalent of me putting my hand down you wife's blouse. It's offensive, and rude.

OK, if the CPU was never online, then you can do what you want. But what we see is that this fails on CPU hotplug. You stop a CPU, and it goes into this cede_processor() call. When you wake it up, suddenly the task on that woken CPU has its preempt count fscked up. This was really really hard to debug. We thought it was stack corruption or something. But it ended up being that this code has one CPU touching the breasts of another CPU. This code is a pervert!

What the trace clearly showed, was that we take down a CPU, and in doing so, the code on that CPU set the preempt count to 1, and it expected to have it as 1 when it returned. But the code that kicked started this CPU back to life (bring the CPU back online), set the preempt count on the task of that CPU to 0, and screwed everything up.

-- Steve

Quoted 14 lines

arch/powerpc/platforms/pseries/smp.c +6 -0

 	if (get_cpu_current_state(lcpu) == CPU_STATE_INACTIVE)
 		goto out;
 
+	/* Check to see if the CPU out of FW already for kexec */
+	if (smp_query_cpu_stopped(pcpu) == QCSS_NOT_STOPPED){
+		cpumask_set_cpu(lcpu, of_spin_mask);
+		return 1;
+	}
+
 	/* 
 	 * If the RTAS start-cpu token does not exist then presume the
 	 * cpu is already spinning.
 

Subject

Re: [PATCH][RFC] preempt_count corruption across H_CEDE call with CONFIG_PREEMPT on pseries

With this in place, we no longer see the preempt_count dropping below zero. However, if I offline/online a CPU about 246 times I hit the opposite problem, a preempt_count() overflow. There appears to be a missing preempt_enable() somewhere in the offline/online paths.

--
Darren Hart
IBM Linux Technology Center
Real-Time Linux Team

Quoted 6 lines · Michael Neuling

We need to call smp_startup_cpu on boot when we the cpus are still in FW. smp_startup_cpu does this for us on boot.

I'm wondering if we just need to move the test down a bit to make sure the preempt_count is set. I've not been following this thread, but maybe this might work?

Egad no! Setting the preempt_count to zero _is_ the bug. I think Darren even said that adding the exit prevented the bug (although now he's hitting a hard lockup someplace else). The original code he was using did not have the condition to return for kexec. It was just a coincidence that this code helped in bringing a CPU back online.

Quoted 1 line

arch/powerpc/platforms/

Quoted 5 lines

Untested patch below...

Mikey

arch/powerpc/platforms/ renamed from arch/powerpc/platforms/pseries/smp.c +0 -0

arch/powerpc/platforms/pseries/smp.c static inline int __devinit smp_startup_cpu(unsigned

Quoted 4 lines

index 0317cce..3afaba4 100644

arch/powerpc/platforms/pseries/smp.c +0 -0

@@ -104,18 +104,18 @@ static inline int __devinit smp_startup_cpu(unsigned 

arch/powerpc/platforms/pseries/smp.c static inline int __devinit smp_startup_cpu(unsigned int lcpu) · line 108

Quoted 11 lines

arch/powerpc/platforms/pseries/smp.c +0 -6

 	pcpu = get_hard_smp_processor_id(lcpu);
 
-	/* Check to see if the CPU out of FW already for kexec */
-	if (smp_query_cpu_stopped(pcpu) == QCSS_NOT_STOPPED){
-		cpumask_set_cpu(lcpu, of_spin_mask);
-		return 1;
-	}
-
 	/* Fixup atomic count: it exited inside IRQ handler. */
 	task_thread_info(paca[lcpu].__current)->preempt_count	= 0;

We DON'T want to do the above. It's nasty! This is one CPU's task touching an intimate part of another CPU's task. It's equivalent of me putting my hand down you wife's blouse. It's offensive, and rude.

OK, if the CPU was never online, then you can do what you want. But what we see is that this fails on CPU hotplug. You stop a CPU, and it goes into this cede_processor() call. When you wake it up, suddenly the task on that woken CPU has its preempt count fscked up. This was really really hard to debug. We thought it was stack corruption or something. But it ended up being that this code has one CPU touching the breasts of another CPU. This code is a pervert!

What the trace clearly showed, was that we take down a CPU, and in doing so, the code on that CPU set the preempt count to 1, and it expected to have it as 1 when it returned. But the code that kicked started this CPU back to life (bring the CPU back online), set the preempt count on the task of that CPU to 0, and screwed everything up.

Quoted 16 lines · In message <[email protected]> you wrote:

Quoted 6 lines · Michael Neuling

We need to call smp_startup_cpu on boot when we the cpus are still in FW. smp_startup_cpu does this for us on boot.

I'm wondering if we just need to move the test down a bit to make sure the preempt_count is set. I've not been following this thread, but maybe this might work?

Egad no! Setting the preempt_count to zero _is_ the bug. I think Darren even said that adding the exit prevented the bug (although now he's hitting a hard lockup someplace else). The original code he was using did not have the condition to return for kexec. It was just a coincidence that this code helped in bringing a CPU back online.

Quoted 1 line

Quoted 5 lines

arch/powerpc/platforms/

Quoted 5 lines

Untested patch below...

Mikey

arch/powerpc/platforms/ renamed from arch/powerpc/platforms/pseries/smp.c +0 -0

pseries/smp.c

Quoted 4 lines

arch/powerpc/platforms/pseries/smp.c static inline int __devinit smp_startup_cpu(unsigned

Quoted 4 lines

index 0317cce..3afaba4 100644

arch/powerpc/platforms/pseries/smp.c +0 -0

@@ -104,18 +104,18 @@ static inline int __devinit smp_startup_cpu(unsigned 

int lcpu)

Quoted 24 lines

arch/powerpc/platforms/pseries/smp.c static inline int __devinit smp_startup_cpu(unsigned int lcpu) · line 108

Quoted 11 lines

arch/powerpc/platforms/pseries/smp.c +0 -6

 	pcpu = get_hard_smp_processor_id(lcpu);
 
-	/* Check to see if the CPU out of FW already for kexec */
-	if (smp_query_cpu_stopped(pcpu) == QCSS_NOT_STOPPED){
-		cpumask_set_cpu(lcpu, of_spin_mask);
-		return 1;
-	}
-
 	/* Fixup atomic count: it exited inside IRQ handler. */
 	task_thread_info(paca[lcpu].__current)->preempt_count	= 0;

We DON'T want to do the above. It's nasty! This is one CPU's task touching an intimate part of another CPU's task. It's equivalent of me putting my hand down you wife's blouse. It's offensive, and rude.

OK, if the CPU was never online, then you can do what you want. But what we see is that this fails on CPU hotplug. You stop a CPU, and it goes into this cede_processor() call. When you wake it up, suddenly the task on that woken CPU has its preempt count fscked up. This was really really hard to debug. We thought it was stack corruption or something. But it ended up being that this code has one CPU touching the breasts of another CPU. This code is a pervert!

Quoted 5 lines

What the trace clearly showed, was that we take down a CPU, and in doing so, the code on that CPU set the preempt count to 1, and it expected to have it as 1 when it returned. But the code that kicked started this CPU back to life (bring the CPU back online), set the preempt count on the task of that CPU to 0, and screwed everything up.

/me goes to checks where this came from...

It's been in the kernel since hotplug CPU support was added to ppc64 back in 2004, so I guess we are all at fault for letting this pervert get away with this stuff for so long in plain sight. :-)

So I guess we should remove this but we need to audit all the different paths that go through here to make sure they are OK with preempt. Normal boot, kexec boot, hotplug with FW stop and hotplug with extended_cede all hit this.

Mikey

+ /* Check to see if the CPU out of FW already for kexec */

This comment is really confusing to me. I _think_ it is saying that this test determines if the CPU is done executing firmware code and has begun executing OS code.... Is that right?