Re: [PATCH 3/6] tracing: Add tp_pstore cmdline to have tracepoints go to pstore

[Steven Rostedt]

On Tue, 9 Oct 2018 23:52:14 +0530
Sai Prakash Ranjan <saiprakash.ranjan@xxxxxxxxxxxxxx> wrote:

> >>> Also regarding the warning on "event_call->event.funcs->trace()" call,
> >>> I see it everytime without spinlock. Also we see output_printk using
> >>> spinlock when making this call. I could not find a way to pass event
> >>> buffer size and allocate in pstore. Steven can give some hints with this
> >>> I guess.  
> > 
> > The spinlock warning you're talking about is this one correct?
> > 
> > [    1.389382] WARNING: CPU: 2 PID: 2 at kernel/trace/trace_output.c:289 trace_raw_output_prep+0x18/0xa0
> > [    1.389416] Modules linked in:
> > which you reported here:
> > https://lkml.org/lkml/2018/9/22/319
> > 
> > This warning happens I think because you're trying to format the events while
> > the trace events are being generated. You said you got this warning when you
> > didn't use the spinlock. I believe the spinlocking prevents such races, but
> > if you didn't need to format the events into text into text in the first
> > place, then you wouldn't need such locking at all.
> > 
> > I believe ftrace doesn't have such issues because such locking is taken care
> > off when the trace events are formatted from the trace buffer and displayed,
> > but I could be wrong about that.. I'll let Steven provide more inputs about
> > how this warning can occur.  
> Yes Steven would have more insight on this warning.

Correct. Formatting should not be done at the location of recording
(it's way too much overhead). Even trace_printk() doesn't format string
at the execution path, but does so at the presentation path (reading
the buffer, via reads of the trace file, or in trace-cmd post
processing of the trace.dat file).

trace_printk() uses vbin_printf() which doesn't do printf()
conversions, but instead only saves the format string and the raw
values into the buffer. Then in uses bstr_printf() that takes the
format string and raw values to produce the "printf()" output you know
and love.

-- Steve