| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-Id: <1480713561-6617-13-git-send-email-kan.liang@intel.com>
Date: Fri, 2 Dec 2016 16:19:20 -0500
From: kan.liang@...el.com
To: peterz@...radead.org, mingo@...hat.com, acme@...nel.org,
linux-kernel@...r.kernel.org
Cc: alexander.shishkin@...ux.intel.com, tglx@...utronix.de,
namhyung@...nel.org, jolsa@...nel.org, adrian.hunter@...el.com,
wangnan0@...wei.com, mark.rutland@....com, andi@...stfloor.org,
Kan Liang <kan.liang@...el.com>
Subject: [PATCH V2 12/13] perf tools: record user space profiling cost
From: Kan Liang <kan.liang@...el.com>
Record the cpu time and elapsed time of perf record.
Show them in perf report.
# To display the perf.data header info, please use
--header/--header-only options.
#
# ========
# Elapsed time: 1199332708(ns)
# Perf record cpu time: 197780038(ns)
#
# CPU SAM SAM cost(ns) MUX MUX cost(ns) SB
SB cost(ns)
# 0 2 13659 12101 6111457 0
0
# 1 1 8160 12101 46062331 0
0
Signed-off-by: Kan Liang <kan.liang@...el.com>
---
tools/perf/builtin-record.c | 52 ++++++++++++++++++++++++++++++++++++++++++++-
tools/perf/util/event.h | 4 ++++
tools/perf/util/machine.c | 5 +++++
tools/perf/util/session.c | 8 +++++++
4 files changed, 68 insertions(+), 1 deletion(-)
diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index e69099d..405eef4 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -49,6 +49,8 @@ struct record {
struct perf_tool tool;
struct record_opts opts;
u64 bytes_written;
+ u64 record_cpu_time;
+ u64 elapsed_time;
struct perf_data_file file;
struct auxtrace_record *itr;
struct perf_evlist *evlist;
@@ -746,6 +748,47 @@ static const struct perf_event_mmap_page *record__pick_pc(struct record *rec)
return NULL;
}
+static int perf_event__synth_overhead(struct record *rec, u64 type, u64 time,
+ perf_event__handler_t process)
+{
+ union perf_event event = {
+ .overhead = {
+ .header = {
+ .type = PERF_RECORD_USER_OVERHEAD,
+ .size = sizeof(struct perf_overhead),
+ },
+ .type = type,
+ .entry = {
+ .nr = 1,
+ .time = time,
+ },
+ },
+ };
+
+ return process(&rec->tool, &event, NULL, NULL);
+}
+
+static int perf_event__synth_overheads(struct record *rec)
+{
+ int err;
+
+ err = perf_event__synth_overhead(rec, PERF_USER_CPU_TIME,
+ (get_vnsecs() - rec->record_cpu_time),
+ process_synthesized_event);
+ if (err < 0)
+ return err;
+ rec->record_cpu_time = get_vnsecs();
+
+ err = perf_event__synth_overhead(rec, PERF_USER_ELAPSED_TIME,
+ (get_nsecs() - rec->elapsed_time),
+ process_synthesized_event);
+ if (err < 0)
+ return err;
+ rec->elapsed_time = get_nsecs();
+
+ return 0;
+}
+
static int record__synthesize(struct record *rec, bool tail)
{
struct perf_session *session = rec->session;
@@ -757,7 +800,7 @@ static int record__synthesize(struct record *rec, bool tail)
int err = 0;
if (rec->opts.tail_synthesize != tail)
- return 0;
+ goto out;
if (file->is_pipe) {
err = perf_event__synthesize_attrs(tool, session,
@@ -819,6 +862,10 @@ static int record__synthesize(struct record *rec, bool tail)
process_synthesized_event, opts->sample_address,
opts->proc_map_timeout);
out:
+ if (tail && perf_evlist__overhead(session->evlist) &&
+ (perf_event__synth_overheads(rec) < 0))
+ pr_err("Couldn't synthesize user overhead information.\n");
+
return err;
}
@@ -1555,6 +1602,9 @@ int cmd_record(int argc, const char **argv, const char *prefix __maybe_unused)
# undef REASON
#endif
+ rec->record_cpu_time = get_vnsecs();
+ rec->elapsed_time = get_nsecs();
+
rec->evlist = perf_evlist__new();
if (rec->evlist == NULL)
return -ENOMEM;
diff --git a/tools/perf/util/event.h b/tools/perf/util/event.h
index 6110f32..9c69c34 100644
--- a/tools/perf/util/event.h
+++ b/tools/perf/util/event.h
@@ -280,6 +280,8 @@ struct events_stats {
u64 total_lost_samples;
u64 total_aux_lost;
u64 total_invalid_chains;
+ u64 cpu_time;
+ u64 elapsed_time;
struct total_overhead overhead;
u32 nr_events[PERF_RECORD_HEADER_MAX];
u32 nr_non_filtered_samples;
@@ -493,6 +495,8 @@ struct time_conv_event {
enum perf_user_overhead_event_type { /* above any possible kernel type */
PERF_USER_OVERHEAD_TYPE_START = 100,
+ PERF_USER_CPU_TIME = 100,
+ PERF_USER_ELAPSED_TIME,
};
struct perf_overhead {
diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
index 72c4412..b95104a 100644
--- a/tools/perf/util/machine.c
+++ b/tools/perf/util/machine.c
@@ -578,6 +578,11 @@ int machine__process_overhead_event(struct machine *machine __maybe_unused,
event->overhead.entry.time,
sample->cpu);
break;
+ case PERF_USER_CPU_TIME:
+ dump_printf(" CPU time: %llu\n", event->overhead.entry.time);
+ break;
+ case PERF_USER_ELAPSED_TIME:
+ dump_printf(" elapsed time: %llu\n", event->overhead.entry.time);
default:
dump_printf("\tUNSUPPORT TYPE 0x%lx!\n", event->overhead.type);
return 0;
diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 7745bec..7cf9e1d 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -1233,6 +1233,12 @@ overhead_stats_update(struct perf_tool *tool,
evlist->stats.overhead.total_sb[cpu].nr += event->overhead.entry.nr;
evlist->stats.overhead.total_sb[cpu].time += event->overhead.entry.time;
break;
+ case PERF_USER_CPU_TIME:
+ evlist->stats.cpu_time += event->overhead.entry.time;
+ break;
+ case PERF_USER_ELAPSED_TIME:
+ evlist->stats.elapsed_time += event->overhead.entry.time;
+ break;
default:
break;
}
@@ -2112,6 +2118,8 @@ void perf_session__fprintf_overhead_info(struct perf_session *session,
}
fprintf(fp, "# ========\n");
+ fprintf(fp, "# Elapsed time: %lu(ns)\n", evlist->stats.elapsed_time);
+ fprintf(fp, "# Perf record cpu time: %lu(ns)\n#\n", evlist->stats.cpu_time);
fprintf(fp, "# CPU");
fprintf(fp, " SAM SAM cost(ns)");
fprintf(fp, " MUX MUX cost(ns)");
--
2.5.5
Powered by blists - more mailing lists