[PATCH][RFC] preempt_count corruption across H_CEDE call with CONFIG_PREEMPT on pseries
Darren Hart
dvhltc at us.ibm.com
Thu Sep 2 04:47:29 EST 2010
On 09/01/2010 08:10 AM, Darren Hart wrote:
> On 08/31/2010 10:54 PM, Michael Ellerman wrote:
>> On Tue, 2010-08-31 at 00:12 -0700, Darren Hart wrote:
>> ..
>>>
>>> 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.
>
> 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 <tglx at linutronix.de>
> 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 <tglx at linutronix.de>
>
>
> 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.
Removing:
aef40e87d866355ffd279ab21021de733242d0d5
powerpc/pseries: Only call start-cpu when a CPU is stopped
--- a/arch/powerpc/platforms/pseries/smp.c
+++ b/arch/powerpc/platforms/pseries/smp.c
@@ -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 */
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?
+ 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;
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.
Many thanks to Steven Rostedt for pouring over the trace and the trace
code with me.
Thanks,
--
Darren Hart
IBM Linux Technology Center
Real-Time Linux Team
More information about the Linuxppc-dev
mailing list