public inbox for linux-trace-kernel@vger.kernel.org
 help / color / mirror / Atom feed
* [PATCH] ring-buffer: Show what clock function is used on timestamp errors
@ 2026-03-24  0:22 Steven Rostedt
  2026-03-25  0:17 ` Masami Hiramatsu
  0 siblings, 1 reply; 2+ messages in thread
From: Steven Rostedt @ 2026-03-24  0:22 UTC (permalink / raw)
  To: LKML, Linux Trace Kernel; +Cc: Masami Hiramatsu, Mathieu Desnoyers

From: Steven Rostedt <rostedt@goodmis.org>

The testing for tracing was triggering a timestamp count issue that was
always off by one. This has been happening for some time but has never
been reported by anyone else. It was finally discovered to be an issue
with the "uptime" (jiffies) clock that happened to be traced and the
internal recursion caused the discrepancy. This would have been much
easier to solve if the clock function being used was displayed when the
error was detected.

Add the clock function to the error output.

Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
 kernel/trace/ring_buffer.c | 10 ++++++----
 1 file changed, 6 insertions(+), 4 deletions(-)

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 170170bd83bd..a99d1c7d180b 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -4435,18 +4435,20 @@ static void check_buffer(struct ring_buffer_per_cpu *cpu_buffer,
 	ret = rb_read_data_buffer(bpage, tail, cpu_buffer->cpu, &ts, &delta);
 	if (ret < 0) {
 		if (delta < ts) {
-			buffer_warn_return("[CPU: %d]ABSOLUTE TIME WENT BACKWARDS: last ts: %lld absolute ts: %lld\n",
-					   cpu_buffer->cpu, ts, delta);
+			buffer_warn_return("[CPU: %d]ABSOLUTE TIME WENT BACKWARDS: last ts: %lld absolute ts: %lld clock:%pS\n",
+					   cpu_buffer->cpu, ts, delta,
+					   cpu_buffer->buffer->clock);
 			goto out;
 		}
 	}
 	if ((full && ts > info->ts) ||
 	    (!full && ts + info->delta != info->ts)) {
-		buffer_warn_return("[CPU: %d]TIME DOES NOT MATCH expected:%lld actual:%lld delta:%lld before:%lld after:%lld%s context:%s\n",
+		buffer_warn_return("[CPU: %d]TIME DOES NOT MATCH expected:%lld actual:%lld delta:%lld before:%lld after:%lld%s context:%s\ntrace clock:%pS",
 				   cpu_buffer->cpu,
 				   ts + info->delta, info->ts, info->delta,
 				   info->before, info->after,
-				   full ? " (full)" : "", show_interrupt_level());
+				   full ? " (full)" : "", show_interrupt_level(),
+				   cpu_buffer->buffer->clock);
 	}
 out:
 	atomic_dec(this_cpu_ptr(&checking));
-- 
2.51.0


^ permalink raw reply related	[flat|nested] 2+ messages in thread

* Re: [PATCH] ring-buffer: Show what clock function is used on timestamp errors
  2026-03-24  0:22 [PATCH] ring-buffer: Show what clock function is used on timestamp errors Steven Rostedt
@ 2026-03-25  0:17 ` Masami Hiramatsu
  0 siblings, 0 replies; 2+ messages in thread
From: Masami Hiramatsu @ 2026-03-25  0:17 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: LKML, Linux Trace Kernel, Masami Hiramatsu, Mathieu Desnoyers

On Mon, 23 Mar 2026 20:22:12 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> From: Steven Rostedt <rostedt@goodmis.org>
> 
> The testing for tracing was triggering a timestamp count issue that was
> always off by one. This has been happening for some time but has never
> been reported by anyone else. It was finally discovered to be an issue
> with the "uptime" (jiffies) clock that happened to be traced and the
> internal recursion caused the discrepancy. This would have been much
> easier to solve if the clock function being used was displayed when the
> error was detected.
> 
> Add the clock function to the error output.

Looks good to me.

Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>

> 
> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> ---
>  kernel/trace/ring_buffer.c | 10 ++++++----
>  1 file changed, 6 insertions(+), 4 deletions(-)
> 
> diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
> index 170170bd83bd..a99d1c7d180b 100644
> --- a/kernel/trace/ring_buffer.c
> +++ b/kernel/trace/ring_buffer.c
> @@ -4435,18 +4435,20 @@ static void check_buffer(struct ring_buffer_per_cpu *cpu_buffer,
>  	ret = rb_read_data_buffer(bpage, tail, cpu_buffer->cpu, &ts, &delta);
>  	if (ret < 0) {
>  		if (delta < ts) {
> -			buffer_warn_return("[CPU: %d]ABSOLUTE TIME WENT BACKWARDS: last ts: %lld absolute ts: %lld\n",
> -					   cpu_buffer->cpu, ts, delta);
> +			buffer_warn_return("[CPU: %d]ABSOLUTE TIME WENT BACKWARDS: last ts: %lld absolute ts: %lld clock:%pS\n",
> +					   cpu_buffer->cpu, ts, delta,
> +					   cpu_buffer->buffer->clock);
>  			goto out;
>  		}
>  	}
>  	if ((full && ts > info->ts) ||
>  	    (!full && ts + info->delta != info->ts)) {
> -		buffer_warn_return("[CPU: %d]TIME DOES NOT MATCH expected:%lld actual:%lld delta:%lld before:%lld after:%lld%s context:%s\n",
> +		buffer_warn_return("[CPU: %d]TIME DOES NOT MATCH expected:%lld actual:%lld delta:%lld before:%lld after:%lld%s context:%s\ntrace clock:%pS",
>  				   cpu_buffer->cpu,
>  				   ts + info->delta, info->ts, info->delta,
>  				   info->before, info->after,
> -				   full ? " (full)" : "", show_interrupt_level());
> +				   full ? " (full)" : "", show_interrupt_level(),
> +				   cpu_buffer->buffer->clock);
>  	}
>  out:
>  	atomic_dec(this_cpu_ptr(&checking));
> -- 
> 2.51.0
> 


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

^ permalink raw reply	[flat|nested] 2+ messages in thread

end of thread, other threads:[~2026-03-25  0:17 UTC | newest]

Thread overview: 2+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2026-03-24  0:22 [PATCH] ring-buffer: Show what clock function is used on timestamp errors Steven Rostedt
2026-03-25  0:17 ` Masami Hiramatsu

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox