<div dir="ltr"><br><div class="gmail_extra"><br><br><div class="gmail_quote">On Thu, Nov 21, 2013 at 7:38 PM, Mathieu Desnoyers <span dir="ltr"><<a href="mailto:mathieu.desnoyers@efficios.com" target="_blank">mathieu.desnoyers@efficios.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div class="im">----- Original Message -----<br>
> From: "Luis Lozano" <<a href="mailto:llozano@google.com">llozano@google.com</a>><br>
> To: "Mathieu Desnoyers" <<a href="mailto:mathieu.desnoyers@efficios.com">mathieu.desnoyers@efficios.com</a>><br>
> Cc: "Jakub Jelinek" <<a href="mailto:jakub@redhat.com">jakub@redhat.com</a>>, "Alexander Holler" <<a href="mailto:holler@ahsoftware.de">holler@ahsoftware.de</a>>, "Linus Torvalds"<br>
> <<a href="mailto:torvalds@linux-foundation.org">torvalds@linux-foundation.org</a>>, "Richard Henderson" <<a href="mailto:rth@twiddle.net">rth@twiddle.net</a>>, "Linux Kernel Mailing List"<br>
> <<a href="mailto:linux-kernel@vger.kernel.org">linux-kernel@vger.kernel.org</a>>, "Will Deacon" <<a href="mailto:will.deacon@arm.com">will.deacon@arm.com</a>>, "Catalin Marinas" <<a href="mailto:catalin.marinas@arm.com">catalin.marinas@arm.com</a>>,<br>
> "Peter Zijlstra" <<a href="mailto:peterz@infradead.org">peterz@infradead.org</a>>, <a href="mailto:lttng-dev@lists.lttng.org">lttng-dev@lists.lttng.org</a>, "Nathan Lynch" <<a href="mailto:Nathan_Lynch@mentor.com">Nathan_Lynch@mentor.com</a>>, "Paul<br>
> E. McKenney" <<a href="mailto:paulmck@linux.vnet.ibm.com">paulmck@linux.vnet.ibm.com</a>>, "Andrew Morton" <<a href="mailto:akpm@linux-foundation.org">akpm@linux-foundation.org</a>>, "Bhaskar Janakiraman"<br>
> <<a href="mailto:bjanakiraman@chromium.org">bjanakiraman@chromium.org</a>>, "Han Shen" <<a href="mailto:shenhan@chromium.org">shenhan@chromium.org</a>><br>
</div><div class="im">> Sent: Thursday, November 21, 2013 9:36:27 PM<br>
> Subject: Re: current_thread_info() not respecting program order with gcc 4.8.x<br>
><br>
</div><div class="im">> Hi Mathieu,<br>
><br>
> Yes the problem we were seeing with GCC bug 58854 is that an interrupt<br>
> handler was corrupting the stack of a routine which had an invalid<br>
> value of SP (not really on "top" of the stack) for part of the<br>
> routine.<br>
> But in the assembly code you sent, I don't see where sp is being<br>
> modified... or where the access to "below" sp is happening.<br>
<br>
</div>The following instruction<br>
<div class="im"><br>
f1c: e50b1048 str r1, [fp, #-72] ; 0xffffffb8<br>
<br>
</div>appears in the assembly generated by gcc 4.8.2, but not in the one<br>
generated by 4.7.3, which makes me wonder if it's good or not.</blockquote><div><br></div><div><br></div><div>It is there in 4.7.3 just a few lines difference. </div><div>I don't see any meaningful difference between the 2 assembly snippets... </div>
<div>Just instructions ordered a little different? </div><div><br></div><div>Luis</div><div> </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"> With<br>
slightly different build output from the diff (probably a different config<br>
from Nathan), the first function instructions look like:<br>
<br>
00000efc <lttng_event_reserve>:<br>
efc: e1a0c00d mov ip, sp<br>
f00: e92ddff0 push {r4, r5, r6, r7, r8, r9, sl, fp, ip, lr, pc}<br>
f04: e24cb004 sub fp, ip, #4<br>
f08: e24dd03c sub sp, sp, #60 ; 0x3c<br>
f0c: e52de004 push {lr} ; (str lr, [sp, #-4]!)<br>
<div class="im"> f10: ebfffffe bl 0 <__gnu_mcount_nc><br>
f14: e5903000 ldr r3, [r0]<br>
f18: e1a04000 mov r4, r0<br>
</div><div class="im"> f1c: e1a0000d mov r0, sp<br>
f20: e5936030 ldr r6, [r3, #48] ; 0x30<br>
</div><div class="im"> f24: e3c03d7f bic r3, r0, #8128 ; 0x1fc0<br>
</div><div class="im"> f28: e3c3303f bic r3, r3, #63 ; 0x3f<br>
</div> f2c: e50b104c str r1, [fp, #-76] ; 0xffffffb4<br>
<div class="im"> f30: e5932004 ldr r2, [r3, #4]<br>
f34: e2822001 add r2, r2, #1<br>
f38: e5832004 str r2, [r3, #4]<br>
</div> f3c: ebfffffe bl 0 <debug_smp_processor_id><br>
f40: e59f2e44 ldr r2, [pc, #3652] ; 1d8c <lttng_event_reserve+0xe90><br>
f44: e59f3e44 ldr r3, [pc, #3652] ; 1d90 <lttng_event_reserve+0xe94><br>
f48: e7921100 ldr r1, [r2, r0, lsl #2]<br>
f4c: e1a05000 mov r5, r0<br>
f50: e7932001 ldr r2, [r3, r1]<br>
<br>
My rusty ARM assembler knowledge analyzes this like:<br>
<br>
ip = sp (ip being the scratch register)<br>
push 11 registers * 4 bytes = 44 bytes onto the stack<br>
fp = ip - 4<br>
sp = sp - 60 (sp = ip - 104)<br>
push {lr} bl<br>
0 <__gnu_mcount_nc> (dynamically patched to a pop {lr})<br>
[...]<br>
store r1 into mem location fp - 76<br>
<br>
So yes, it does look like the -76 from fp is within the stack.<br>
<div class="im"><br>
<br>
> In GCC bug 58854 it was pretty clear that the restore of the sp<br>
> register in the epilogue is moved to somewhere close to the prologue<br>
> of the routine.<br>
> Are we missing some diffs from the assembly comparison?<br>
<br>
</div>My next step is to setup my own 4.8.2 ARM cross-compiler. I've tried this morning,<br>
did not manage to get one working even after following 2 howtos, trying with Debian<br>
packages, etc. Nathan told me this diff was the full comparison between the two<br>
functions, but you'll understand that at this point I want to reproduce<br>
everything myself, because this is a _weird_ issue.<br>
<br>
But after a long day of debugging, it's time for some sleep. I will get back to this<br>
tomorrow,<br>
<br>
Thanks,<br>
<br>
Mathieu<br>
<div class="HOEnZb"><div class="h5"><br>
><br>
> Thanks<br>
><br>
> Luis<br>
><br>
><br>
><br>
><br>
> On Thu, Nov 21, 2013 at 5:57 PM, Mathieu Desnoyers<br>
> <<a href="mailto:mathieu.desnoyers@efficios.com">mathieu.desnoyers@efficios.com</a>> wrote:<br>
> > ----- Original Message -----<br>
> >> From: "Jakub Jelinek" <<a href="mailto:jakub@redhat.com">jakub@redhat.com</a>><br>
> >> To: "Luis Lozano" <<a href="mailto:llozano@google.com">llozano@google.com</a>><br>
> >> Cc: "Alexander Holler" <<a href="mailto:holler@ahsoftware.de">holler@ahsoftware.de</a>>, "Linus Torvalds"<br>
> >> <<a href="mailto:torvalds@linux-foundation.org">torvalds@linux-foundation.org</a>>, "Mathieu Desnoyers"<br>
> >> <<a href="mailto:mathieu.desnoyers@efficios.com">mathieu.desnoyers@efficios.com</a>>, "Richard Henderson" <<a href="mailto:rth@twiddle.net">rth@twiddle.net</a>>,<br>
> >> "Linux Kernel Mailing List"<br>
> >> <<a href="mailto:linux-kernel@vger.kernel.org">linux-kernel@vger.kernel.org</a>>, "Will Deacon" <<a href="mailto:will.deacon@arm.com">will.deacon@arm.com</a>>,<br>
> >> "Catalin Marinas" <<a href="mailto:catalin.marinas@arm.com">catalin.marinas@arm.com</a>>,<br>
> >> "Peter Zijlstra" <<a href="mailto:peterz@infradead.org">peterz@infradead.org</a>>, <a href="mailto:lttng-dev@lists.lttng.org">lttng-dev@lists.lttng.org</a>,<br>
> >> "Nathan Lynch" <<a href="mailto:Nathan_Lynch@mentor.com">Nathan_Lynch@mentor.com</a>>, "Paul<br>
> >> E. McKenney" <<a href="mailto:paulmck@linux.vnet.ibm.com">paulmck@linux.vnet.ibm.com</a>>, "Andrew Morton"<br>
> >> <<a href="mailto:akpm@linux-foundation.org">akpm@linux-foundation.org</a>>, "Bhaskar Janakiraman"<br>
> >> <<a href="mailto:bjanakiraman@chromium.org">bjanakiraman@chromium.org</a>>, "Han Shen" <<a href="mailto:shenhan@chromium.org">shenhan@chromium.org</a>><br>
> >> Sent: Thursday, November 21, 2013 7:39:04 PM<br>
> >> Subject: Re: current_thread_info() not respecting program order with gcc<br>
> >> 4.8.x<br>
> >><br>
> >> On Thu, Nov 21, 2013 at 03:45:35PM -0800, Luis Lozano wrote:<br>
> >> > I think we need a reproducer. Without this we may all be going on the<br>
> >> > wrong path. This whole conversation started on an *assumption* that<br>
> >> > some accesses were being reordered.<br>
> >> ><br>
> >> > evidence of the reorder or reproducer please?<br>
> >><br>
> >> Yeah, if a compiler bug is suspected, can anybody please open<br>
> >> a bugreport in <a href="http://gcc.gnu.org/bugzilla/" target="_blank">http://gcc.gnu.org/bugzilla/</a> with the preprocessed source,<br>
> >> compiler version, flags and how it was configured and some hint in which<br>
> >> function to look for what exactly? We don't necessarily need a runtime<br>
> >> small reproducer, but if it can be shown in the assembly what has been<br>
> >> reordered and why you think it shouldn't, with the above mentioned input<br>
> >> that ought to be sufficient. Thanks.<br>
> ><br>
> > OK OK, let me reply on list first so I can share the result of a full day<br>
> > of bug hunting. We're not there yet, but many options have been eliminated.<br>
> ><br>
> > The issue shows up in stress test, when tracing with lttng-modules 2.4-rc1,<br>
> > on ARM. It's been reproduced with a Linux kernel 3.12 so far, with<br>
> > lttng-modules<br>
> > compiled against that kernel.<br>
> ><br>
> > First, I asked Nathan to compile his kernel with gcc 4.7, and lttng-modules<br>
> > with gcc 4.8.x (and vice-versa). The problem only appears when<br>
> > lttng-modules<br>
> > are compiled with gcc 4.8.x. The compiler version used to compile the rest<br>
> > of the kernel does not matter.<br>
> ><br>
> > Then I looked at gcc 4.8 changelog for ARM, new feature:<br>
> > -fno-sched-pressure<br>
> > (sched pressure is there by default). Nathan tried compiling lttng-modules<br>
> > with<br>
> > -fno-sched-pressure. The problem still reproduces.<br>
> ><br>
> > Knowing that adding barrier() outside of preempt_disable()/enable() was<br>
> > fixing the issue, we tried identifying which code location was responsible<br>
> > for working around the issue. Skipping a long investigation, here is the<br>
> > executive summary:<br>
> ><br>
> > <a href="http://git.lttng.org/?p=lttng-modules.git;a=blob;f=lttng-ring-buffer-client.h;h=50c47b3bf49f6c2dd24e250cf1a9b97808cd8e27;hb=HEAD" target="_blank">http://git.lttng.org/?p=lttng-modules.git;a=blob;f=lttng-ring-buffer-client.h;h=50c47b3bf49f6c2dd24e250cf1a9b97808cd8e27;hb=HEAD</a><br>
> ><br>
> > Has the following function. We identified that adding a barrier() as shown<br>
> > below<br>
> > works around the issue:<br>
> ><br>
> > static<br>
> > int lttng_event_reserve(struct lib_ring_buffer_ctx *ctx,<br>
> > uint32_t event_id)<br>
> > {<br>
> > struct lttng_channel *lttng_chan = channel_get_private(ctx->chan);<br>
> > int ret, cpu;<br>
> ><br>
> > cpu = lib_ring_buffer_get_cpu(&client_config);<br>
> > if (cpu < 0)<br>
> > return -EPERM;<br>
> > ctx->cpu = cpu;<br>
> ><br>
> > switch (lttng_chan->header_type) {<br>
> > case 1: /* compact */<br>
> > if (event_id > 30)<br>
> > ctx->rflags |= LTTNG_RFLAG_EXTENDED;<br>
> > break;<br>
> > case 2: /* large */<br>
> > if (event_id > 65534)<br>
> > ctx->rflags |= LTTNG_RFLAG_EXTENDED;<br>
> > break;<br>
> > default:<br>
> > WARN_ON_ONCE(1);<br>
> > }<br>
> ><br>
> > ret = lib_ring_buffer_reserve(&client_config, ctx);<br>
> > if (ret)<br>
> > goto put;<br>
> > lttng_write_event_header(&client_config, ctx, event_id);<br>
> > return 0;<br>
> > put:<br>
> > lib_ring_buffer_put_cpu(&client_config);<br>
> > ---------------> barrier() added here;<br>
> > <----------------------------<br>
> > return ret;<br>
> > }<br>
> ><br>
> > Where barrier() is the usual asm volatile with "memory" clobber, nothing<br>
> > else.<br>
> ><br>
> > Nathan gave me the binary diff for the assembly generated for this function<br>
> > without<br>
> > the barrier and with the barrier:<br>
> ><br>
> > --- /tmp/lttng_event_reserve-4.8.2.dump 2013-11-21 11:14:14.536495079 -0600<br>
> > +++ /tmp/lttng_event_reserve-with-barrier-4.8.2.dump 2013-11-21<br>
> > 14:12:52.997355907 -0600<br>
> > @@ -7,11 +7,11 @@<br>
> > f10: ebfffffe bl 0 <__gnu_mcount_nc><br>
> > f14: e5903000 ldr r3, [r0]<br>
> > f18: e1a04000 mov r4, r0<br>
> > - f1c: e50b1048 str r1, [fp, #-72] ; 0xffffffb8<br>
> > + f1c: e1a0000d mov r0, sp<br>
> > f20: e5936030 ldr r6, [r3, #48] ; 0x30<br>
> > - f24: e1a0000d mov r0, sp<br>
> > - f28: e3c03d7f bic r3, r0, #8128 ; 0x1fc0<br>
> > - f2c: e3c3303f bic r3, r3, #63 ; 0x3f<br>
> > + f24: e3c03d7f bic r3, r0, #8128 ; 0x1fc0<br>
> > + f28: e3c3303f bic r3, r3, #63 ; 0x3f<br>
> > + f2c: e50b1048 str r1, [fp, #-72] ; 0xffffffb8<br>
> > f30: e5932004 ldr r2, [r3, #4]<br>
> > f34: e2822001 add r2, r2, #1<br>
> > f38: e5832004 str r2, [r3, #4]<br>
> > @@ -53,7 +53,7 @@<br>
> > fc8: e3c3303f bic r3, r3, #63 ; 0x3f<br>
> > fcc: e5933000 ldr r3, [r3]<br>
> > fd0: e3130002 tst r3, #2<br>
> > - fd4: 0a000000 beq fdc <lttng_event_reserve+0xe0><br>
> > + fd4: 0a0002be beq 1ad4 <lttng_event_reserve+0xbd8><br>
> > fd8: ebfffffe bl 0 <preempt_schedule><br>
> > fdc: ea0002bc b 1ad4 <lttng_event_reserve+0xbd8><br>
> > fe0: e3500000 cmp r0, #0<br>
> ><br>
> > We tried disabling the ftrace function tracing to get mcount out of the<br>
> > way,<br>
> > and the problem still reproduces.<br>
> ><br>
> > I'm stopping here in terms of details about the disassembly, because I<br>
> > need to double check with Nathan that I get the right disassembly for the<br>
> > right<br>
> > cases. I also terribly need to setup a 4.8.2 ARM cross-compiler on my<br>
> > machine.<br>
> ><br>
> > I'm attaching Nathan's ARM configuration.<br>
> ><br>
> > It does look behave a bit like this bug pointed out by Luis:<br>
> ><br>
> > <a href="http://gcc.gnu.org/bugzilla/show_bug.cgi?id=58854" target="_blank">http://gcc.gnu.org/bugzilla/show_bug.cgi?id=58854</a><br>
> ><br>
> > AFAIU (please correct me if I am wrong), ARM's interrupt handler run<br>
> > on top of the thread stack (?). If it's the case, then anything stored<br>
> > on the stack below "sp" could be overwritten by an interrupt handler.<br>
> > This would fit well the reproduction scenario for this bug: Nathan runs<br>
> > LTTng tracing of kmem_cache_free tracepoint with hackbench running.<br>
> > A race between a short window of stack use below sp and interrupt handlers<br>
> > would trigger with this kind of stress-test.<br>
> ><br>
> > Thoughts ?<br>
> ><br>
> > Thanks,<br>
> ><br>
> > Mathieu<br>
> ><br>
> ><br>
> > --<br>
> > Mathieu Desnoyers<br>
> > EfficiOS Inc.<br>
> > <a href="http://www.efficios.com" target="_blank">http://www.efficios.com</a><br>
><br>
><br>
><br>
> --<br>
><br>
> Luis A. Lozano | Software Engineer | <a href="mailto:llozano@google.com">llozano@google.com</a> | <a href="tel:%2B1%20%28408%29431-5164" value="+14084315164">+1 (408)431-5164</a><br>
><br>
<br>
--<br>
Mathieu Desnoyers<br>
EfficiOS Inc.<br>
<a href="http://www.efficios.com" target="_blank">http://www.efficios.com</a><br>
</div></div></blockquote></div><br></div></div>