Re: [PATCH v4 1/6] perf header: Record first sample time and last sample time in perf file header

From: Arnaldo Carvalho de Melo
Date: Thu Oct 19 2017 - 16:17:45 EST


Em Tue, Oct 03, 2017 at 10:22:33PM +0800, Jin Yao escreveu:
> perf report/script/... have a --time option to limit the time range
> of output. That's very useful to slice large traces, e.g. when processing
> the output of perf script for some analysis.
>
> But right now --time only supports absolute time. Also there is no fast
> way to get the start/end times of a given trace except for looking at it.
> This makes it hard to e.g. only decode the first half of the trace, which
> is useful for parallelization of scripts
>
> Another problem is that perf records are variable size and there is no
> synchronization mechanism. So the only way to find the last sample reliably
> would be to walk all samples. But we want to avoid that in perf report/...

So _who_ will walk all the samples, its not clear from this specific
message (1/6) who will do this...

- Arnaldo

> because it is already quite expensive. That is why storing the first sample
> time and last sample time in perf record is better.
>
> This patch creates a new header feature type HEADER_SAMPLE_TIME and related
> ops. Save the first sample time and the last sample time to the feature
> section in perf file header.
>
> Change log:
> -----------
> v4: Use perf script time style for timestamp printing. Also add with
> the printing of sample duration.
>
> v3: Remove the definitions of first_sample_time/last_sample_time from
> perf_session. Just define them in perf_evlist
>
> Signed-off-by: Jin Yao <yao.jin@xxxxxxxxxxxxxxx>
> ---
> tools/perf/Documentation/perf.data-file-format.txt | 4 ++
> tools/perf/util/evlist.h | 2 +
> tools/perf/util/header.c | 60 ++++++++++++++++++++++
> tools/perf/util/header.h | 1 +
> 4 files changed, 67 insertions(+)
>
> diff --git a/tools/perf/Documentation/perf.data-file-format.txt b/tools/perf/Documentation/perf.data-file-format.txt
> index e90c59c..d5e3043 100644
> --- a/tools/perf/Documentation/perf.data-file-format.txt
> +++ b/tools/perf/Documentation/perf.data-file-format.txt
> @@ -238,6 +238,10 @@ struct auxtrace_index {
> struct auxtrace_index_entry entries[PERF_AUXTRACE_INDEX_ENTRY_COUNT];
> };
>
> + HEADER_SAMPLE_TIME = 21,
> +
> +Two uint64_t for the time of first sample and the time of last sample.
> +
> other bits are reserved and should ignored for now
> HEADER_FEAT_BITS = 256,
>
> diff --git a/tools/perf/util/evlist.h b/tools/perf/util/evlist.h
> index b1c14f1..9ccc2fb 100644
> --- a/tools/perf/util/evlist.h
> +++ b/tools/perf/util/evlist.h
> @@ -99,6 +99,8 @@ struct perf_evlist {
> struct perf_evsel *selected;
> struct events_stats stats;
> struct perf_env *env;
> + u64 first_sample_time;
> + u64 last_sample_time;
> };
>
> struct perf_evsel_str_handler {
> diff --git a/tools/perf/util/header.c b/tools/perf/util/header.c
> index 605bbd5..61b28d89 100644
> --- a/tools/perf/util/header.c
> +++ b/tools/perf/util/header.c
> @@ -17,6 +17,7 @@
> #include <sys/types.h>
> #include <sys/utsname.h>
> #include <unistd.h>
> +#include <linux/time64.h>
>
> #include "evlist.h"
> #include "evsel.h"
> @@ -36,6 +37,7 @@
> #include <api/fs/fs.h>
> #include "asm/bug.h"
> #include "tool.h"
> +#include "time-utils.h"
>
> #include "sane_ctype.h"
>
> @@ -1181,6 +1183,20 @@ static int write_stat(struct feat_fd *ff __maybe_unused,
> return 0;
> }
>
> +static int write_sample_time(struct feat_fd *ff,
> + struct perf_evlist *evlist)
> +{
> + int ret;
> +
> + ret = do_write(ff, &evlist->first_sample_time,
> + sizeof(evlist->first_sample_time));
> + if (ret < 0)
> + return ret;
> +
> + return do_write(ff, &evlist->last_sample_time,
> + sizeof(evlist->last_sample_time));
> +}
> +
> static void print_hostname(struct feat_fd *ff, FILE *fp)
> {
> fprintf(fp, "# hostname : %s\n", ff->ph->env.hostname);
> @@ -1506,6 +1522,28 @@ static void print_group_desc(struct feat_fd *ff, FILE *fp)
> }
> }
>
> +static void print_sample_time(struct feat_fd *ff, FILE *fp)
> +{
> + struct perf_session *session;
> + char time_buf[32];
> + double d;
> +
> + session = container_of(ff->ph, struct perf_session, header);
> +
> + timestamp__scnprintf_usec(session->evlist->first_sample_time,
> + time_buf, sizeof(time_buf));
> + fprintf(fp, "# time of first sample : %s\n", time_buf);
> +
> + timestamp__scnprintf_usec(session->evlist->last_sample_time,
> + time_buf, sizeof(time_buf));
> + fprintf(fp, "# time of last sample : %s\n", time_buf);
> +
> + d = (double)(session->evlist->last_sample_time -
> + session->evlist->first_sample_time) / NSEC_PER_MSEC;
> +
> + fprintf(fp, "# sample duration : %10.3f ms\n", d);
> +}
> +
> static int __event_process_build_id(struct build_id_event *bev,
> char *filename,
> struct perf_session *session)
> @@ -2147,6 +2185,27 @@ static int process_cache(struct feat_fd *ff, void *data __maybe_unused)
> return -1;
> }
>
> +static int process_sample_time(struct feat_fd *ff, void *data __maybe_unused)
> +{
> + struct perf_session *session;
> + u64 first_sample_time, last_sample_time;
> + int ret;
> +
> + session = container_of(ff->ph, struct perf_session, header);
> +
> + ret = do_read_u64(ff, &first_sample_time);
> + if (ret)
> + return -1;
> +
> + ret = do_read_u64(ff, &last_sample_time);
> + if (ret)
> + return -1;
> +
> + session->evlist->first_sample_time = first_sample_time;
> + session->evlist->last_sample_time = last_sample_time;
> + return 0;
> +}
> +
> struct feature_ops {
> int (*write)(struct feat_fd *ff, struct perf_evlist *evlist);
> void (*print)(struct feat_fd *ff, FILE *fp);
> @@ -2204,6 +2263,7 @@ static const struct feature_ops feat_ops[HEADER_LAST_FEATURE] = {
> FEAT_OPN(AUXTRACE, auxtrace, false),
> FEAT_OPN(STAT, stat, false),
> FEAT_OPN(CACHE, cache, true),
> + FEAT_OPR(SAMPLE_TIME, sample_time, false),
> };
>
> struct header_print_data {
> diff --git a/tools/perf/util/header.h b/tools/perf/util/header.h
> index f7a16ee..1911831 100644
> --- a/tools/perf/util/header.h
> +++ b/tools/perf/util/header.h
> @@ -33,6 +33,7 @@ enum {
> HEADER_AUXTRACE,
> HEADER_STAT,
> HEADER_CACHE,
> + HEADER_SAMPLE_TIME,
> HEADER_LAST_FEATURE,
> HEADER_FEAT_BITS = 256,
> };
> --
> 2.7.4