linux-kernel - [PATCH V2 13/13] perf report: warn on high overhead

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

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:   Fri,  2 Dec 2016 16:19:21 -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 13/13] perf report: warn on high overhead

From: Kan Liang <kan.liang@...el.com>

Warning the user if the overhead is too high.
The overhead evaluation metrics is as below.
- Kerenl profiling cost evaluation
  MAX(cpu0_overhead, cpu1_overhead,...) / perf monotonic wall time
  If the rate is > 10%, a warning is printed.

- perf record profiling cost evaluation
  CPU time of perf record / perf monotonic wall time
  If the rate is > 50%, a warning is printed.

Here is an example of output.

Warning:
Perf kernel profiling cost is high! The cost rate is 15.30%

Please consider reducing the number of events, or increasing the period,
or decrease the frequency.

 # To display the perf.data header info, please use
 --header/--header-only options.
 #
 # ========
 # Elapsed time: 120345432522(ns)
 # Perf record cpu time: 505470324(ns)
 #
 # CPU       SAM    SAM cost(ns)       MUX    MUX cost(ns)        SB
 SB cost(ns)
 #  -1    2247030     1705370307     111354     3111550168    1237358
 13591276893
 # ========
 #

Signed-off-by: Kan Liang <kan.liang@...el.com>
---
 tools/perf/util/session.c | 48 +++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 48 insertions(+)

diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 7cf9e1d..1188a1a 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -1563,6 +1563,52 @@ perf_session__warn_order(const struct perf_session *session)
 		ui__warning("%u out of order events recorded.\n", oe->nr_unordered_events);
 }
 
+static void
+perf_session__warn_overhead(const struct perf_session *session)
+{
+	const struct events_stats *stats = &session->evlist->stats;
+	double overhead_rate;
+	u64 overhead, max;
+	int cpu;
+	int i;
+
+	overhead = stats->overhead.total_sample[MAX_NR_CPUS].time;
+	overhead += stats->overhead.total_mux[MAX_NR_CPUS].time;
+	overhead += stats->overhead.total_sb[MAX_NR_CPUS].time;
+	max = overhead;
+	cpu = -1;
+
+	for (i = 0; i < session->header.env.nr_cpus_online; i++) {
+		overhead = stats->overhead.total_sample[i].time;
+		overhead += stats->overhead.total_mux[i].time;
+		overhead += stats->overhead.total_sb[i].time;
+		if (overhead > max) {
+			max = overhead;
+			cpu = i;
+		}
+	}
+	overhead_rate = (double)max / (double)stats->elapsed_time;
+
+	if (overhead_rate > 0.1) {
+		if (cpu > 0) {
+			ui__warning("Perf kernel profiling cost is high! The cost rate is %3.2f%% on CPU %d\n\n"
+				    "Please consider reducing the number of events, or increasing the period, or decrease the frequency.\n\n",
+				    overhead_rate * 100.0, cpu);
+		} else {
+			ui__warning("Perf kernel profiling cost is high! The cost rate is %3.2f%%\n\n"
+				    "Please consider reducing the number of events, or increasing the period, or decrease the frequency.\n\n",
+				    overhead_rate * 100.0);
+		}
+	}
+
+	overhead_rate = (double)stats->cpu_time / (double)stats->elapsed_time;
+	if (overhead_rate > 0.5) {
+		ui__warning("Perf record profiling cost is high! The cost rate is %3.2f%%\n\n"
+			    "Please consider reducing the number of events, or increasing the period, or decrease the frequency.\n\n",
+			    overhead_rate * 100.0);
+	}
+}
+
 static void perf_session__warn_about_errors(const struct perf_session *session)
 {
 	const struct events_stats *stats = &session->evlist->stats;
@@ -1636,6 +1682,8 @@ static void perf_session__warn_about_errors(const struct perf_session *session)
 			    "Increase it by --proc-map-timeout\n",
 			    stats->nr_proc_map_timeout);
 	}
+
+	perf_session__warn_overhead(session);
 }
 
 static int perf_session__flush_thread_stack(struct thread *thread,
-- 
2.5.5