[RFC][BUG] tracer: Fails to work

[RFC][BUG] tracer: Fails to work

[Peter Zijlstra]

Hi Steve,

So I was hunting wabbits the other day and ftrace failed to work.

After I cursed a bit on IRC, Thomas found the below, after 'fixing' it
like so things worked enough to get the trace out.

Relying on things like this make it entirely impossible to get any trace
data out if you've wedged a CPU. Exactly the kind of situation you want
trace data for.

Please consider an appropriate change to make this happen.

---
diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 95181e36891a..b09c5b955555 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -4053,7 +4053,7 @@ EXPORT_SYMBOL_GPL(ring_buffer_read_prepare);
 void
 ring_buffer_read_prepare_sync(void)
 {
-	synchronize_sched();
+//	synchronize_sched();
 }
 EXPORT_SYMBOL_GPL(ring_buffer_read_prepare_sync);
 

Re: [RFC][BUG] tracer: Fails to work

[Mathieu Desnoyers]

----- On Jan 28, 2016, at 3:08 AM, Peter Zijlstra peterz@infradead.org wrote:

> Hi Steve,
> 
> So I was hunting wabbits the other day and ftrace failed to work.
> 
> After I cursed a bit on IRC, Thomas found the below, after 'fixing' it
> like so things worked enough to get the trace out.
> 
> Relying on things like this make it entirely impossible to get any trace
> data out if you've wedged a CPU. Exactly the kind of situation you want
> trace data for.
> 
> Please consider an appropriate change to make this happen.

I wonder if we should start considering using SRCU to protect
tracepoint (and other instrumentation mechanisms) critical sections
rather than RCU-sched ?

SRCU would allow us to wait for a grace-period specifically targeting
tracing, which should increase tracer robustness in face of misbehaving
CPUs. It would also allow us to do blocking calls (e.g. get_user())
from syscall entry/exit tracing, which I've been wanting to do for a
while.

Thoughts ?

Thanks,

Mathieu

> 
> ---
> diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
> index 95181e36891a..b09c5b955555 100644
> --- a/kernel/trace/ring_buffer.c
> +++ b/kernel/trace/ring_buffer.c
> @@ -4053,7 +4053,7 @@ EXPORT_SYMBOL_GPL(ring_buffer_read_prepare);
> void
> ring_buffer_read_prepare_sync(void)
> {
> -	synchronize_sched();
> +//	synchronize_sched();
> }
>  EXPORT_SYMBOL_GPL(ring_buffer_read_prepare_sync);

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

Re: [RFC][BUG] tracer: Fails to work

[Peter Zijlstra]

On Thu, Jan 28, 2016 at 01:38:00PM +0000, Mathieu Desnoyers wrote:

> Thoughts ?

So ideally dumping the trace data would not depend on any of that,
because I can break it all :-)

Not being able to access the trace data completely and utterly defeats
the purpose of having a tracer in the first place.

Re: [RFC][BUG] tracer: Fails to work

[Steven Rostedt]

On Thu, 28 Jan 2016 14:57:33 +0100
Peter Zijlstra <peterz@infradead.org> wrote:

> On Thu, Jan 28, 2016 at 01:38:00PM +0000, Mathieu Desnoyers wrote:
> 
> > Thoughts ?  
> 
> So ideally dumping the trace data would not depend on any of that,
> because I can break it all :-)
> 
> Not being able to access the trace data completely and utterly defeats
> the purpose of having a tracer in the first place.
> 

The solution is to use trace_pipe. That's for live tracing (or in this
case, tracing when the system gets corrupted). I may update the tracing
documentation to note this.

The trace file preserves the data it reads, and disables the ring
buffer before reading it to keep the iterator from being corrupted. But
that requires a somewhat working system (not a CPU being stuck). Hence,
use trace_pipe for your debugging. The only thing you'll lose is the
header that trace provides.

-- Steve

Re: [RFC][BUG] tracer: Fails to work

[Mathieu Desnoyers]

----- On Jan 28, 2016, at 8:57 AM, Peter Zijlstra peterz@infradead.org wrote:

> On Thu, Jan 28, 2016 at 01:38:00PM +0000, Mathieu Desnoyers wrote:
> 
>> Thoughts ?
> 
> So ideally dumping the trace data would not depend on any of that,
> because I can break it all :-)
> 
> Not being able to access the trace data completely and utterly defeats
> the purpose of having a tracer in the first place.

One item I have on my todo list is to allow mapping
the tracer buffers (lttng in my case) onto RAM that
persists across reboots/kexec using dax and the pmem
driver. Since the original system is clearly inactive
after a reboot, we can read the buffers from memory
without caring about synchronization.

That would be one possible way of handling your
snapshot-of-buggy-kernel-trace-buffers use-case.

Thanks,

Mathieu

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

Re: [RFC][BUG] tracer: Fails to work

[Peter Zijlstra]

On Thu, Jan 28, 2016 at 02:38:16PM +0000, Mathieu Desnoyers wrote:
> ----- On Jan 28, 2016, at 8:57 AM, Peter Zijlstra peterz@infradead.org wrote:
> 
> > On Thu, Jan 28, 2016 at 01:38:00PM +0000, Mathieu Desnoyers wrote:
> > 
> >> Thoughts ?
> > 
> > So ideally dumping the trace data would not depend on any of that,
> > because I can break it all :-)
> > 
> > Not being able to access the trace data completely and utterly defeats
> > the purpose of having a tracer in the first place.
> 
> One item I have on my todo list is to allow mapping
> the tracer buffers (lttng in my case) onto RAM that
> persists across reboots/kexec using dax and the pmem
> driver. Since the original system is clearly inactive
> after a reboot, we can read the buffers from memory
> without caring about synchronization.

I would expect the new kernel to use the same buffer for its tracing,
right? After all, there's no distinction between the old and new kernel
except a reboot.

In which case, my kernels often start babbling the moment I boot. So I
need to take care not to scribble the old data.

> That would be one possible way of handling your
> snapshot-of-buggy-kernel-trace-buffers use-case.

Now I wonder if my ipmipower -r is a warn reset :-)

(I'm assuming the pmem/dax stuff would simply use regular RAM to back
this stuff)

Re: [RFC][BUG] tracer: Fails to work

[Mathieu Desnoyers]

----- On Jan 28, 2016, at 9:47 AM, Peter Zijlstra peterz@infradead.org wrote:

> On Thu, Jan 28, 2016 at 02:38:16PM +0000, Mathieu Desnoyers wrote:
>> ----- On Jan 28, 2016, at 8:57 AM, Peter Zijlstra peterz@infradead.org wrote:
>> 
>> > On Thu, Jan 28, 2016 at 01:38:00PM +0000, Mathieu Desnoyers wrote:
>> > 
>> >> Thoughts ?
>> > 
>> > So ideally dumping the trace data would not depend on any of that,
>> > because I can break it all :-)
>> > 
>> > Not being able to access the trace data completely and utterly defeats
>> > the purpose of having a tracer in the first place.
>> 
>> One item I have on my todo list is to allow mapping
>> the tracer buffers (lttng in my case) onto RAM that
>> persists across reboots/kexec using dax and the pmem
>> driver. Since the original system is clearly inactive
>> after a reboot, we can read the buffers from memory
>> without caring about synchronization.
> 
> I would expect the new kernel to use the same buffer for its tracing,
> right? After all, there's no distinction between the old and new kernel
> except a reboot.

The new kernel can allocate the buffers into separate "files"
on the DAX in-RAM filesystem, so the old buffers would still be
there even when running the new kernel.

> 
> In which case, my kernels often start babbling the moment I boot. So I
> need to take care not to scribble the old data.
> 
>> That would be one possible way of handling your
>> snapshot-of-buggy-kernel-trace-buffers use-case.
> 
> Now I wonder if my ipmipower -r is a warn reset :-)
> 
> (I'm assuming the pmem/dax stuff would simply use regular RAM to back
> this stuff)

On x86, many BIOS wipe the memory content even after a warm reset :(
The most reliable solution I found on x86 is to use kexec() to
boot into a new kernel, mount the DAX filesystem again and read the
buffers from there.

I currently have the persistent buffer support implemented for the
lttng userspace tracer, but not yet for the kernel tracer. It's high
on my todo priority list though :)

Thanks,

Mathieu

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

Re: [RFC][BUG] tracer: Fails to work

[Peter Zijlstra]

On Thu, Jan 28, 2016 at 02:53:53PM +0000, Mathieu Desnoyers wrote:
> On x86, many BIOS wipe the memory content even after a warm reset :(
> The most reliable solution I found on x86 is to use kexec() to
> boot into a new kernel, mount the DAX filesystem again and read the
> buffers from there.

kexec() is tricky when the kernel is still prefectly fine, I doubt it'll
work when I've hosed it properly :/

Re: [RFC][BUG] tracer: Fails to work

[Steven Rostedt]

On Thu, 28 Jan 2016 16:29:57 +0100
Peter Zijlstra <peterz@infradead.org> wrote:

> On Thu, Jan 28, 2016 at 02:53:53PM +0000, Mathieu Desnoyers wrote:
> > On x86, many BIOS wipe the memory content even after a warm reset :(
> > The most reliable solution I found on x86 is to use kexec() to
> > boot into a new kernel, mount the DAX filesystem again and read the
> > buffers from there.  
> 
> kexec() is tricky when the kernel is still prefectly fine, I doubt it'll
> work when I've hosed it properly :/

I use it all the time when a kernel crashes. Well, kexec and kdump.
Which by the way, the crash utility has a way to read the ftrace ring
buffer from a kexec kdump core file.

-- Steve