pmcstat: print raw TSC in decoded log output

Extend pmcstat -R output to include the raw TSC for each decoded record
and print tsc_freq from the initialize record so TSC deltas can be
converted to elapsed time.

Update the pmcstat documentation to describe the decoded output and the
architecture-specific TSC behavior.

Sponsored by: AMD
Signed-off-by: Andre Silva <andasilv@amd.com>
Reviewed by: imp, mhorne, Ali Mashtizadeh
Pull Request: https://github.com/freebsd/freebsd-src/pull/2085

3 files changed, 34 insertions, 5 deletions

diff --git a/usr.sbin/pmcstat/pmcstat.8 b/usr.sbin/pmcstat/pmcstat.8
index edb9ff106092..c78a13f910f9 100644
--- a/usr.sbin/pmcstat/pmcstat.8
+++ b/usr.sbin/pmcstat/pmcstat.8
@@ -23,7 +23,7 @@
 .\" out of the use of this software, even if advised of the possibility of
 .\" such damage.
 .\"
-.Dd April 19, 2025
+.Dd April 15, 2026
 .Dt PMCSTAT 8
 .Os
 .Sh NAME
@@ -220,6 +220,30 @@ specified in
 .It Fl R Ar logfilename
 Perform offline analysis using sampling data in file
 .Ar logfilename .
+Each decoded record is printed as a single line with the following fields:
+a record type (e.g.,
+.Dq callchain ,
+.Dq initlog ) ,
+type-specific data, and a trailing 20-digit raw TSC value recording the
+CPU cycle at which the event occurred.
+The
+.Dq initlog
+record additionally prints
+.Dq Li tsc_freq=<hz> ,
+the TSC tick rate in Hz measured by the kernel at boot.
+To convert a TSC delta to nanoseconds:
+.Pp
+.Dl elapsed_ns = (tsc_end - tsc_start) * 1e9 / tsc_freq
+.Pp
+TSC-based timestamps and
+.Dq Li tsc_freq
+are only meaningful on x86 architectures
+.Pq amd64 and i386 .
+On all other architectures
+.Pq including arm64 and powerpc
+the
+.Dq Li tsc_freq
+field will be zero.
 .It Fl S Ar event-spec
 Allocate a system mode sampling PMC measuring hardware events
 specified in
diff --git a/usr.sbin/pmcstat/pmcstat.h b/usr.sbin/pmcstat/pmcstat.h
index 67571ce4b2ee..6131d7a50404 100644
--- a/usr.sbin/pmcstat/pmcstat.h
+++ b/usr.sbin/pmcstat/pmcstat.h
@@ -50,8 +50,9 @@
 
 #define	PMCSTAT_PRINT_ENTRY(T,...) do {					\
 		(void) fprintf(args.pa_printfile, "%-9s", T);		\
-		(void) fprintf(args.pa_printfile, " "  __VA_ARGS__);	\
-		(void) fprintf(args.pa_printfile, "\n");		\
+		(void) fprintf(args.pa_printfile, " " __VA_ARGS__);	\
+		(void) fprintf(args.pa_printfile, " %20ju\n",		\
+		(uintmax_t)_pmcstat_current_tsc);			\
 	} while (0)
 
 #define PMCSTAT_PL_NONE		0
diff --git a/usr.sbin/pmcstat/pmcstat_log.c b/usr.sbin/pmcstat/pmcstat_log.c
index db9cbfabd9da..9af2ccc4e365 100644
--- a/usr.sbin/pmcstat/pmcstat_log.c
+++ b/usr.sbin/pmcstat/pmcstat_log.c
@@ -194,6 +194,7 @@ static struct pmc_plugins plugins[] = {
 };
 
 static int pmcstat_mergepmc;
+static uint64_t _pmcstat_current_tsc; /* TSC for PMCSTAT_PRINT_ENTRY */
 
 int pmcstat_pmcinfilter = 0; /* PMC filter for top mode. */
 float pmcstat_threshold = 0.5; /* Cost filter for top mode. */
@@ -471,6 +472,7 @@ pmcstat_print_log(void)
 
 	while (pmclog_read(args.pa_logparser, &ev) == 0) {
 		assert(ev.pl_state == PMCLOG_OK);
+		_pmcstat_current_tsc = ev.pl_tsc;
 		switch (ev.pl_type) {
 		case PMCLOG_TYPE_CALLCHAIN:
 			PMCSTAT_PRINT_ENTRY("callchain",
@@ -496,9 +498,11 @@ pmcstat_print_log(void)
 			PMCSTAT_PRINT_ENTRY("drop",);
 			break;
 		case PMCLOG_TYPE_INITIALIZE:
-			PMCSTAT_PRINT_ENTRY("initlog","0x%x \"%s\"",
+			PMCSTAT_PRINT_ENTRY("initlog",
+			    "0x%x \"%s\" tsc_freq=%" PRIu64,
 			    ev.pl_u.pl_i.pl_version,
-			    pmc_name_of_cputype(ev.pl_u.pl_i.pl_arch));
+			    pmc_name_of_cputype(ev.pl_u.pl_i.pl_arch),
+			    ev.pl_u.pl_i.pl_tsc_freq);
 			if ((ev.pl_u.pl_i.pl_version & 0xFF000000) !=
 			    PMC_VERSION_MAJOR << 24)
 				warnx(