From: Kan Liang <[email protected]> Record the elapsed time of perf record, and display it in perf report
Signed-off-by: Kan Liang <[email protected]> --- tools/perf/builtin-record.c | 10 ++++++++++ tools/perf/builtin-report.c | 1 + tools/perf/util/event.h | 3 +++ tools/perf/util/machine.c | 3 +++ tools/perf/util/session.c | 3 +++ 5 files changed, 20 insertions(+) diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c index 492058e..ea94e10 100644 --- a/tools/perf/builtin-record.c +++ b/tools/perf/builtin-record.c @@ -69,6 +69,7 @@ struct record { bool switch_output; unsigned long long samples; struct write_overhead overhead[MAX_NR_CPUS]; + u64 elapsed_time; }; static u64 get_vnsecs(void) @@ -866,6 +867,12 @@ static void perf_event__synth_overhead(struct record *rec, perf_event__handler_t (void)process(&rec->tool, &event, NULL, NULL); } + + event.overhead.type = PERF_USER_ELAPSED_TIME; + event.overhead.entry.cpu = -1; + event.overhead.entry.nr = 1; + event.overhead.entry.time = rec->elapsed_time; + (void)process(&rec->tool, &event, NULL, NULL); } static int __cmd_record(struct record *rec, int argc, const char **argv) @@ -1129,6 +1136,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv) goto out_child; } + rec->elapsed_time = get_nsecs() - rec->elapsed_time; perf_event__synth_overhead(rec, process_synthesized_event); if (!quiet) @@ -1601,6 +1609,8 @@ int cmd_record(int argc, const char **argv, const char *prefix __maybe_unused) # undef REASON #endif + rec->elapsed_time = get_nsecs(); + rec->evlist = perf_evlist__new(); if (rec->evlist == NULL) return -ENOMEM; diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index 9c0a424..de2a9b6 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c @@ -371,6 +371,7 @@ static int perf_evlist__tty_browse_hists(struct perf_evlist *evlist, fprintf(stdout, "#\n# Total Lost Samples: %" PRIu64 "\n#\n", evlist->stats.total_lost_samples); if (symbol_conf.show_overhead) { + fprintf(stdout, "# Elapsed time: %" PRIu64 " ns\n", evlist->stats.elapsed_time); fprintf(stdout, "# Overhead:\n"); for (cpu = 0; cpu < session->header.env.nr_cpus_online; cpu++) { if (!evlist->stats.total_nmi_overhead[cpu][0]) diff --git a/tools/perf/util/event.h b/tools/perf/util/event.h index 9927cf9..ceb0968 100644 --- a/tools/perf/util/event.h +++ b/tools/perf/util/event.h @@ -275,6 +275,7 @@ enum auxtrace_error_type { * The total_user_write_overhead tells exactly the overhead to write data in * perf record. * The total write# is stored in [0], while the accumulated time is in [1]. + * The elapsed_time tells the elapsed time of perf record */ struct events_stats { u64 total_period; @@ -287,6 +288,7 @@ struct events_stats { u64 total_mux_overhead[MAX_NR_CPUS][2]; u64 total_sb_overhead[MAX_NR_CPUS][2]; u64 total_user_write_overhead[MAX_NR_CPUS][2]; + u64 elapsed_time; u32 nr_events[PERF_RECORD_HEADER_MAX]; u32 nr_non_filtered_samples; u32 nr_lost_warned; @@ -497,6 +499,7 @@ struct time_conv_event { u64 time_zero; }; +#define PERF_USER_ELAPSED_TIME 200 /* above any possible overhead type */ enum perf_user_overhead_event_type { /* above any possible kernel type */ PERF_USER_OVERHEAD_TYPE_START = 100, PERF_USER_WRITE_OVERHEAD = 100, diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c index ce7a0ea..150071f 100644 --- a/tools/perf/util/machine.c +++ b/tools/perf/util/machine.c @@ -578,6 +578,9 @@ int machine__process_overhead_event(struct machine *machine __maybe_unused, event->overhead.entry.nr, event->overhead.entry.time, event->overhead.entry.cpu); + } else if (event->overhead.type == PERF_USER_ELAPSED_TIME) { + dump_printf(" Elapsed time: %llu\n", + event->overhead.entry.time); } else { dump_printf("\tUNSUPPORT OVERHEAD TYPE 0x%x!\n", event->overhead.type); } diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c index a72992b..e84808f 100644 --- a/tools/perf/util/session.c +++ b/tools/perf/util/session.c @@ -1231,6 +1231,9 @@ overhead_stats_update(struct perf_tool *tool, evlist->stats.total_user_write_overhead[event->overhead.entry.cpu][0] += event->overhead.entry.nr; evlist->stats.total_user_write_overhead[event->overhead.entry.cpu][1] += event->overhead.entry.time; break; + case PERF_USER_ELAPSED_TIME: + evlist->stats.elapsed_time = event->overhead.entry.time; + break; default: break; } -- 2.5.5
