Re: Potential Issue in Tracing Ring Buffer

[J. Avila]

Hello Steven,

Thank you once again for all of your support. We saw that you also recently
merged a change[1] which adds some validation for the timestamps in
ring_buffer.c. Would you have any recommendations on how to add a more
lightweight check for time going "backwards" in the timestamps? The idea
is that we could use this quick test to detect the problem, then run a build
with your config to dig deeper.

Thanks,

Avila

[1] https://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git/commit/?h=for-next

On Mon, Nov 30, 2020 at 10:13 AM William Mcvicker
<willmcvicker@xxxxxxxxxx> wrote:
>
> On Mon, Nov 30, 2020 at 09:48:46AM -0500, Steven Rostedt wrote:
> > On Thu, 26 Nov 2020 13:26:13 -0500
> > Steven Rostedt <rostedt@xxxxxxxxxxx> wrote:
> >
> > > On Thu, 26 Nov 2020 06:52:45 +0100
> > > Greg KH <gregkh@xxxxxxxxxxxxxxxxxxx> wrote:
> > >
> > > > On Tue, Nov 24, 2020 at 10:39:17PM +0000, J. Avila wrote:
> > > > > Hello,
> > > > >
> > > > > In the ftrace logs we've collected internally, we have found that there are
> > > > > situations where time seems to go backwards; this breaks userspace tools which
> > > > > expect time to always go forward in these logs. For example, in this snippet
> > > > > from a db845c running a 5.10-rc4 kernel[1] (thanks for getting us the trace,
> > > > > John!), we see:
> > > >
> > > > Does the patch at:
> > > >   https://lore.kernel.org/r/20201125225654.1618966-1-minchan@xxxxxxxxxx
> > > >
> > > > resolve this issue for you?
> > > >
> > >
> > > I think I found the bug. Can you apply this patch and let me know if it
> > > fixes the issue for you?
> > >
> > > -- Steve
> > >
> > > diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
> > > index dc83b3fa9fe7..bccaf88d3706 100644
> > > --- a/kernel/trace/ring_buffer.c
> > > +++ b/kernel/trace/ring_buffer.c
> > > @@ -3291,7 +3291,7 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
> > >                     /* Nothing came after this event between C and E */
> > >                     info->delta = ts - info->after;
> > >                     (void)rb_time_cmpxchg(&cpu_buffer->write_stamp,
> > > -                                         info->after, info->ts);
> > > +                                         info->after, ts);
> > >                     info->ts = ts;
> > >             } else {
> > >                     /*
> > >
> >
> > Can I get a Tested-by from someone on the Google team, so that I can send
> > this upstream? It already passed all my internal testing, but I want to
> > make sure this is the fix for the issue I reference in the change log.
> >
> > -- Steve
> >
> > --
> > To unsubscribe from this group and stop receiving emails from it, send an email to kernel-team+unsubscribe@xxxxxxxxxxx.
> >
> Hi Steve,
>
> Thanks for the quick turnaround! Daniel and I have both tested your patch and
> verified it's working on our end. Feel free to include:
>
> Tested-by: Daniel Mentz <danielmentz@xxxxxxxxxx>
> Tested-by: Will McVicker <willmcvicker@xxxxxxxxxx>
>
> --Will