[PATCH 0/4] perf cs_etm: Basic support for virtual/kernel timestamps

[PATCH 0/4] perf cs_etm: Basic support for virtual/kernel timestamps

[German Gomez]

Hi,

This change has a soft dependency on [1], but assuming the name/location
of the new sysfs interface (ts_source) doesn't change, it should be safe
to apply.

The new 'ts_source' interface allows perf to detect if the timestamps in
the trace correspond to the value of CNTVCT_EL0, which we can convert to
a perf timestamp and store it in the instruction and branch samples.

Due to the way the trace is compressed and decoded by OpenCSD, we only
know the precise time of the first instruction in a range, but I think
for now this is better than not having timestamps at all...

Thanks,
German

[1] https://lore.kernel.org/all/20220503123537.1003035-1-german.gomez@arm.com/

German Gomez (4):
  perf pmu: Add function to check if a pmu file exists
  perf cs_etm: Keep separate symbols for ETMv4 and ETE parameters
  perf cs_etm: Record ts_source in AUXTRACE_INFO for ETMv4 and ETE
  perf cs_etm: Set the time field in the synthetic samples

 tools/perf/arch/arm/util/cs-etm.c |  89 +++++++++++++++++++--
 tools/perf/util/cs-etm.c          | 126 +++++++++++++++++++++++++-----
 tools/perf/util/cs-etm.h          |  13 ++-
 tools/perf/util/pmu.c             |  17 ++++
 tools/perf/util/pmu.h             |   2 +
 5 files changed, 221 insertions(+), 26 deletions(-)

-- 
2.25.1

[PATCH 1/4] perf pmu: Add function to check if a pmu file exists

[German Gomez]

Add a utility function perf_pmu__file_exists() to check if a given pmu
file exists in the sysfs filesystem.

Signed-off-by: German Gomez <german.gomez@arm.com>
---
 tools/perf/util/pmu.c | 17 +++++++++++++++++
 tools/perf/util/pmu.h |  2 ++
 2 files changed, 19 insertions(+)

diff --git a/tools/perf/util/pmu.c b/tools/perf/util/pmu.c
index 9a1c7e63e663..9479e9a4da54 100644
--- a/tools/perf/util/pmu.c
+++ b/tools/perf/util/pmu.c
@@ -1854,6 +1854,23 @@ int perf_pmu__scan_file(struct perf_pmu *pmu, const char *name, const char *fmt,
 	return ret;
 }
 
+bool perf_pmu__file_exists(struct perf_pmu *pmu, const char *name)
+{
+	char path[PATH_MAX];
+	struct stat statbuf;
+	const char *sysfs = sysfs__mountpoint();
+
+	if (!sysfs)
+		return false;
+
+	snprintf(path, PATH_MAX,
+		 "%s" EVENT_SOURCE_DEVICE_PATH "%s/%s", sysfs, pmu->name, name);
+	if (!file_available(path))
+		return false;
+
+	return stat(path, &statbuf) == 0;
+}
+
 static int perf_pmu__new_caps(struct list_head *list, char *name, char *value)
 {
 	struct perf_pmu_caps *caps = zalloc(sizeof(*caps));
diff --git a/tools/perf/util/pmu.h b/tools/perf/util/pmu.h
index 541889fa9f9c..ab728eaf13b6 100644
--- a/tools/perf/util/pmu.h
+++ b/tools/perf/util/pmu.h
@@ -120,6 +120,8 @@ bool pmu_have_event(const char *pname, const char *name);
 
 int perf_pmu__scan_file(struct perf_pmu *pmu, const char *name, const char *fmt, ...) __scanf(3, 4);
 
+bool perf_pmu__file_exists(struct perf_pmu *pmu, const char *name);
+
 int perf_pmu__test(void);
 
 struct perf_event_attr *perf_pmu__get_default_config(struct perf_pmu *pmu);
-- 
2.25.1

[PATCH 2/4] perf cs_etm: Keep separate symbols for ETMv4 and ETE parameters

[German Gomez]

Previously, adding a new parameter at the end of ETMv4 meant adding it
somewhere in the middle of ETE, which is not supported by the current
header version.

Signed-off-by: German Gomez <german.gomez@arm.com>
---
 tools/perf/arch/arm/util/cs-etm.c | 43 +++++++++++++++++++++++++-----
 tools/perf/util/cs-etm.c          | 44 +++++++++++++++++++++----------
 tools/perf/util/cs-etm.h          | 11 +++++++-
 3 files changed, 76 insertions(+), 22 deletions(-)

diff --git a/tools/perf/arch/arm/util/cs-etm.c b/tools/perf/arch/arm/util/cs-etm.c
index 11c71aa219f7..4899eb549b4d 100644
--- a/tools/perf/arch/arm/util/cs-etm.c
+++ b/tools/perf/arch/arm/util/cs-etm.c
@@ -53,7 +53,15 @@ static const char * const metadata_etmv4_ro[] = {
 	[CS_ETMV4_TRCIDR2]		= "trcidr/trcidr2",
 	[CS_ETMV4_TRCIDR8]		= "trcidr/trcidr8",
 	[CS_ETMV4_TRCAUTHSTATUS]	= "mgmt/trcauthstatus",
-	[CS_ETE_TRCDEVARCH]		= "mgmt/trcdevarch"
+};
+
+static const char * const metadata_ete_ro[] = {
+	[CS_ETE_TRCIDR0]		= "trcidr/trcidr0",
+	[CS_ETE_TRCIDR1]		= "trcidr/trcidr1",
+	[CS_ETE_TRCIDR2]		= "trcidr/trcidr2",
+	[CS_ETE_TRCIDR8]		= "trcidr/trcidr8",
+	[CS_ETE_TRCAUTHSTATUS]		= "mgmt/trcauthstatus",
+	[CS_ETE_TRCDEVARCH]		= "mgmt/trcdevarch",
 };
 
 static bool cs_etm_is_etmv4(struct auxtrace_record *itr, int cpu);
@@ -616,7 +624,7 @@ static bool cs_etm_is_ete(struct auxtrace_record *itr, int cpu)
 {
 	struct cs_etm_recording *ptr = container_of(itr, struct cs_etm_recording, itr);
 	struct perf_pmu *cs_etm_pmu = ptr->cs_etm_pmu;
-	int trcdevarch = cs_etm_get_ro(cs_etm_pmu, cpu, metadata_etmv4_ro[CS_ETE_TRCDEVARCH]);
+	int trcdevarch = cs_etm_get_ro(cs_etm_pmu, cpu, metadata_ete_ro[CS_ETE_TRCDEVARCH]);
 
 	/*
 	 * ETE if ARCHVER is 5 (ARCHVER is 4 for ETM) and ARCHPART is 0xA13.
@@ -647,6 +655,31 @@ static void cs_etm_save_etmv4_header(__u64 data[], struct auxtrace_record *itr,
 						     metadata_etmv4_ro[CS_ETMV4_TRCAUTHSTATUS]);
 }
 
+static void cs_etm_save_ete_header(__u64 data[], struct auxtrace_record *itr, int cpu)
+{
+	struct cs_etm_recording *ptr = container_of(itr, struct cs_etm_recording, itr);
+	struct perf_pmu *cs_etm_pmu = ptr->cs_etm_pmu;
+
+	/* Get trace configuration register */
+	data[CS_ETE_TRCCONFIGR] = cs_etmv4_get_config(itr);
+	/* Get traceID from the framework */
+	data[CS_ETE_TRCTRACEIDR] = coresight_get_trace_id(cpu);
+	/* Get read-only information from sysFS */
+	data[CS_ETE_TRCIDR0] = cs_etm_get_ro(cs_etm_pmu, cpu,
+					     metadata_ete_ro[CS_ETE_TRCIDR0]);
+	data[CS_ETE_TRCIDR1] = cs_etm_get_ro(cs_etm_pmu, cpu,
+					     metadata_ete_ro[CS_ETE_TRCIDR1]);
+	data[CS_ETE_TRCIDR2] = cs_etm_get_ro(cs_etm_pmu, cpu,
+					     metadata_ete_ro[CS_ETE_TRCIDR2]);
+	data[CS_ETE_TRCIDR8] = cs_etm_get_ro(cs_etm_pmu, cpu,
+					     metadata_ete_ro[CS_ETE_TRCIDR8]);
+	data[CS_ETE_TRCAUTHSTATUS] = cs_etm_get_ro(cs_etm_pmu, cpu,
+						   metadata_ete_ro[CS_ETE_TRCAUTHSTATUS]);
+	/* ETE uses the same registers as ETMv4 plus TRCDEVARCH */
+	data[CS_ETE_TRCDEVARCH] = cs_etm_get_ro(cs_etm_pmu, cpu,
+						metadata_ete_ro[CS_ETE_TRCDEVARCH]);
+}
+
 static void cs_etm_get_metadata(int cpu, u32 *offset,
 				struct auxtrace_record *itr,
 				struct perf_record_auxtrace_info *info)
@@ -660,11 +693,7 @@ static void cs_etm_get_metadata(int cpu, u32 *offset,
 	/* first see what kind of tracer this cpu is affined to */
 	if (cs_etm_is_ete(itr, cpu)) {
 		magic = __perf_cs_ete_magic;
-		/* ETE uses the same registers as ETMv4 plus TRCDEVARCH */
-		cs_etm_save_etmv4_header(&info->priv[*offset], itr, cpu);
-		info->priv[*offset + CS_ETE_TRCDEVARCH] =
-			cs_etm_get_ro(cs_etm_pmu, cpu,
-				      metadata_etmv4_ro[CS_ETE_TRCDEVARCH]);
+		cs_etm_save_ete_header(&info->priv[*offset], itr, cpu);
 
 		/* How much space was used */
 		increment = CS_ETE_PRIV_MAX;
diff --git a/tools/perf/util/cs-etm.c b/tools/perf/util/cs-etm.c
index 8b95fb3c4d7b..5991a1a46b5c 100644
--- a/tools/perf/util/cs-etm.c
+++ b/tools/perf/util/cs-etm.c
@@ -464,12 +464,12 @@ static void cs_etm__set_trace_param_ete(struct cs_etm_trace_params *t_params,
 	u64 **metadata = etm->metadata;
 
 	t_params[idx].protocol = CS_ETM_PROTO_ETE;
-	t_params[idx].ete.reg_idr0 = metadata[idx][CS_ETMV4_TRCIDR0];
-	t_params[idx].ete.reg_idr1 = metadata[idx][CS_ETMV4_TRCIDR1];
-	t_params[idx].ete.reg_idr2 = metadata[idx][CS_ETMV4_TRCIDR2];
-	t_params[idx].ete.reg_idr8 = metadata[idx][CS_ETMV4_TRCIDR8];
-	t_params[idx].ete.reg_configr = metadata[idx][CS_ETMV4_TRCCONFIGR];
-	t_params[idx].ete.reg_traceidr = metadata[idx][CS_ETMV4_TRCTRACEIDR];
+	t_params[idx].ete.reg_idr0 = metadata[idx][CS_ETE_TRCIDR0];
+	t_params[idx].ete.reg_idr1 = metadata[idx][CS_ETE_TRCIDR1];
+	t_params[idx].ete.reg_idr2 = metadata[idx][CS_ETE_TRCIDR2];
+	t_params[idx].ete.reg_idr8 = metadata[idx][CS_ETE_TRCIDR8];
+	t_params[idx].ete.reg_configr = metadata[idx][CS_ETE_TRCCONFIGR];
+	t_params[idx].ete.reg_traceidr = metadata[idx][CS_ETE_TRCTRACEIDR];
 	t_params[idx].ete.reg_devarch = metadata[idx][CS_ETE_TRCDEVARCH];
 }
 
@@ -2537,7 +2537,20 @@ static const char * const cs_etmv4_priv_fmts[] = {
 	[CS_ETMV4_TRCIDR2]	= "	TRCIDR2			       %llx\n",
 	[CS_ETMV4_TRCIDR8]	= "	TRCIDR8			       %llx\n",
 	[CS_ETMV4_TRCAUTHSTATUS] = "	TRCAUTHSTATUS		       %llx\n",
-	[CS_ETE_TRCDEVARCH]	= "	TRCDEVARCH                     %llx\n"
+};
+
+static const char * const cs_ete_priv_fmts[] = {
+	[CS_ETM_MAGIC]		= "	Magic number		       %llx\n",
+	[CS_ETM_CPU]		= "	CPU			       %lld\n",
+	[CS_ETM_NR_TRC_PARAMS]	= "	NR_TRC_PARAMS		       %llx\n",
+	[CS_ETE_TRCCONFIGR]	= "	TRCCONFIGR		       %llx\n",
+	[CS_ETE_TRCTRACEIDR]	= "	TRCTRACEIDR		       %llx\n",
+	[CS_ETE_TRCIDR0]	= "	TRCIDR0			       %llx\n",
+	[CS_ETE_TRCIDR1]	= "	TRCIDR1			       %llx\n",
+	[CS_ETE_TRCIDR2]	= "	TRCIDR2			       %llx\n",
+	[CS_ETE_TRCIDR8]	= "	TRCIDR8			       %llx\n",
+	[CS_ETE_TRCAUTHSTATUS] = "	TRCAUTHSTATUS		       %llx\n",
+	[CS_ETE_TRCDEVARCH]	= "	TRCDEVARCH                     %llx\n",
 };
 
 static const char * const param_unk_fmt =
@@ -2597,19 +2610,22 @@ static int cs_etm__print_cpu_metadata_v1(__u64 *val, int *offset)
 			else
 				fprintf(stdout, cs_etm_priv_fmts[j], val[i]);
 		}
-	} else if (magic == __perf_cs_etmv4_magic || magic == __perf_cs_ete_magic) {
-		/*
-		 * ETE and ETMv4 can be printed in the same block because the number of parameters
-		 * is saved and they share the list of parameter names. ETE is also only supported
-		 * in V1 files.
-		 */
+	} else if (magic == __perf_cs_etmv4_magic) {
 		for (j = 0; j < total_params; j++, i++) {
 			/* if newer record - could be excess params */
-			if (j >= CS_ETE_PRIV_MAX)
+			if (j >= CS_ETMV4_PRIV_MAX)
 				fprintf(stdout, param_unk_fmt, j, val[i]);
 			else
 				fprintf(stdout, cs_etmv4_priv_fmts[j], val[i]);
 		}
+	} else if (magic == __perf_cs_ete_magic) {
+		for (j = 0; j < total_params; j++, i++) {
+			/* if newer record - could be excess params */
+			if (j >= CS_ETE_PRIV_MAX)
+				fprintf(stdout, param_unk_fmt, j, val[i]);
+			else
+				fprintf(stdout, cs_ete_priv_fmts[j], val[i]);
+		}
 	} else {
 		/* failure - note bad magic value and error out */
 		fprintf(stdout, magic_unk_fmt, magic);
diff --git a/tools/perf/util/cs-etm.h b/tools/perf/util/cs-etm.h
index 90c83f932d9a..817d068de98c 100644
--- a/tools/perf/util/cs-etm.h
+++ b/tools/perf/util/cs-etm.h
@@ -81,7 +81,16 @@ enum {
  * added in header V1
  */
 enum {
-	CS_ETE_TRCDEVARCH = CS_ETMV4_PRIV_MAX,
+	/* Dynamic, configurable parameters */
+	CS_ETE_TRCCONFIGR = CS_ETM_COMMON_BLK_MAX_V1,
+	CS_ETE_TRCTRACEIDR,
+	/* RO, taken from sysFS */
+	CS_ETE_TRCIDR0,
+	CS_ETE_TRCIDR1,
+	CS_ETE_TRCIDR2,
+	CS_ETE_TRCIDR8,
+	CS_ETE_TRCAUTHSTATUS,
+	CS_ETE_TRCDEVARCH,
 	CS_ETE_PRIV_MAX
 };
 
-- 
2.25.1

[PATCH 3/4] perf cs_etm: Record ts_source in AUXTRACE_INFO for ETMv4 and ETE

[German Gomez]

Read the value of ts_source exposed by the driver and store it in the
ETMv4 and ETE header. If the interface doesn't exist (such as in older
Kernels), defaults to a safe value of -1.

Signed-off-by: German Gomez <german.gomez@arm.com>
---
 tools/perf/arch/arm/util/cs-etm.c | 46 +++++++++++++++++++++++++++++++
 tools/perf/util/cs-etm.c          |  2 ++
 tools/perf/util/cs-etm.h          |  2 ++
 3 files changed, 50 insertions(+)

diff --git a/tools/perf/arch/arm/util/cs-etm.c b/tools/perf/arch/arm/util/cs-etm.c
index 4899eb549b4d..f063fece90c3 100644
--- a/tools/perf/arch/arm/util/cs-etm.c
+++ b/tools/perf/arch/arm/util/cs-etm.c
@@ -53,6 +53,7 @@ static const char * const metadata_etmv4_ro[] = {
 	[CS_ETMV4_TRCIDR2]		= "trcidr/trcidr2",
 	[CS_ETMV4_TRCIDR8]		= "trcidr/trcidr8",
 	[CS_ETMV4_TRCAUTHSTATUS]	= "mgmt/trcauthstatus",
+	[CS_ETMV4_TS_SOURCE]		= "ts_source",
 };
 
 static const char * const metadata_ete_ro[] = {
@@ -62,6 +63,7 @@ static const char * const metadata_ete_ro[] = {
 	[CS_ETE_TRCIDR8]		= "trcidr/trcidr8",
 	[CS_ETE_TRCAUTHSTATUS]		= "mgmt/trcauthstatus",
 	[CS_ETE_TRCDEVARCH]		= "mgmt/trcdevarch",
+	[CS_ETE_TS_SOURCE]		= "ts_source",
 };
 
 static bool cs_etm_is_etmv4(struct auxtrace_record *itr, int cpu);
@@ -612,6 +614,32 @@ static int cs_etm_get_ro(struct perf_pmu *pmu, int cpu, const char *path)
 	return val;
 }
 
+static int cs_etm_get_ro_signed(struct perf_pmu *pmu, int cpu, const char *path)
+{
+	char pmu_path[PATH_MAX];
+	int scan;
+	int val = 0;
+
+	/* Get RO metadata from sysfs */
+	snprintf(pmu_path, PATH_MAX, "cpu%d/%s", cpu, path);
+
+	scan = perf_pmu__scan_file(pmu, pmu_path, "%d", &val);
+	if (scan != 1)
+		pr_err("%s: error reading: %s\n", __func__, pmu_path);
+
+	return val;
+}
+
+static bool cs_etm_pmu_path_exists(struct perf_pmu *pmu, int cpu, const char *path)
+{
+	char pmu_path[PATH_MAX];
+
+	/* Get RO metadata from sysfs */
+	snprintf(pmu_path, PATH_MAX, "cpu%d/%s", cpu, path);
+
+	return perf_pmu__file_exists(pmu, pmu_path);
+}
+
 #define TRCDEVARCH_ARCHPART_SHIFT 0
 #define TRCDEVARCH_ARCHPART_MASK  GENMASK(11, 0)
 #define TRCDEVARCH_ARCHPART(x)    (((x) & TRCDEVARCH_ARCHPART_MASK) >> TRCDEVARCH_ARCHPART_SHIFT)
@@ -653,6 +681,15 @@ static void cs_etm_save_etmv4_header(__u64 data[], struct auxtrace_record *itr,
 					       metadata_etmv4_ro[CS_ETMV4_TRCIDR8]);
 	data[CS_ETMV4_TRCAUTHSTATUS] = cs_etm_get_ro(cs_etm_pmu, cpu,
 						     metadata_etmv4_ro[CS_ETMV4_TRCAUTHSTATUS]);
+
+	/* Kernels older than 5.19 may not expose ts_source */
+	if (cs_etm_pmu_path_exists(cs_etm_pmu, cpu, metadata_etmv4_ro[CS_ETMV4_TS_SOURCE]))
+		data[CS_ETMV4_TS_SOURCE] = (__u64) cs_etm_get_ro_signed(cs_etm_pmu, cpu,
+				metadata_etmv4_ro[CS_ETMV4_TS_SOURCE]);
+	else {
+		pr_warning("[%03d] pmu file 'ts_source' not found. Fallback to safe value (-1)\n", cpu);
+		data[CS_ETMV4_TS_SOURCE] = (__u64) -1;
+	}
 }
 
 static void cs_etm_save_ete_header(__u64 data[], struct auxtrace_record *itr, int cpu)
@@ -678,6 +715,15 @@ static void cs_etm_save_ete_header(__u64 data[], struct auxtrace_record *itr, in
 	/* ETE uses the same registers as ETMv4 plus TRCDEVARCH */
 	data[CS_ETE_TRCDEVARCH] = cs_etm_get_ro(cs_etm_pmu, cpu,
 						metadata_ete_ro[CS_ETE_TRCDEVARCH]);
+
+	/* Kernels older than 5.19 may not expose ts_source */
+	if (cs_etm_pmu_path_exists(cs_etm_pmu, cpu, metadata_ete_ro[CS_ETE_TS_SOURCE]))
+		data[CS_ETE_TS_SOURCE] = (__u64) cs_etm_get_ro_signed(cs_etm_pmu, cpu,
+				metadata_ete_ro[CS_ETE_TS_SOURCE]);
+	else {
+		pr_warning("[%03d] pmu file 'ts_source' not found. Fallback to safe value (-1)\n", cpu);
+		data[CS_ETE_TS_SOURCE] = (__u64) -1;
+	}
 }
 
 static void cs_etm_get_metadata(int cpu, u32 *offset,
diff --git a/tools/perf/util/cs-etm.c b/tools/perf/util/cs-etm.c
index 5991a1a46b5c..e883ef6d9c75 100644
--- a/tools/perf/util/cs-etm.c
+++ b/tools/perf/util/cs-etm.c
@@ -2537,6 +2537,7 @@ static const char * const cs_etmv4_priv_fmts[] = {
 	[CS_ETMV4_TRCIDR2]	= "	TRCIDR2			       %llx\n",
 	[CS_ETMV4_TRCIDR8]	= "	TRCIDR8			       %llx\n",
 	[CS_ETMV4_TRCAUTHSTATUS] = "	TRCAUTHSTATUS		       %llx\n",
+	[CS_ETMV4_TS_SOURCE] = "	TS_SOURCE		       %lld\n",
 };
 
 static const char * const cs_ete_priv_fmts[] = {
@@ -2551,6 +2552,7 @@ static const char * const cs_ete_priv_fmts[] = {
 	[CS_ETE_TRCIDR8]	= "	TRCIDR8			       %llx\n",
 	[CS_ETE_TRCAUTHSTATUS] = "	TRCAUTHSTATUS		       %llx\n",
 	[CS_ETE_TRCDEVARCH]	= "	TRCDEVARCH                     %llx\n",
+	[CS_ETE_TS_SOURCE]	= "	TS_SOURCE                      %lld\n",
 };
 
 static const char * const param_unk_fmt =
diff --git a/tools/perf/util/cs-etm.h b/tools/perf/util/cs-etm.h
index 817d068de98c..35b783178347 100644
--- a/tools/perf/util/cs-etm.h
+++ b/tools/perf/util/cs-etm.h
@@ -70,6 +70,7 @@ enum {
 	CS_ETMV4_TRCIDR2,
 	CS_ETMV4_TRCIDR8,
 	CS_ETMV4_TRCAUTHSTATUS,
+	CS_ETMV4_TS_SOURCE,
 	CS_ETMV4_PRIV_MAX,
 };
 
@@ -91,6 +92,7 @@ enum {
 	CS_ETE_TRCIDR8,
 	CS_ETE_TRCAUTHSTATUS,
 	CS_ETE_TRCDEVARCH,
+	CS_ETE_TS_SOURCE,
 	CS_ETE_PRIV_MAX
 };
 
-- 
2.25.1

[PATCH 4/4] perf cs_etm: Set the time field in the synthetic samples

[German Gomez]

If virtual timestamps are detected, set sample time field accordingly,
otherwise warn the user that the samples will not include the time data.

 | Test notes (FEAT_TRF platform)
 |
 | $ ./perf record -e cs_etm//u -a -- sleep 4
 | $ ./perf script --fields +time
 | 	    perf   422 [000]   163.375100:          1 branches:uH:                 0 [unknown] ([unknown])
 | 	    perf   422 [000]   163.375100:          1 branches:uH:      ffffb8009544 ioctl+0x14 (/lib/aarch64-linux-gnu/libc-2.27.so)
 | 	    perf   422 [000]   163.375100:          1 branches:uH:      aaaaab6bebf4 perf_evsel__run_ioctl+0x90 (/home/german/linux/tools/perf/perf)
 | [...]
 | 	    perf   422 [000]   167.393100:          1 branches:uH:      aaaaab6bda00 __xyarray__entry+0x74 (/home/german/linux/tools/perf/perf)
 | 	    perf   422 [000]   167.393099:          1 branches:uH:      aaaaab6bda0c __xyarray__entry+0x80 (/home/german/linux/tools/perf/perf)
 | 	    perf   422 [000]   167.393099:          1 branches:uH:      ffffb8009538 ioctl+0x8 (/lib/aarch64-linux-gnu/libc-2.27.so)
 |
 | The time from the first sample to the last sample is 4 seconds

Signed-off-by: German Gomez <german.gomez@arm.com>
---
 tools/perf/util/cs-etm.c | 80 ++++++++++++++++++++++++++++++++++++++--
 1 file changed, 76 insertions(+), 4 deletions(-)

diff --git a/tools/perf/util/cs-etm.c b/tools/perf/util/cs-etm.c
index e883ef6d9c75..ace4ba3256df 100644
--- a/tools/perf/util/cs-etm.c
+++ b/tools/perf/util/cs-etm.c
@@ -35,6 +35,7 @@
 #include "tool.h"
 #include "thread.h"
 #include "thread-stack.h"
+#include "tsc.h"
 #include <tools/libc_compat.h>
 #include "util/synthetic-events.h"
 
@@ -46,10 +47,12 @@ struct cs_etm_auxtrace {
 	struct perf_session *session;
 	struct machine *machine;
 	struct thread *unknown_thread;
+	struct perf_tsc_conversion tc;
 
 	u8 timeless_decoding;
 	u8 snapshot_mode;
 	u8 data_queued;
+	u8 has_virtual_ts; /* Virtual/Kernel timestamps in the trace. */
 
 	int num_cpu;
 	u64 latest_kernel_timestamp;
@@ -1161,6 +1164,22 @@ static void cs_etm__copy_insn(struct cs_etm_queue *etmq,
 			   sample->insn_len, (void *)sample->insn);
 }
 
+static inline void cs_etm__resolve_sample_time(struct cs_etm_queue *etmq,
+					       struct cs_etm_traceid_queue *tidq,
+					       u64 *time)
+{
+	struct cs_etm_auxtrace *etm = etmq->etm;
+	struct cs_etm_packet_queue *packet_queue = &tidq->packet_queue;
+
+	if (etm->timeless_decoding)
+		*time = 0;
+	else if (etm->has_virtual_ts)
+		*time = tsc_to_perf_time(packet_queue->cs_timestamp, &etm->tc);
+	else
+		*time = etm->latest_kernel_timestamp;
+
+}
+
 static int cs_etm__synth_instruction_sample(struct cs_etm_queue *etmq,
 					    struct cs_etm_traceid_queue *tidq,
 					    u64 addr, u64 period)
@@ -1174,8 +1193,9 @@ static int cs_etm__synth_instruction_sample(struct cs_etm_queue *etmq,
 	event->sample.header.misc = cs_etm__cpu_mode(etmq, addr);
 	event->sample.header.size = sizeof(struct perf_event_header);
 
-	if (!etm->timeless_decoding)
-		sample.time = etm->latest_kernel_timestamp;
+	/* Set time field based con etm auxtrace config. */
+	cs_etm__resolve_sample_time(etmq, tidq, &sample.time);
+
 	sample.ip = addr;
 	sample.pid = tidq->pid;
 	sample.tid = tidq->tid;
@@ -1232,8 +1252,9 @@ static int cs_etm__synth_branch_sample(struct cs_etm_queue *etmq,
 	event->sample.header.misc = cs_etm__cpu_mode(etmq, ip);
 	event->sample.header.size = sizeof(struct perf_event_header);
 
-	if (!etm->timeless_decoding)
-		sample.time = etm->latest_kernel_timestamp;
+	/* Set time field based con etm auxtrace config. */
+	cs_etm__resolve_sample_time(etmq, tidq, &sample.time);
+
 	sample.ip = ip;
 	sample.pid = tidq->pid;
 	sample.tid = tidq->tid;
@@ -2899,12 +2920,46 @@ static int cs_etm__queue_aux_records(struct perf_session *session)
 	return 0;
 }
 
+/*
+ * Loop through the ETMs and complain if we find at least one where ts_source != 1 (virtual
+ * timestamps).
+ */
+static bool cs_etm__has_virtual_ts(u64 **metadata, int num_cpu)
+{
+	int j;
+
+	for (j = 0; j < num_cpu; j++) {
+
+#define HAS_PARAM(j, type, param) (metadata[(j)][CS_ETM_NR_TRC_PARAMS] <= (CS_##type##_##param - CS_ETM_COMMON_BLK_MAX_V1))
+
+		switch (metadata[j][CS_ETM_MAGIC]) {
+		case __perf_cs_etmv4_magic:
+			if (HAS_PARAM(j, ETMV4, TS_SOURCE) || metadata[j][CS_ETMV4_TS_SOURCE] != 1)
+				return false;
+			break;
+		case __perf_cs_ete_magic:
+			if (HAS_PARAM(j, ETE, TS_SOURCE) || metadata[j][CS_ETE_TS_SOURCE] != 1)
+				return false;
+			break;
+		default:
+			/* Unknown / unsupported magic number. */
+			return false;
+		}
+
+#undef HAS_PARAM
+
+	}
+
+	return true;
+}
+
 int cs_etm__process_auxtrace_info(union perf_event *event,
 				  struct perf_session *session)
 {
 	struct perf_record_auxtrace_info *auxtrace_info = &event->auxtrace_info;
 	struct cs_etm_auxtrace *etm = NULL;
 	struct int_node *inode;
+	struct perf_record_time_conv *tc = &session->time_conv;
 	unsigned int pmu_type;
 	int event_header_size = sizeof(struct perf_event_header);
 	int info_header_size;
@@ -3071,6 +3126,13 @@ int cs_etm__process_auxtrace_info(union perf_event *event,
 	etm->auxtrace_type = auxtrace_info->type;
 	etm->timeless_decoding = cs_etm__is_timeless_decoding(etm);
 
+	/* Use virtual timestamps if all ETMs report ts_source = 1 */
+	etm->has_virtual_ts = cs_etm__has_virtual_ts(metadata, num_cpu);
+
+	if (!etm->has_virtual_ts)
+		ui__warning("Virtual timestamps are not enabled, or not supported by the traced system.\n\n"
+			    "The time field of the samples will not be set.\n\n");
+
 	etm->auxtrace.process_event = cs_etm__process_event;
 	etm->auxtrace.process_auxtrace_event = cs_etm__process_auxtrace_event;
 	etm->auxtrace.flush_events = cs_etm__flush_events;
@@ -3100,6 +3162,16 @@ int cs_etm__process_auxtrace_info(union perf_event *event,
 		goto err_delete_thread;
 	}
 
+	etm->tc.time_shift = tc->time_shift;
+	etm->tc.time_mult = tc->time_mult;
+	etm->tc.time_zero = tc->time_zero;
+	if (event_contains(*tc, time_cycles)) {
+		etm->tc.time_cycles = tc->time_cycles;
+		etm->tc.time_mask = tc->time_mask;
+		etm->tc.cap_user_time_zero = tc->cap_user_time_zero;
+		etm->tc.cap_user_time_short = tc->cap_user_time_short;
+	}
+
 	if (dump_trace) {
 		cs_etm__print_auxtrace_info(auxtrace_info->priv, num_cpu);
 	}
-- 
2.25.1

Re: [PATCH 0/4] perf cs_etm: Basic support for virtual/kernel timestamps

[Mike Leach]

Hi German,

On Wed, 4 May 2022 at 16:02, German Gomez <german.gomez@arm.com> wrote:
>
> Hi,
>
> This change has a soft dependency on [1], but assuming the name/location
> of the new sysfs interface (ts_source) doesn't change, it should be safe
> to apply.
>
> The new 'ts_source' interface allows perf to detect if the timestamps in
> the trace correspond to the value of CNTVCT_EL0, which we can convert to
> a perf timestamp and store it in the instruction and branch samples.
>
> Due to the way the trace is compressed and decoded by OpenCSD, we only
> know the precise time of the first instruction in a range, but I think
> for now this is better than not having timestamps at all...
>

The output of OpenCSD is reflective of the architecture of the trace hardware.

Timestamps in the trace are always associated with waypoint elements -
primarily branches.
Hardware trace compression results in only these elements being
output, i.e. E / N atoms representing branches taken or not taken.
Instructions between branches have no explicit element appearing in
the trace.
The decode process implies all the instructions between these elements
to form a range of executed instructions, hence the timestamp being
associated with the first instruction in a range.
Moreover, even though we may request a high timestamp rate, output of
other trace is prioritised over timestamp trace, so there is never any
guarantee that we can force timestamps to appear at the start of every
range.

Any attempt to increase number of timestamps in a trace range would
have to be done by some software interpolation mechanism

Regards

Mike


> Thanks,
> German
>
> [1] https://lore.kernel.org/all/20220503123537.1003035-1-german.gomez@arm.com/
>
> German Gomez (4):
>   perf pmu: Add function to check if a pmu file exists
>   perf cs_etm: Keep separate symbols for ETMv4 and ETE parameters
>   perf cs_etm: Record ts_source in AUXTRACE_INFO for ETMv4 and ETE
>   perf cs_etm: Set the time field in the synthetic samples
>
>  tools/perf/arch/arm/util/cs-etm.c |  89 +++++++++++++++++++--
>  tools/perf/util/cs-etm.c          | 126 +++++++++++++++++++++++++-----
>  tools/perf/util/cs-etm.h          |  13 ++-
>  tools/perf/util/pmu.c             |  17 ++++
>  tools/perf/util/pmu.h             |   2 +
>  5 files changed, 221 insertions(+), 26 deletions(-)
>
> --
> 2.25.1
>


--
Mike Leach
Principal Engineer, ARM Ltd.
Manchester Design Centre. UK

Re: [PATCH 1/4] perf pmu: Add function to check if a pmu file exists

[Arnaldo Carvalho de Melo]

Em Wed, May 04, 2022 at 04:02:12PM +0100, German Gomez escreveu:
> Add a utility function perf_pmu__file_exists() to check if a given pmu
> file exists in the sysfs filesystem.

While reviewing this I noticed:

int perf_pmu__caps_parse(struct perf_pmu *pmu)
{
        struct stat st;
        char caps_path[PATH_MAX];
        const char *sysfs = sysfs__mountpoint();
        DIR *caps_dir;
        struct dirent *evt_ent;
        int nr_caps = 0;

        if (!sysfs)
                return -1;

        snprintf(caps_path, PATH_MAX,
                 "%s" EVENT_SOURCE_DEVICE_PATH "%s/caps", sysfs, pmu->name);

        if (stat(caps_path, &st) < 0)
                return 0;       /* no error if caps does not exist */


------------------------

Shouldn't we introduce a:

const int perf__pmu_pathname_scnprintf(struct perf_pmu *pmu, char *pathname, size_t size, char *filename)
{

	return scnprintf(pathname, size, "%s" EVENT_SOURCE_DEVICE_PATH "%s/%s", sysfs, pmu->name, filename);
}

And use in your perf_pmu__file_exists() and in the other places where
this open coded pattern appears?

I'm waiting for reviews for the ARM specific bits.

- Arnaldo
 
> Signed-off-by: German Gomez <german.gomez@arm.com>
> ---
>  tools/perf/util/pmu.c | 17 +++++++++++++++++
>  tools/perf/util/pmu.h |  2 ++
>  2 files changed, 19 insertions(+)
> 
> diff --git a/tools/perf/util/pmu.c b/tools/perf/util/pmu.c
> index 9a1c7e63e663..9479e9a4da54 100644
> --- a/tools/perf/util/pmu.c
> +++ b/tools/perf/util/pmu.c
> @@ -1854,6 +1854,23 @@ int perf_pmu__scan_file(struct perf_pmu *pmu, const char *name, const char *fmt,
>  	return ret;
>  }
>  
> +bool perf_pmu__file_exists(struct perf_pmu *pmu, const char *name)
> +{
> +	char path[PATH_MAX];
> +	struct stat statbuf;
> +	const char *sysfs = sysfs__mountpoint();
> +
> +	if (!sysfs)
> +		return false;
> +
> +	snprintf(path, PATH_MAX,
> +		 "%s" EVENT_SOURCE_DEVICE_PATH "%s/%s", sysfs, pmu->name, name);
> +	if (!file_available(path))
> +		return false;
> +
> +	return stat(path, &statbuf) == 0;
> +}
> +
>  static int perf_pmu__new_caps(struct list_head *list, char *name, char *value)
>  {
>  	struct perf_pmu_caps *caps = zalloc(sizeof(*caps));
> diff --git a/tools/perf/util/pmu.h b/tools/perf/util/pmu.h
> index 541889fa9f9c..ab728eaf13b6 100644
> --- a/tools/perf/util/pmu.h
> +++ b/tools/perf/util/pmu.h
> @@ -120,6 +120,8 @@ bool pmu_have_event(const char *pname, const char *name);
>  
>  int perf_pmu__scan_file(struct perf_pmu *pmu, const char *name, const char *fmt, ...) __scanf(3, 4);
>  
> +bool perf_pmu__file_exists(struct perf_pmu *pmu, const char *name);
> +
>  int perf_pmu__test(void);
>  
>  struct perf_event_attr *perf_pmu__get_default_config(struct perf_pmu *pmu);
> -- 
> 2.25.1

-- 

- Arnaldo

Re: [PATCH 1/4] perf pmu: Add function to check if a pmu file exists

[German Gomez]

Hi Arnaldo, thanks for the review

On 10/05/2022 17:41, Arnaldo Carvalho de Melo wrote:
> Em Wed, May 04, 2022 at 04:02:12PM +0100, German Gomez escreveu:
>> Add a utility function perf_pmu__file_exists() to check if a given pmu
>> file exists in the sysfs filesystem.
> While reviewing this I noticed:
>
> int perf_pmu__caps_parse(struct perf_pmu *pmu)
> {
>         struct stat st;
>         char caps_path[PATH_MAX];
>         const char *sysfs = sysfs__mountpoint();
>         DIR *caps_dir;
>         struct dirent *evt_ent;
>         int nr_caps = 0;
>
>         if (!sysfs)
>                 return -1;
>
>         snprintf(caps_path, PATH_MAX,
>                  "%s" EVENT_SOURCE_DEVICE_PATH "%s/caps", sysfs, pmu->name);
>
>         if (stat(caps_path, &st) < 0)
>                 return 0;       /* no error if caps does not exist */
>
>
> ------------------------
>
> Shouldn't we introduce a:
>
> const int perf__pmu_pathname_scnprintf(struct perf_pmu *pmu, char *pathname, size_t size, char *filename)
> {
>
> 	return scnprintf(pathname, size, "%s" EVENT_SOURCE_DEVICE_PATH "%s/%s", sysfs, pmu->name, filename);
> }
>
> And use in your perf_pmu__file_exists() and in the other places where
> this open coded pattern appears?

I agree. If nobody else has done it before me, I will send the refactor
in the next respin.

Thanks,
German

>
> I'm waiting for reviews for the ARM specific bits.
>
> - Arnaldo
>  
>> Signed-off-by: German Gomez <german.gomez@arm.com>
>> ---
>>  tools/perf/util/pmu.c | 17 +++++++++++++++++
>>  tools/perf/util/pmu.h |  2 ++
>>  2 files changed, 19 insertions(+)
>>
>> diff --git a/tools/perf/util/pmu.c b/tools/perf/util/pmu.c
>> index 9a1c7e63e663..9479e9a4da54 100644
>> --- a/tools/perf/util/pmu.c
>> +++ b/tools/perf/util/pmu.c
>> @@ -1854,6 +1854,23 @@ int perf_pmu__scan_file(struct perf_pmu *pmu, const char *name, const char *fmt,
>>  	return ret;
>>  }
>>  
>> +bool perf_pmu__file_exists(struct perf_pmu *pmu, const char *name)
>> +{
>> +	char path[PATH_MAX];
>> +	struct stat statbuf;
>> +	const char *sysfs = sysfs__mountpoint();
>> +
>> +	if (!sysfs)
>> +		return false;
>> +
>> +	snprintf(path, PATH_MAX,
>> +		 "%s" EVENT_SOURCE_DEVICE_PATH "%s/%s", sysfs, pmu->name, name);
>> +	if (!file_available(path))
>> +		return false;
>> +
>> +	return stat(path, &statbuf) == 0;
>> +}
>> +
>>  static int perf_pmu__new_caps(struct list_head *list, char *name, char *value)
>>  {
>>  	struct perf_pmu_caps *caps = zalloc(sizeof(*caps));
>> diff --git a/tools/perf/util/pmu.h b/tools/perf/util/pmu.h
>> index 541889fa9f9c..ab728eaf13b6 100644
>> --- a/tools/perf/util/pmu.h
>> +++ b/tools/perf/util/pmu.h
>> @@ -120,6 +120,8 @@ bool pmu_have_event(const char *pname, const char *name);
>>  
>>  int perf_pmu__scan_file(struct perf_pmu *pmu, const char *name, const char *fmt, ...) __scanf(3, 4);
>>  
>> +bool perf_pmu__file_exists(struct perf_pmu *pmu, const char *name);
>> +
>>  int perf_pmu__test(void);
>>  
>>  struct perf_event_attr *perf_pmu__get_default_config(struct perf_pmu *pmu);
>> -- 
>> 2.25.1