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

2020-08-03 Thread Jiri Olsa
On Mon, Aug 03, 2020 at 12:55:50PM +0900, Namhyung Kim wrote:

SNIP

> > 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.

oops, you're right.. wil fix in new version

> 
> 
> > 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

ok

SNIP

> > +   else {
> > +   strftime(date, sizeof(date), "%F %T", );
> > +   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?

sure, why not

thanks,
jirka



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

2020-08-02 Thread 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 
> Signed-off-by: Jiri Olsa 
> ---
>  .../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
> +  */
> + boolenabled;
> + } 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(_ns.tv_sec, ) == NULL)
> + snprintf(tstr, sizeof(tstr), "");
> + else {
> + strftime(date, sizeof(date), "%F %T", );
> + 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, ))
> + 

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

2020-07-31 Thread David Ahern
On 7/31/20 10:15 AM, Jiri Olsa wrote:
>> It might also want to be implemented in a loop and iteration with minimal
>> time delta is chosen to improve synchronization accuracy and also mitigate
>> possible context switches between gettimeofday() and clock_gettime() calls.
> right, we could make this more accurate.. I'll post some follow up
> change with that

If it is handled through vdso (e.g., x86) both calls should be very fast
with no context switches and the margin of error is well less than the
usec resolution in the output.


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

2020-07-31 Thread Jiri Olsa
On Fri, Jul 31, 2020 at 06:52:36PM +0300, Alexey Budankov wrote:
> 
> On 31.07.2020 0:39, 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 
> > Signed-off-by: Jiri Olsa 
> > ---
> >  .../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;
> > +};
> > +
> > other bits are reserved and should ignored for now
> > HEADER_FEAT_BITS= 256,
> >  
> > diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
> > index 468c669519a6..f8280e721e1a 100644
> > --- a/tools/perf/builtin-record.c
> > +++ b/tools/perf/builtin-record.c
> > @@ -70,6 +70,7 @@
> >  #include 
> >  #include 
> >  #include 
> > +#include 
> >  
> >  struct switch_output {
> > bool enabled;
> > @@ -1203,6 +1204,9 @@ static void record__init_features(struct record *rec)
> > if (!(rec->opts.use_clockid && rec->opts.clockid_res_ns))
> > perf_header__clear_feat(>header, HEADER_CLOCKID);
> >  
> > +   if (!rec->opts.use_clockid)
> > +   perf_header__clear_feat(>header, HEADER_CLOCK_DATA);
> > +
> > perf_header__clear_feat(>header, HEADER_DIR_FORMAT);
> > if (!record__comp_enabled(rec))
> > perf_header__clear_feat(>header, HEADER_COMPRESSED);
> > @@ -1551,6 +1555,40 @@ static int record__setup_sb_evlist(struct record 
> > *rec)
> > return 0;
> >  }
> >  
> > +static int record__init_clock(struct record *rec)
> > +{
> > +   struct perf_session *session = rec->session;
> > +   struct timespec ref_clockid;
> > +   struct timeval ref_tod;
> > +   u64 ref;
> > +
> > +   if (!rec->opts.use_clockid)
> > +   return 0;
> > +
> > +   session->header.env.clock.clockid = rec->opts.clockid;
> > +
> > +   if (gettimeofday(_tod, NULL) != 0) {
> > +   pr_err("gettimeofday failed, cannot set reference time.\n");
> > +   return -1;
> > +   }
> > +
> > +   if (clock_gettime(rec->opts.clockid, _clockid)) {
> > +   pr_err("clock_gettime failed, cannot set reference time.\n");
> > +   return -1;
> > +   }
> 
> It might also want to be implemented in a loop and iteration with minimal
> time delta is chosen to improve synchronization accuracy and also mitigate
> possible context switches between gettimeofday() and clock_gettime() calls.

right, we could make this more accurate.. I'll post some follow up
change with that

thanks,
jirka



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

2020-07-31 Thread Alexey Budankov


On 31.07.2020 0:39, 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 
> Signed-off-by: Jiri Olsa 
> ---
>  .../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;
> +};
> +
>   other bits are reserved and should ignored for now
>   HEADER_FEAT_BITS= 256,
>  
> diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
> index 468c669519a6..f8280e721e1a 100644
> --- a/tools/perf/builtin-record.c
> +++ b/tools/perf/builtin-record.c
> @@ -70,6 +70,7 @@
>  #include 
>  #include 
>  #include 
> +#include 
>  
>  struct switch_output {
>   bool enabled;
> @@ -1203,6 +1204,9 @@ static void record__init_features(struct record *rec)
>   if (!(rec->opts.use_clockid && rec->opts.clockid_res_ns))
>   perf_header__clear_feat(>header, HEADER_CLOCKID);
>  
> + if (!rec->opts.use_clockid)
> + perf_header__clear_feat(>header, HEADER_CLOCK_DATA);
> +
>   perf_header__clear_feat(>header, HEADER_DIR_FORMAT);
>   if (!record__comp_enabled(rec))
>   perf_header__clear_feat(>header, HEADER_COMPRESSED);
> @@ -1551,6 +1555,40 @@ static int record__setup_sb_evlist(struct record *rec)
>   return 0;
>  }
>  
> +static int record__init_clock(struct record *rec)
> +{
> + struct perf_session *session = rec->session;
> + struct timespec ref_clockid;
> + struct timeval ref_tod;
> + u64 ref;
> +
> + if (!rec->opts.use_clockid)
> + return 0;
> +
> + session->header.env.clock.clockid = rec->opts.clockid;
> +
> + if (gettimeofday(_tod, NULL) != 0) {
> + pr_err("gettimeofday failed, cannot set reference time.\n");
> + return -1;
> + }
> +
> + if (clock_gettime(rec->opts.clockid, _clockid)) {
> + pr_err("clock_gettime failed, cannot set reference time.\n");
> + return -1;
> + }

It might also want to be implemented in a loop and iteration with minimal
time delta is chosen to improve synchronization accuracy and also mitigate
possible context switches between gettimeofday() and clock_gettime() calls.

Alexei


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

2020-07-30 Thread Jiri Olsa
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 
Signed-off-by: Jiri Olsa 
---
 .../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;
+};
+
other bits are reserved and should ignored for now
HEADER_FEAT_BITS= 256,
 
diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index 468c669519a6..f8280e721e1a 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -70,6 +70,7 @@
 #include 
 #include 
 #include 
+#include 
 
 struct switch_output {
bool enabled;
@@ -1203,6 +1204,9 @@ static void record__init_features(struct record *rec)
if (!(rec->opts.use_clockid && rec->opts.clockid_res_ns))
perf_header__clear_feat(>header, HEADER_CLOCKID);
 
+   if (!rec->opts.use_clockid)
+   perf_header__clear_feat(>header, HEADER_CLOCK_DATA);
+
perf_header__clear_feat(>header, HEADER_DIR_FORMAT);
if (!record__comp_enabled(rec))
perf_header__clear_feat(>header, HEADER_COMPRESSED);
@@ -1551,6 +1555,40 @@ static int record__setup_sb_evlist(struct record *rec)
return 0;
 }
 
+static int record__init_clock(struct record *rec)
+{
+   struct perf_session *session = rec->session;
+   struct timespec ref_clockid;
+   struct timeval ref_tod;
+   u64 ref;
+
+   if (!rec->opts.use_clockid)
+   return 0;
+
+   session->header.env.clock.clockid = rec->opts.clockid;
+
+   if (gettimeofday(_tod, NULL) != 0) {
+   pr_err("gettimeofday failed, cannot set reference time.\n");
+   return -1;
+   }
+
+   if (clock_gettime(rec->opts.clockid, _clockid)) {
+   pr_err("clock_gettime failed, cannot set reference time.\n");
+   return -1;
+   }
+
+   ref = (u64) ref_tod.tv_sec * NSEC_PER_SEC +
+ (u64) ref_tod.tv_usec * NSEC_PER_USEC;
+
+   session->header.env.clock.clockid_ns = ref;
+
+   ref = (u64) ref_clockid.tv_sec * NSEC_PER_SEC +
+ (u64) ref_clockid.tv_nsec;
+
+   session->header.env.clock.tod_ns = ref;
+   return 0;
+}
+
 static int __cmd_record(struct record *rec, int argc, const char **argv)
 {
int err;
@@ -1630,6 +1668,9 @@ static int __cmd_record(struct record *rec, int argc, 
const char **argv)
return -1;
}
 
+   if (record__init_clock(rec))
+   return -1;
+
record__init_features(rec);
 
if (rec->opts.use_clockid && rec->opts.clockid_res_ns)
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. */
+   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
+*/
+   boolenabled;
+   } clock;
 };
 
 enum perf_compress_type {
diff --git