Re: [PATCH 2/6] perf tools: Store clock references for -k/--clockid option

[Namhyung Kim]

On Thu, Jul 30, 2020 at 11:39:46PM +0200, Jiri Olsa wrote:
> Adding new CLOCK_DATA feature that stores reference times
> when -k/--clockid option is specified.
> 
> It contains clock id and its reference time together with
> wall clock time taken at the 'same time', both values are
> in nanoseconds.
> 
> The format of data is as below:
> 
>   struct {
>        u32 version;  /* version = 1 */
>        u32 clockid;
>        u64 clockid_time_ns;
>        u64 wall_clock_ns;
>   };
> 
> This clock reference times will be used in following changes
> to display wall clock for perf events.
> 
> It's available only for recording with clockid specified,
> because it's the only case where we can get reference time
> to wallclock time. It's can't do that with perf clock yet.
> 
> Original-patch-by: David Ahern <dsahern@xxxxxxxxx>
> Signed-off-by: Jiri Olsa <jolsa@xxxxxxxxxx>
> ---
>  .../Documentation/perf.data-file-format.txt   |  13 ++
>  tools/perf/builtin-record.c                   |  41 +++++++
>  tools/perf/util/env.h                         |  12 ++
>  tools/perf/util/header.c                      | 112 ++++++++++++++++++
>  tools/perf/util/header.h                      |   1 +
>  5 files changed, 179 insertions(+)
> 
> diff --git a/tools/perf/Documentation/perf.data-file-format.txt b/tools/perf/Documentation/perf.data-file-format.txt
> index b6472e463284..c484e81987c7 100644
> --- a/tools/perf/Documentation/perf.data-file-format.txt
> +++ b/tools/perf/Documentation/perf.data-file-format.txt
> @@ -389,6 +389,19 @@ struct {
>  Example:
>   cpu pmu capabilities: branches=32, max_precise=3, pmu_name=icelake
>  
> +	HEADER_CLOCK_DATA = 29,
> +
> +	Contains clock id and its reference time together with wall clock
> +	time taken at the 'same time', both values are in nanoseconds.
> +	The format of data is as below.
> +
> +struct {
> +	u32 version;  /* version = 1 */
> +	u32 clockid;
> +	u64 clockid_time_ns;
> +	u64 wall_clock_ns;
> +};
> +

It seems that it's slightly different than what it actually write to a file.
Specifically the last two fields should be reversed IMHO.


>  	other bits are reserved and should ignored for now
>  	HEADER_FEAT_BITS	= 256,
>
[SNIP]

> diff --git a/tools/perf/util/env.h b/tools/perf/util/env.h
> index 1ab2682d5d2b..4098a63d5e64 100644
> --- a/tools/perf/util/env.h
> +++ b/tools/perf/util/env.h
> @@ -100,6 +100,18 @@ struct perf_env {
>  	/* For fast cpu to numa node lookup via perf_env__numa_node */
>  	int			*numa_map;
>  	int			 nr_numa_map;
> +
> +	/* For real clock time refference. */

typo: reference

> +	struct {
> +		u64	tod_ns;
> +		u64	clockid_ns;
> +		int	clockid;
> +		/*
> +		 * enabled is valid for report mode, and is true if above
> +		 * values are set, it's set in process_clock_data
> +		 */
> +		bool	enabled;
> +	} clock;
>  };
>  
>  enum perf_compress_type {

[SNIP]
> +static void print_clock_data(struct feat_fd *ff, FILE *fp)
> +{
> +	struct timespec clockid_ns;
> +	char tstr[64], date[64];
> +	struct timeval tod_ns;
> +	clockid_t clockid;
> +	struct tm ltime;
> +	u64 ref;
> +
> +	if (!ff->ph->env.clock.enabled) {
> +		fprintf(fp, "# reference time disabled\n");
> +		return;
> +	}
> +
> +	/* Compute TOD time. */
> +	ref = ff->ph->env.clock.tod_ns;
> +	tod_ns.tv_sec = ref / NSEC_PER_SEC;
> +	ref -= tod_ns.tv_sec * NSEC_PER_SEC;
> +	tod_ns.tv_usec = ref / NSEC_PER_USEC;
> +
> +	/* Compute clockid time. */
> +	ref = ff->ph->env.clock.clockid_ns;
> +	clockid_ns.tv_sec = ref / NSEC_PER_SEC;
> +	ref -= clockid_ns.tv_sec * NSEC_PER_SEC;
> +	clockid_ns.tv_nsec = ref;
> +
> +	clockid = ff->ph->env.clock.clockid;
> +
> +	if (localtime_r(&tod_ns.tv_sec, &ltime) == NULL)
> +		snprintf(tstr, sizeof(tstr), "<error>");
> +	else {
> +		strftime(date, sizeof(date), "%F %T", &ltime);
> +		scnprintf(tstr, sizeof(tstr), "%s.%06d",
> +			  date, (int) tod_ns.tv_usec);
> +	}
> +
> +	fprintf(fp, "# clockid: %s (%u)\n", clockid_name(clockid), clockid);
> +	fprintf(fp, "# reference time: %s = %ld.%06d (TOD) = %ld.%ld (%s)\n",

Shouldn't the last one be %ld.%09ld?

Thanks
Namhyung


> +		    tstr, tod_ns.tv_sec, (int) tod_ns.tv_usec,
> +		    clockid_ns.tv_sec, clockid_ns.tv_nsec,
> +		    clockid_name(clockid));
> +}
> +
>  static void print_dir_format(struct feat_fd *ff, FILE *fp)
>  {
>  	struct perf_session *session;
> @@ -2738,6 +2815,40 @@ static int process_clockid(struct feat_fd *ff,
>  	return 0;
>  }
>  
> +static int process_clock_data(struct feat_fd *ff,
> +			      void *_data __maybe_unused)
> +{
> +	u32 data32;
> +	u64 data64;
> +
> +	/* version */
> +	if (do_read_u32(ff, &data32))
> +		return -1;
> +
> +	if (data32 != 1)
> +		return -1;
> +
> +	/* clockid */
> +	if (do_read_u32(ff, &data32))
> +		return -1;
> +
> +	ff->ph->env.clock.clockid = data32;
> +
> +	/* TOD ref time */
> +	if (do_read_u64(ff, &data64))
> +		return -1;
> +
> +	ff->ph->env.clock.tod_ns = data64;
> +
> +	/* clockid ref time */
> +	if (do_read_u64(ff, &data64))
> +		return -1;
> +
> +	ff->ph->env.clock.clockid_ns = data64;
> +	ff->ph->env.clock.enabled = true;
> +	return 0;
> +}
> +
>  static int process_dir_format(struct feat_fd *ff,
>  			      void *_data __maybe_unused)
>  {
> @@ -3008,6 +3119,7 @@ const struct perf_header_feature_ops feat_ops[HEADER_LAST_FEATURE] = {
>  	FEAT_OPR(BPF_BTF,       bpf_btf,        false),
>  	FEAT_OPR(COMPRESSED,	compressed,	false),
>  	FEAT_OPR(CPU_PMU_CAPS,	cpu_pmu_caps,	false),
> +	FEAT_OPR(CLOCK_DATA,	clock_data,	false),
>  };
>  
>  struct header_print_data {
> diff --git a/tools/perf/util/header.h b/tools/perf/util/header.h
> index 650bd1c7a99b..2aca71763ecf 100644
> --- a/tools/perf/util/header.h
> +++ b/tools/perf/util/header.h
> @@ -44,6 +44,7 @@ enum {
>  	HEADER_BPF_BTF,
>  	HEADER_COMPRESSED,
>  	HEADER_CPU_PMU_CAPS,
> +	HEADER_CLOCK_DATA,
>  	HEADER_LAST_FEATURE,
>  	HEADER_FEAT_BITS	= 256,
>  };
> -- 
> 2.25.4