leandrof/linux
1
0
Fork 0
forked from Minki/linux
Code Issues Pull Requests Packages Projects Releases Wiki Activity

perf kmem: Add option to specify time window of interest

Browse Source 
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 <dsahern@gmail.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: Namhyung Kim <namhyung@kernel.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/1480439746-42695-6-git-send-email-dsahern@gmail.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
This commit is contained in:
David Ahern 2016-11-29 10:15:45 -07:00 committed by Arnaldo Carvalho de Melo
parent 853b740711
commit 2a865bd8dd
2 changed files with 31 additions and 0 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

7
tools/perf/Documentation/perf-kmem.txt
View File

@ -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: <start>,<stop>. 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]

24
tools/perf/builtin-kmem.c
View File

@ -11,6 +11,7 @@
#include "util/session.h"
#include "util/tool.h"
#include "util/callchain.h"
#include "util/time-utils.h"
#include <subcmd/parse-options.h>
#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, "");