tracing: Record trace_clock in last_boot_info

[PATCH] tracing: Record trace_clock in last_boot_info

Posted by Masami Hiramatsu (Google) 8 months, 1 week ago

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

Record trace_clock information in the trace_scratch area and show
it via `last_boot_info` so that reader can docode the timestamp
correctly.
With this change, the first line of the last_boot_info becomes
trace_clock which is used when the trace was recorded. E.g.

/sys/kernel/tracing/instances/boot_mapped # cat last_boot_info
trace_clock: mono
ffffffff81000000        [kernel]

Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 include/linux/trace_clock.h |    2 ++
 kernel/trace/trace.c        |   14 ++++++++++++--
 2 files changed, 14 insertions(+), 2 deletions(-)

diff --git a/include/linux/trace_clock.h b/include/linux/trace_clock.h
index 00e8f98c940f..2245848270d2 100644
--- a/include/linux/trace_clock.h
+++ b/include/linux/trace_clock.h
@@ -15,6 +15,8 @@
 
 #include <asm/trace_clock.h>
 
+#define TRACE_CLOCK_NAME_MAX 16
+
 extern u64 notrace trace_clock_local(void);
 extern u64 notrace trace_clock(void);
 extern u64 notrace trace_clock_jiffies(void);
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 8ddf6b17215c..e59826fa4cb3 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -6004,6 +6004,7 @@ struct trace_mod_entry {
 };
 
 struct trace_scratch {
+	char			clock[TRACE_CLOCK_NAME_MAX];
 	unsigned long		text_addr;
 	unsigned long		nr_entries;
 	struct trace_mod_entry	entries[];
@@ -6114,6 +6115,8 @@ static void update_last_data(struct trace_array *tr)
 	if (tr->scratch) {
 		struct trace_scratch *tscratch = tr->scratch;
 
+		strscpy(tscratch->clock, trace_clocks[tr->clock_id].name,
+			TRACE_CLOCK_NAME_MAX);
 		memset(tscratch->entries, 0,
 		       flex_array_size(tscratch, entries, tscratch->nr_entries));
 		tscratch->nr_entries = 0;
@@ -7000,9 +7003,10 @@ static void show_last_boot_header(struct seq_file *m, struct trace_array *tr)
 	 * Otherwise it shows the KASLR address from the previous boot which
 	 * should not be the same as the current boot.
 	 */
-	if (tscratch && (tr->flags & TRACE_ARRAY_FL_LAST_BOOT))
+	if (tscratch && (tr->flags & TRACE_ARRAY_FL_LAST_BOOT)) {
+		seq_printf(m, "trace_clock: %s\n", tscratch->clock);
 		seq_printf(m, "%lx\t[kernel]\n", tscratch->text_addr);
-	else
+	} else
 		seq_puts(m, "# Current\n");
 }
 
@@ -7289,6 +7293,12 @@ int tracing_set_clock(struct trace_array *tr, const char *clockstr)
 	tracing_reset_online_cpus(&tr->max_buffer);
 #endif
 
+	if (tr->scratch && !(tr->flags & TRACE_ARRAY_FL_LAST_BOOT)) {
+		struct trace_scratch *tscratch = tr->scratch;
+
+		strscpy(tscratch->clock, trace_clocks[i].name, TRACE_CLOCK_NAME_MAX);
+	}
+
 	mutex_unlock(&trace_types_lock);
 
 	return 0;

Re: [PATCH] tracing: Record trace_clock in last_boot_info

Posted by Steven Rostedt 8 months, 1 week ago

On Wed, 16 Apr 2025 23:46:38 +0900
"Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:

> Record trace_clock information in the trace_scratch area and show
> it via `last_boot_info` so that reader can docode the timestamp
> correctly.
> With this change, the first line of the last_boot_info becomes
> trace_clock which is used when the trace was recorded. E.g.
> 
> /sys/kernel/tracing/instances/boot_mapped # cat last_boot_info
> trace_clock: mono
> ffffffff81000000        [kernel]
> 

As this will not go in this cycle, which means tools may be built
around this.

Either we put it at the end, or we make it:

# trace_clock: mono
ffffffff81000000        [kernel]

Where "info" like "trace_clock" will be in the comment section, and all
non comments will be addresses.

Tooling can then just ignore the comment section, or read it for more
information.

-- Steve

Re: [PATCH] tracing: Record trace_clock in last_boot_info

Posted by Masami Hiramatsu (Google) 8 months ago

On Wed, 16 Apr 2025 11:12:27 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Wed, 16 Apr 2025 23:46:38 +0900
> "Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:
> 
> > Record trace_clock information in the trace_scratch area and show
> > it via `last_boot_info` so that reader can docode the timestamp
> > correctly.
> > With this change, the first line of the last_boot_info becomes
> > trace_clock which is used when the trace was recorded. E.g.
> > 
> > /sys/kernel/tracing/instances/boot_mapped # cat last_boot_info
> > trace_clock: mono
> > ffffffff81000000        [kernel]
> > 
> 
> As this will not go in this cycle, which means tools may be built
> around this.
> 
> Either we put it at the end, or we make it:
> 
> # trace_clock: mono
> ffffffff81000000        [kernel]
> 
> Where "info" like "trace_clock" will be in the comment section, and all
> non comments will be addresses.

OK. Anyway, as we discussed offline, I'll update it to just set the
value to the "trace_clock" file instead of using "last_boot_info".

Thank you,

> 
> Tooling can then just ignore the comment section, or read it for more
> information.
> 
> -- Steve


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