From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1760835AbcLASFC (ORCPT ); Thu, 1 Dec 2016 13:05:02 -0500 Received: from merlin.infradead.org ([205.233.59.134]:49704 "EHLO merlin.infradead.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1758532AbcLASDG (ORCPT ); Thu, 1 Dec 2016 13:03:06 -0500 From: Arnaldo Carvalho de Melo To: Ingo Molnar Cc: linux-kernel@vger.kernel.org, David Ahern , David Ahern , Jiri Olsa , Peter Zijlstra , Arnaldo Carvalho de Melo Subject: [PATCH 16/19] perf kmem: Add option to specify time window of interest Date: Thu, 1 Dec 2016 15:02:32 -0300 Message-Id: <20161201180235.18392-17-acme@kernel.org> X-Mailer: git-send-email 2.9.3 In-Reply-To: <20161201180235.18392-1-acme@kernel.org> References: <20161201180235.18392-1-acme@kernel.org> X-SRS-Rewrite: SMTP reverse-path rewritten from by merlin.infradead.org. See http://www.infradead.org/rpr.html Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org From: David Ahern Add option to allow user to control analysis window. e.g., collect data for time window and analyze a segment of interest within that window. Committer notes: Testing it: # perf kmem record usleep 1 [ perf record: Woken up 0 times to write data ] [ perf record: Captured and wrote 1.540 MB perf.data (2049 samples) ] # perf evlist kmem:kmalloc kmem:kmalloc_node kmem:kfree kmem:kmem_cache_alloc kmem:kmem_cache_alloc_node kmem:kmem_cache_free # Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events # # # Use 'perf script' to get a first approach, select a chunk for then using # # with 'perf kmem stat --time' # # perf script | tail -15 usleep 9889 [0] 20119.782088: kmem:kmem_cache_free: (selinux_file_free_security+0x27) call_site=ffffffffb936aa07 ptr=0xffff888a1df49fc0 perf 9888 [3] 20119.782088: kmem:kmem_cache_free: (jbd2_journal_stop+0x1a1) call_site=ffffffffb9334581 ptr=0xffff888bdf1a39c0 perf 9888 [3] 20119.782089: kmem:kmem_cache_alloc: (jbd2__journal_start+0x72) call_site=ffffffffb9333b42 ptr=0xffff888bdf1a39c0 bytes_req=48 bytes_alloc=48 gfp_flags=GFP_NOFS|__GFP_ZERO perf 9888 [3] 20119.782090: kmem:kmem_cache_free: (jbd2_journal_stop+0x1a1) call_site=ffffffffb9334581 ptr=0xffff888bdf1a39c0 perf 9888 [3] 20119.782090: kmem:kmem_cache_alloc: (jbd2__journal_start+0x72) call_site=ffffffffb9333b42 ptr=0xffff888bdf1a39c0 bytes_req=48 bytes_alloc=48 gfp_flags=GFP_NOFS|__GFP_ZERO usleep 9889 [0] 20119.782091: kmem:kmem_cache_alloc: (__sigqueue_alloc+0x4a) call_site=ffffffffb90ad33a ptr=0xffff8889f071f6e0 bytes_req=160 bytes_alloc=160 gfp_flags=GFP_ATOMIC|__GFP_NOTRACK perf 9888 [3] 20119.782091: kmem:kmem_cache_free: (jbd2_journal_stop+0x1a1) call_site=ffffffffb9334581 ptr=0xffff888bdf1a39c0 perf 9888 [3] 20119.782093: kmem:kmem_cache_free: (__sigqueue_free.part.17+0x33) call_site=ffffffffb90ad3f3 ptr=0xffff8889f071f6e0 perf 9888 [3] 20119.782098: kmem:kmem_cache_alloc: (jbd2__journal_start+0x72) call_site=ffffffffb9333b42 ptr=0xffff888bdf1a39c0 bytes_req=48 bytes_alloc=48 gfp_flags=GFP_NOFS|__GFP_ZERO perf 9888 [3] 20119.782098: kmem:kmem_cache_free: (jbd2_journal_stop+0x1a1) call_site=ffffffffb9334581 ptr=0xffff888bdf1a39c0 perf 9888 [3] 20119.782099: kmem:kmem_cache_alloc: (jbd2__journal_start+0x72) call_site=ffffffffb9333b42 ptr=0xffff888bdf1a39c0 bytes_req=48 bytes_alloc=48 gfp_flags=GFP_NOFS|__GFP_ZERO perf 9888 [3] 20119.782100: kmem:kmem_cache_alloc: (alloc_buffer_head+0x21) call_site=ffffffffb9287cc1 ptr=0xffff8889b12722d8 bytes_req=104 bytes_alloc=104 gfp_flags=GFP_NOFS|__GFP_ZERO perf 9888 [3] 20119.782101: kmem:kmem_cache_free: (jbd2_journal_stop+0x1a1) call_site=ffffffffb9334581 ptr=0xffff888bdf1a39c0 perf 9888 [3] 20119.782102: kmem:kmem_cache_alloc: (jbd2__journal_start+0x72) call_site=ffffffffb9333b42 ptr=0xffff888bdf1a39c0 bytes_req=48 bytes_alloc=48 gfp_flags=GFP_NOFS|__GFP_ZERO perf 9888 [3] 20119.782103: kmem:kmem_cache_free: (jbd2_journal_stop+0x1a1) call_site=ffffffffb9334581 ptr=0xffff888bdf1a39c0 # # # stats for the whole perf.data file, i.e. no interval specified # # perf kmem stat SUMMARY (SLAB allocator) ======================== Total bytes requested: 172,628 Total bytes allocated: 173,088 Total bytes freed: 161,280 Net total bytes allocated: 11,808 Total bytes wasted on internal fragmentation: 460 Internal fragmentation: 0.265761% Cross CPU allocations: 0/851 # # # stats for an end open interval, after a certain time: # # perf kmem stat --time 20119.782088, SUMMARY (SLAB allocator) ======================== Total bytes requested: 552 Total bytes allocated: 552 Total bytes freed: 448 Net total bytes allocated: 104 Total bytes wasted on internal fragmentation: 0 Internal fragmentation: 0.000000% Cross CPU allocations: 0/8 # Signed-off-by: David Ahern Tested-by: Arnaldo Carvalho de Melo Acked-by: Namhyung Kim Cc: Jiri Olsa Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/1480439746-42695-6-git-send-email-dsahern@gmail.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/Documentation/perf-kmem.txt | 7 +++++++ tools/perf/builtin-kmem.c | 24 ++++++++++++++++++++++++ 2 files changed, 31 insertions(+) diff --git a/tools/perf/Documentation/perf-kmem.txt b/tools/perf/Documentation/perf-kmem.txt index ff0f433b3fce..479fc3261a50 100644 --- a/tools/perf/Documentation/perf-kmem.txt +++ b/tools/perf/Documentation/perf-kmem.txt @@ -61,6 +61,13 @@ OPTIONS default, but this option shows live (currently allocated) pages instead. (This option works with --page option only) +--time:: + Only analyze samples within given time window: ,. Times + have the format seconds.microseconds. If start is not given (i.e., time + string is ',x.y') then analysis starts at the beginning of the file. If + stop time is not given (i.e, time string is 'x.y,') then analysis goes + to end of file. + SEE ALSO -------- linkperf:perf-record[1] diff --git a/tools/perf/builtin-kmem.c b/tools/perf/builtin-kmem.c index 7fd6f1e1e293..35a02f8e5a4a 100644 --- a/tools/perf/builtin-kmem.c +++ b/tools/perf/builtin-kmem.c @@ -11,6 +11,7 @@ #include "util/session.h" #include "util/tool.h" #include "util/callchain.h" +#include "util/time-utils.h" #include #include "util/trace-event.h" @@ -66,6 +67,10 @@ static struct rb_root root_caller_sorted; static unsigned long total_requested, total_allocated, total_freed; static unsigned long nr_allocs, nr_cross_allocs; +/* filters for controlling start and stop of time of analysis */ +static struct perf_time_interval ptime; +const char *time_str; + static int insert_alloc_stat(unsigned long call_site, unsigned long ptr, int bytes_req, int bytes_alloc, int cpu) { @@ -912,6 +917,15 @@ static int perf_evsel__process_page_free_event(struct perf_evsel *evsel, return 0; } +static bool perf_kmem__skip_sample(struct perf_sample *sample) +{ + /* skip sample based on time? */ + if (perf_time__skip_sample(&ptime, sample->time)) + return true; + + return false; +} + typedef int (*tracepoint_handler)(struct perf_evsel *evsel, struct perf_sample *sample); @@ -931,6 +945,9 @@ static int process_sample_event(struct perf_tool *tool __maybe_unused, return -1; } + if (perf_kmem__skip_sample(sample)) + return 0; + dump_printf(" ... thread: %s:%d\n", thread__comm_str(thread), thread->tid); if (evsel->handler != NULL) { @@ -1894,6 +1911,8 @@ int cmd_kmem(int argc, const char **argv, const char *prefix __maybe_unused) OPT_CALLBACK_NOOPT(0, "page", NULL, NULL, "Analyze page allocator", parse_page_opt), OPT_BOOLEAN(0, "live", &live_page, "Show live page stat"), + OPT_STRING(0, "time", &time_str, "str", + "Time span of interest (start,stop)"), OPT_END() }; const char *const kmem_subcommands[] = { "record", "stat", NULL }; @@ -1954,6 +1973,11 @@ int cmd_kmem(int argc, const char **argv, const char *prefix __maybe_unused) symbol__init(&session->header.env); + if (perf_time__parse_str(&ptime, time_str) != 0) { + pr_err("Invalid time string\n"); + return -EINVAL; + } + if (!strcmp(argv[0], "stat")) { setlocale(LC_ALL, ""); -- 2.9.3