Re: [PATCH] tracing: Resets the trace buffer after a snapshot

From: Frank A. Cancio Bello
Date: Sun Jan 05 2020 - 05:31:23 EST


On Fri, Jan 03, 2020 at 05:37:11PM -0500, Joel Fernandes wrote:
> On Fri, Jan 03, 2020 at 11:40:01AM -0500, Steven Rostedt wrote:
> > On Tue, 31 Dec 2019 03:58:22 -0500
> > "Frank A. Cancio Bello" <frank@xxxxxxxxxxxxxxxxxxxxxx> wrote:
> >
> > > Currently, when a snapshot is taken the trace_buffer and the
> > > max_buffer are swapped. After this swap, the "new" trace_buffer is
> > > not reset. This produces an odd behavior: after a snapshot is taken
> > > the previous snapshot entries become available to the next reader of
> > > the trace_buffer as far as the reading occurs before the buffer is
> > > refilled with new entries by a writer.
> >
> > I consider this a feature not a bug ;-)
> >
> > Anyway, this behavior should be determined by an option. Care to create
> > one? (reset_on_snapshot?) I would keep the default behavior the same,
> > but document this a bit better.
>
> I relate to what Steve said as well. It is not strictly a bug per-se. An
> option to do this would be nice but I am doubting a user will really turn on
> such option (or even know an option exists) ;-). I would say leave it in the
> current state unless some usecase is disrupted by the current behavior..
>

Thank you both for your answers. I'm wondering what would be the reason
for not resetting the trace buffer after it gets swapped with the snapshot
buffer. Given that resetting it's not expensive, I would say that is not
performance, so I'm intrigued ;)

If it's OK, I will send two patches then, one documenting explicitly
that the trace buffer it will not be reset after be swapped and the
implications of this, and the second one changing the documentation of
the field trace_array->max_buffer that I now realized that say:

"
/*
...
* The buffers for the max_buffer are set up the same as the trace_buffer
* When a snapshot is taken, the buffer of the max_buffer is swapped
* with the buffer of the trace_buffer and the buffers are reset for
* the trace_buffer so the tracing can continue.
*/

thanks
frank a.

> thanks!
>
> - Joel
>
>
> >
> > Thanks!
> >
> > -- Steve
> >
> > >
> > > This patch resets the trace buffer after a snapshot is taken.
> > >
> > > Signed-off-by: Frank A. Cancio Bello <frank@xxxxxxxxxxxxxxxxxxxxxx>
> > > ---
> > >
> > > The following commands illustrate this odd behavior:
> > >
> > > # cd /sys/kernel/debug/tracing
> > > # echo nop > current_tracer
> > > # echo 1 > tracing_on
> > > # echo m1 > trace_marker
> > > # echo 1 > snapshot
> > > # echo m2 > trace_marker
> > > # echo 1 > snapshot
> > > # cat trace
> > > # tracer: nop
> > > #
> > > # entries-in-buffer/entries-written: 1/1 #P:2
> > > #
> > > # _-----=> irqs-off
> > > # / _----=> need-resched
> > > # | / _---=> hardirq/softirq
> > > # || / _--=> preempt-depth
> > > # ||| / delay
> > > # TASK-PID CPU# |||| TIMESTAMP FUNCTION
> > > # | | | |||| | |
> > > bash-550 [000] .... 50.479755: tracing_mark_write: m1
> > >
> > >
> > > kernel/trace/trace.c | 7 +++++--
> > > 1 file changed, 5 insertions(+), 2 deletions(-)
> > >
> > > diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> > > index ddb7e7f5fe8d..58373b5ae0cf 100644
> > > --- a/kernel/trace/trace.c
> > > +++ b/kernel/trace/trace.c
> > > @@ -6867,10 +6867,13 @@ tracing_snapshot_write(struct file *filp, const char __user *ubuf, size_t cnt,
> > > break;
> > > local_irq_disable();
> > > /* Now, we're going to swap */
> > > - if (iter->cpu_file == RING_BUFFER_ALL_CPUS)
> > > + if (iter->cpu_file == RING_BUFFER_ALL_CPUS) {
> > > update_max_tr(tr, current, smp_processor_id(), NULL);
> > > - else
> > > + tracing_reset_online_cpus(&tr->trace_buffer);
> > > + } else {
> > > update_max_tr_single(tr, current, iter->cpu_file);
> > > + tracing_reset_cpu(&tr->trace_buffer, iter->cpu_file);
> > > + }
> > > local_irq_enable();
> > > break;
> > > default:
> >