diff options
author | David Ahern <dsa@cumulusnetworks.com> | 2016-11-29 12:15:46 -0500 |
---|---|---|
committer | Arnaldo Carvalho de Melo <acme@redhat.com> | 2016-12-01 11:03:10 -0500 |
commit | 46690a8051e4b5901a49080443a17a270e0bd8a2 (patch) | |
tree | fcdedd95bdb5f61a5b66e89468bd0bdb99888a76 | |
parent | 2a865bd8dddd44315c88bf922761e4fd3374d046 (diff) |
perf report: Add option to specify time window of interest
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:
Using the perf.data file captured via 'perf kmem record':
# perf report --header-only
# ========
# captured on: Tue Nov 29 16:01:53 2016
# hostname : jouet
# os release : 4.8.8-300.fc25.x86_64
# perf version : 4.9.rc6.g5a6aca
# arch : x86_64
# nrcpus online : 4
# nrcpus avail : 4
# cpudesc : Intel(R) Core(TM) i7-5600U CPU @ 2.60GHz
# cpuid : GenuineIntel,6,61,4
# total memory : 20254660 kB
# cmdline : /home/acme/bin/perf kmem record usleep 1
# event : name = kmem:kmalloc, , id = { 931980, 931981, 931982, 931983 }, type = 2, size = 112, config = 0x1b9, { sample_period, sample_freq } = 1, sample_typ
# event : name = kmem:kmalloc_node, , id = { 931984, 931985, 931986, 931987 }, type = 2, size = 112, config = 0x1b7, { sample_period, sample_freq } = 1, sampl
# event : name = kmem:kfree, , id = { 931988, 931989, 931990, 931991 }, type = 2, size = 112, config = 0x1b5, { sample_period, sample_freq } = 1, sample_type
# event : name = kmem:kmem_cache_alloc, , id = { 931992, 931993, 931994, 931995 }, type = 2, size = 112, config = 0x1b8, { sample_period, sample_freq } = 1, s
# event : name = kmem:kmem_cache_alloc_node, , id = { 931996, 931997, 931998, 931999 }, type = 2, size = 112, config = 0x1b6, { sample_period, sample_freq } =
# event : name = kmem:kmem_cache_free, , id = { 932000, 932001, 932002, 932003 }, type = 2, size = 112, config = 0x1b4, { sample_period, sample_freq } = 1, sa
# HEADER_CPU_TOPOLOGY info available, use -I to display
# HEADER_NUMA_TOPOLOGY info available, use -I to display
# pmu mappings: cpu = 4, intel_pt = 7, intel_bts = 6, uncore_arb = 13, cstate_pkg = 15, breakpoint = 5, uncore_cbox_1 = 12, power = 9, software = 1, uncore_im
# HEADER_CACHE info available, use -I to display
# missing features: HEADER_BRANCH_STACK HEADER_GROUP_DESC HEADER_AUXTRACE HEADER_STAT
# ========
#
# # Looking at just the histogram entries for the first event:
#
# perf report | head -33
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 40 of event 'kmem:kmalloc'
# Event count (approx.): 40
#
# Overhead Trace output
# ........ ...............................................................................................................
#
37.50% call_site=ffffffffb91ad3c7 ptr=0xffff88895fc05000 bytes_req=4096 bytes_alloc=4096 gfp_flags=GFP_KERNEL
10.00% call_site=ffffffffb9258416 ptr=0xffff888a1dc61f00 bytes_req=240 bytes_alloc=256 gfp_flags=GFP_KERNEL|__GFP_ZERO
7.50% call_site=ffffffffb9258416 ptr=0xffff888a2640ac00 bytes_req=240 bytes_alloc=256 gfp_flags=GFP_KERNEL|__GFP_ZERO
2.50% call_site=ffffffffb92759ba ptr=0xffff888a26776000 bytes_req=4096 bytes_alloc=4096 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb9276864 ptr=0xffff8886f6b82600 bytes_req=136 bytes_alloc=192 gfp_flags=GFP_KERNEL|__GFP_ZERO
2.50% call_site=ffffffffb9276903 ptr=0xffff888aefcf0460 bytes_req=32 bytes_alloc=32 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb92ad0ce ptr=0xffff888756c98a00 bytes_req=392 bytes_alloc=512 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb92ad0ce ptr=0xffff888756c9ba00 bytes_req=504 bytes_alloc=512 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb92ad301 ptr=0xffff888a31747600 bytes_req=128 bytes_alloc=128 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb92ad511 ptr=0xffff888a9d26a2a0 bytes_req=28 bytes_alloc=32 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c11a0 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c12c0 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c1540 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c15a0 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c15e0 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c16e0 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb936a7fb ptr=0xffff88873e8c1c20 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb936a7fb ptr=0xffff888a9d26a2a0 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL
2.50% call_site=ffffffffb9373e66 ptr=0xffff8889f1931240 bytes_req=64 bytes_alloc=64 gfp_flags=GFP_ATOMIC|__GFP_ZERO
2.50% call_site=ffffffffb9373e66 ptr=0xffff8889f1931980 bytes_req=64 bytes_alloc=64 gfp_flags=GFP_ATOMIC|__GFP_ZERO
2.50% call_site=ffffffffb9373e66 ptr=0xffff8889f1931a00 bytes_req=64 bytes_alloc=64 gfp_flags=GFP_ATOMIC|__GFP_ZERO
#
# # And then limiting using the example for 'perf kmem stat --time' used
# # in the previous changeset committer note we see that there were no
# # kmem:kmalloc in that last part of the file, but there were some
# # kmem:kmem_cache_alloc ones:
#
# perf report --time 20119.782088, --stdio
#
# Total Lost Samples: 0
#
# Samples: 0 of event 'kmem:kmalloc'
# Event count (approx.): 0
#
# Overhead Trace output
# ........ ............
#
# Samples: 0 of event 'kmem:kmalloc_node'
# Event count (approx.): 0
#
# Overhead Trace output
# ........ ............
#
# Samples: 0 of event 'kmem:kfree'
# Event count (approx.): 0
#
# Overhead Trace output
# ........ ............
#
# Samples: 8 of event 'kmem:kmem_cache_alloc'
# Event count (approx.): 8
#
# Overhead Trace output
# ........ ..................................................................................................................
#
75.00% call_site=ffffffffb9333b42 ptr=0xffff888bdf1a39c0 bytes_req=48 bytes_alloc=48 gfp_flags=GFP_NOFS|__GFP_ZERO
12.50% call_site=ffffffffb90ad33a ptr=0xffff8889f071f6e0 bytes_req=160 bytes_alloc=160 gfp_flags=GFP_ATOMIC|__GFP_NOTRACK
12.50% call_site=ffffffffb9287cc1 ptr=0xffff8889b12722d8 bytes_req=104 bytes_alloc=104 gfp_flags=GFP_NOFS|__GFP_ZERO
#
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-7-git-send-email-dsahern@gmail.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
-rw-r--r-- | tools/perf/Documentation/perf-report.txt | 7 | ||||
-rw-r--r-- | tools/perf/builtin-report.c | 14 |
2 files changed, 20 insertions, 1 deletions
diff --git a/tools/perf/Documentation/perf-report.txt b/tools/perf/Documentation/perf-report.txt index 2d1746295abf..3a166ae4a4d3 100644 --- a/tools/perf/Documentation/perf-report.txt +++ b/tools/perf/Documentation/perf-report.txt | |||
@@ -382,6 +382,13 @@ OPTIONS | |||
382 | --header-only:: | 382 | --header-only:: |
383 | Show only perf.data header (forces --stdio). | 383 | Show only perf.data header (forces --stdio). |
384 | 384 | ||
385 | --time:: | ||
386 | Only analyze samples within given time window: <start>,<stop>. Times | ||
387 | have the format seconds.microseconds. If start is not given (i.e., time | ||
388 | string is ',x.y') then analysis starts at the beginning of the file. If | ||
389 | stop time is not given (i.e, time string is 'x.y,') then analysis goes | ||
390 | to end of file. | ||
391 | |||
385 | --itrace:: | 392 | --itrace:: |
386 | Options for decoding instruction tracing data. The options are: | 393 | Options for decoding instruction tracing data. The options are: |
387 | 394 | ||
diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c index 3dfbfffe2ecd..d2afbe4a240d 100644 --- a/tools/perf/builtin-report.c +++ b/tools/perf/builtin-report.c | |||
@@ -36,7 +36,7 @@ | |||
36 | #include "util/hist.h" | 36 | #include "util/hist.h" |
37 | #include "util/data.h" | 37 | #include "util/data.h" |
38 | #include "arch/common.h" | 38 | #include "arch/common.h" |
39 | 39 | #include "util/time-utils.h" | |
40 | #include "util/auxtrace.h" | 40 | #include "util/auxtrace.h" |
41 | 41 | ||
42 | #include <dlfcn.h> | 42 | #include <dlfcn.h> |
@@ -59,6 +59,8 @@ struct report { | |||
59 | const char *pretty_printing_style; | 59 | const char *pretty_printing_style; |
60 | const char *cpu_list; | 60 | const char *cpu_list; |
61 | const char *symbol_filter_str; | 61 | const char *symbol_filter_str; |
62 | const char *time_str; | ||
63 | struct perf_time_interval ptime; | ||
62 | float min_percent; | 64 | float min_percent; |
63 | u64 nr_entries; | 65 | u64 nr_entries; |
64 | u64 queue_size; | 66 | u64 queue_size; |
@@ -158,6 +160,9 @@ static int process_sample_event(struct perf_tool *tool, | |||
158 | }; | 160 | }; |
159 | int ret = 0; | 161 | int ret = 0; |
160 | 162 | ||
163 | if (perf_time__skip_sample(&rep->ptime, sample->time)) | ||
164 | return 0; | ||
165 | |||
161 | if (machine__resolve(machine, &al, sample) < 0) { | 166 | if (machine__resolve(machine, &al, sample) < 0) { |
162 | pr_debug("problem processing %d event, skipping it.\n", | 167 | pr_debug("problem processing %d event, skipping it.\n", |
163 | event->header.type); | 168 | event->header.type); |
@@ -830,6 +835,8 @@ int cmd_report(int argc, const char **argv, const char *prefix __maybe_unused) | |||
830 | OPT_CALLBACK_DEFAULT(0, "stdio-color", NULL, "mode", | 835 | OPT_CALLBACK_DEFAULT(0, "stdio-color", NULL, "mode", |
831 | "'always' (default), 'never' or 'auto' only applicable to --stdio mode", | 836 | "'always' (default), 'never' or 'auto' only applicable to --stdio mode", |
832 | stdio__config_color, "always"), | 837 | stdio__config_color, "always"), |
838 | OPT_STRING(0, "time", &report.time_str, "str", | ||
839 | "Time span of interest (start,stop)"), | ||
833 | OPT_END() | 840 | OPT_END() |
834 | }; | 841 | }; |
835 | struct perf_data_file file = { | 842 | struct perf_data_file file = { |
@@ -1015,6 +1022,11 @@ repeat: | |||
1015 | if (symbol__init(&session->header.env) < 0) | 1022 | if (symbol__init(&session->header.env) < 0) |
1016 | goto error; | 1023 | goto error; |
1017 | 1024 | ||
1025 | if (perf_time__parse_str(&report.ptime, report.time_str) != 0) { | ||
1026 | pr_err("Invalid time string\n"); | ||
1027 | return -EINVAL; | ||
1028 | } | ||
1029 | |||
1018 | sort__setup_elide(stdout); | 1030 | sort__setup_elide(stdout); |
1019 | 1031 | ||
1020 | ret = __cmd_report(&report); | 1032 | ret = __cmd_report(&report); |