Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1756343AbcLBVWZ (ORCPT ); Fri, 2 Dec 2016 16:22:25 -0500 Received: from mga14.intel.com ([192.55.52.115]:10154 "EHLO mga14.intel.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751731AbcLBVUm (ORCPT ); Fri, 2 Dec 2016 16:20:42 -0500 X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="5.33,288,1477983600"; d="scan'208";a="1093847559" From: kan.liang@intel.com To: peterz@infradead.org, mingo@redhat.com, acme@kernel.org, linux-kernel@vger.kernel.org Cc: alexander.shishkin@linux.intel.com, tglx@linutronix.de, namhyung@kernel.org, jolsa@kernel.org, adrian.hunter@intel.com, wangnan0@huawei.com, mark.rutland@arm.com, andi@firstfloor.org, Kan Liang Subject: [PATCH V2 13/13] perf report: warn on high overhead Date: Fri, 2 Dec 2016 16:19:21 -0500 Message-Id: <1480713561-6617-14-git-send-email-kan.liang@intel.com> X-Mailer: git-send-email 2.5.5 In-Reply-To: <1480713561-6617-1-git-send-email-kan.liang@intel.com> References: <1480713561-6617-1-git-send-email-kan.liang@intel.com> Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 3585 Lines: 107 From: Kan Liang 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 --- 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