2020-11-28 21:59:22

by Andrea Righi

Subject: [PATCH] ring-buffer: set the right timestamp in the slow path of __rb_reserve_next()

In the slow path of __rb_reserve_next() a nested event(s) can happen
between evaluating the timestamp delta of the current event and updating
write_stamp via local_cmpxchg(); in this case the delta is not valid
anymore and it should be set to 0 (same timestamp as the interrupting
event), since the event that we are currently processing is not the last
event in the buffer.

Link: https://lwn.net/Articles/831207
Fixes: a389d86f7fd0 ("ring-buffer: Have nested events still record running time stamp")
Signed-off-by: Andrea Righi <[email protected]>
---
kernel/trace/ring_buffer.c | 6 +++---
1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index dc83b3fa9fe7..5e30e0cdb6ce 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -3287,11 +3287,11 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
ts = rb_time_stamp(cpu_buffer->buffer);
barrier();
/*E*/ if (write == (local_read(&tail_page->write) & RB_WRITE_MASK) &&
- info->after < ts) {
+ info->after < ts &&
+ rb_time_cmpxchg(&cpu_buffer->write_stamp,
+ info->after, info->ts)) {
/* 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->ts = ts;
} else {
/*
--
2.29.2

2020-11-30 18:54:43

by Steven Rostedt

Subject: Re: [PATCH] ring-buffer: set the right timestamp in the slow path of __rb_reserve_next()

On Sat, 28 Nov 2020 10:15:17 +0100
Andrea Righi <[email protected]> wrote:

> In the slow path of __rb_reserve_next() a nested event(s) can happen
> between evaluating the timestamp delta of the current event and updating
> write_stamp via local_cmpxchg(); in this case the delta is not valid
> anymore and it should be set to 0 (same timestamp as the interrupting
> event), since the event that we are currently processing is not the last
> event in the buffer.
>
> Link: https://lwn.net/Articles/831207

And it looks like we have a WINNER!

Thanks! It shows someone is paying attention.

There's a few other patches I need to test, but I've queued this up for my
next pull request.

-- Steve


> Fixes: a389d86f7fd0 ("ring-buffer: Have nested events still record running time stamp")
> Signed-off-by: Andrea Righi <[email protected]>
> ---
> kernel/trace/ring_buffer.c | 6 +++---
> 1 file changed, 3 insertions(+), 3 deletions(-)
>
> diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
> index dc83b3fa9fe7..5e30e0cdb6ce 100644
> --- a/kernel/trace/ring_buffer.c
> +++ b/kernel/trace/ring_buffer.c
> @@ -3287,11 +3287,11 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
> ts = rb_time_stamp(cpu_buffer->buffer);
> barrier();
> /*E*/ if (write == (local_read(&tail_page->write) & RB_WRITE_MASK) &&
> - info->after < ts) {
> + info->after < ts &&
> + rb_time_cmpxchg(&cpu_buffer->write_stamp,
> + info->after, info->ts)) {
> /* 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->ts = ts;
> } else {
> /*