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(-)
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);
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
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
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 };
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 };
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); }
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
-
Arnaldo Carvalho de Melo -
German Gomez -
Mike Leach