* [PATCHv9 0/3] perf stat: Add scripting support
@ 2016-01-06 10:49 Jiri Olsa
2016-01-06 10:49 ` [PATCH 1/3] perf tools: Fix cpu conversion in cpu_map__from_entries Jiri Olsa
` (3 more replies)
0 siblings, 4 replies; 11+ messages in thread
From: Jiri Olsa @ 2016-01-06 10:49 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Andi Kleen, Ulrich Drepper, Will Deacon, Stephane Eranian,
Don Zickus, lkml, David Ahern, Ingo Molnar, Namhyung Kim,
Peter Zijlstra, Liang, Kan
hi,
sending another version of stat scripting.
v9 changes:
- rebased on top of accepted patches
- desribed CPI metric in changelog [Arnaldo]
- fixed cpu conversion [Arnaldo]
v8 changes:
- check for stat callbacks properly [Namhyung]
- used '#!/usr/bin/env python' for stat-cpi.py [Namhyung]
- used tuple_set_u64 for storing u64 into python tuple [Namhyung]
v7 changes:
- perf stat record/report patches already taken,
posting the rest of the scripting support
- rebased to latest Arnaldo's perf/core
v6 changes:
- several patches from v4 already taken
- perf stat record can now place 'record' keyword
anywhere within stat options
- placed STAT feature checking earlier into record
patches so commands processing perf.data recognize
stat data and skip sample_type checking
- rebased on Arnaldo's perf/stat
- added Tested-by: Kan Liang <kan.liang@intel.com>
v5 changes:
- several patches from v4 already taken
- using u16 for cpu number in cpu_map_event
- renamed PERF_RECORD_HEADER_ATTR_UPDATE to PERF_RECORD_EVENT_UPDATE
- moved low hanging fuits patches to the start of the patchset
- patchset tested by Kan Liang, thanks!
v4 changes:
- added attr update event for event's cpumask
- forbig aggregation on task workloads
- some minor reorders and changelog fixes
v3 changes:
- added attr update event to handle unit,scale,name for event
it fixed the uncore_imc_1/cas_count_read/ record/report
- perf report -D now displays stat related events
- some minor and changelog fixes
v2 changes:
- rebased to latest Arnaldo's perf/core
- patches 1 to 11 already merged in
- added --per-core/--per-socket/-A options for perf stat report
command to allow custom aggregation in stat report, please
check new examples below
- couple changelogs changes
The initial attempt defined its own formula lang and allowed
triggering user's script on the end of the stat command:
http://marc.info/?l=linux-kernel&m=136742146322273&w=2
This patchset abandons the idea of new formula language
and rather adds support to:
- store stat data into perf.data file
- add python support to process stat events
Basically it allows to store stat data into perf.data and
post process it with python scripts in a similar way we
do for sampling data.
The stat data are stored in new stat, stat-round, stat-config user events.
stat - stored for each read syscall of the counter
stat round - stored for each interval or end of the command invocation
stat config - stores all the config information needed to process data
so report tool could restore the same output as record
The python script can now define 'stat__<eventname>_<modifier>' functions
to get stat events data and 'stat__interval' to get stat-round data.
See CPI script example in scripts/python/stat-cpi.py.
Also available in:
git://git.kernel.org/pub/scm/linux/kernel/git/jolsa/perf.git
perf/stat_script
thanks,
jirka
Examples:
- To record data for command stat workload:
$ perf stat record kill
...
Performance counter stats for 'kill':
0.372007 task-clock (msec) # 0.613 CPUs utilized
3 context-switches # 0.008 M/sec
0 cpu-migrations # 0.000 K/sec
62 page-faults # 0.167 M/sec
1,129,973 cycles # 3.038 GHz
<not supported> stalled-cycles-frontend
<not supported> stalled-cycles-backend
813,313 instructions # 0.72 insns per cycle
166,161 branches # 446.661 M/sec
8,747 branch-misses # 5.26% of all branches
0.000607287 seconds time elapsed
- To report perf stat data:
$ perf stat report
Performance counter stats for '/home/jolsa/bin/perf stat record kill':
0.372007 task-clock (msec) # inf CPUs utilized
3 context-switches # 0.008 M/sec
0 cpu-migrations # 0.000 K/sec
62 page-faults # 0.167 M/sec
1,129,973 cycles # 3.038 GHz
<not supported> stalled-cycles-frontend
<not supported> stalled-cycles-backend
813,313 instructions # 0.72 insns per cycle
166,161 branches # 446.661 M/sec
8,747 branch-misses # 5.26% of all branches
0.000000000 seconds time elapsed
- To store system-wide period stat data:
$ perf stat -e cycles:u,instructions:u -a -I 1000 record
# time counts unit events
1.000265471 462,311,482 cycles:u (100.00%)
1.000265471 590,037,440 instructions:u
2.000483453 722,532,336 cycles:u (100.00%)
2.000483453 848,678,197 instructions:u
3.000759876 75,990,880 cycles:u (100.00%)
3.000759876 86,187,813 instructions:u
^C 3.213960893 85,329,533 cycles:u (100.00%)
3.213960893 135,954,296 instructions:u
- To report perf stat data:
$ perf stat report
# time counts unit events
1.000265471 462,311,482 cycles:u (100.00%)
1.000265471 590,037,440 instructions:u
2.000483453 722,532,336 cycles:u (100.00%)
2.000483453 848,678,197 instructions:u
3.000759876 75,990,880 cycles:u (100.00%)
3.000759876 86,187,813 instructions:u
3.213960893 85,329,533 cycles:u (100.00%)
3.213960893 135,954,296 instructions:u
- To run stat-cpi.py script over perf.data:
$ perf script -s scripts/python/stat-cpi.py
1.000265: cpu -1, thread -1 -> cpi 0.783529 (462311482/590037440)
2.000483: cpu -1, thread -1 -> cpi 0.851362 (722532336/848678197)
3.000760: cpu -1, thread -1 -> cpi 0.881689 (75990880/86187813)
3.213961: cpu -1, thread -1 -> cpi 0.627634 (85329533/135954296)
- To pipe data from stat to stat-cpi script:
$ perf stat -e cycles:u,instructions:u -A -C 0 -I 1000 record | perf script -s scripts/python/stat-cpi.py
1.000192: cpu 0, thread -1 -> cpi 0.739535 (23921908/32347236)
2.000376: cpu 0, thread -1 -> cpi 1.663482 (2519340/1514498)
3.000621: cpu 0, thread -1 -> cpi 1.396308 (16162767/11575362)
4.000700: cpu 0, thread -1 -> cpi 1.092246 (20077258/18381624)
5.000867: cpu 0, thread -1 -> cpi 0.473816 (45157586/95306156)
6.001034: cpu 0, thread -1 -> cpi 0.532792 (43701668/82023818)
7.001195: cpu 0, thread -1 -> cpi 1.122059 (29890042/26638561)
- Raw script stat data output:
$ perf stat -e cycles:u,instructions:u -A -C 0 -I 1000 record | perf --no-pager script
CPU THREAD VAL ENA RUN TIME EVENT
0 -1 12302059 1000811347 1000810712 1000198821 cycles:u
0 -1 2565362 1000823218 1000823218 1000198821 instructions:u
0 -1 14453353 1000812704 1000812704 2000382283 cycles:u
0 -1 4600932 1000799342 1000799342 2000382283 instructions:u
0 -1 15245106 1000774425 1000774425 3000538255 cycles:u
0 -1 2624324 1000769310 1000769310 3000538255 instructions:u
- To display different aggregation in report:
$ perf stat -e cycles -a -I 1000 record sleep 3
# time counts unit events
1.000223609 703,427,617 cycles
2.000443651 609,975,307 cycles
3.000569616 668,479,597 cycles
3.000735323 1,155,816 cycles
$ perf stat report
# time counts unit events
1.000223609 703,427,617 cycles
2.000443651 609,975,307 cycles
3.000569616 668,479,597 cycles
3.000735323 1,155,816 cycles
$ perf stat report --per-core
# time core cpus counts unit events
1.000223609 S0-C0 2 327,612,412 cycles
1.000223609 S0-C1 2 375,815,205 cycles
2.000443651 S0-C0 2 287,462,177 cycles
2.000443651 S0-C1 2 322,513,130 cycles
3.000569616 S0-C0 2 271,571,908 cycles
3.000569616 S0-C1 2 396,907,689 cycles
3.000735323 S0-C0 2 694,977 cycles
3.000735323 S0-C1 2 460,839 cycles
$ perf stat report --per-socket
# time socket cpus counts unit events
1.000223609 S0 4 703,427,617 cycles
2.000443651 S0 4 609,975,307 cycles
3.000569616 S0 4 668,479,597 cycles
3.000735323 S0 4 1,155,816 cycles
$ perf stat report -A
# time CPU counts unit events
1.000223609 CPU0 205,431,505 cycles
1.000223609 CPU1 122,180,907 cycles
1.000223609 CPU2 176,649,682 cycles
1.000223609 CPU3 199,165,523 cycles
2.000443651 CPU0 148,447,922 cycles
2.000443651 CPU1 139,014,255 cycles
2.000443651 CPU2 204,436,559 cycles
2.000443651 CPU3 118,076,571 cycles
3.000569616 CPU0 149,788,954 cycles
3.000569616 CPU1 121,782,954 cycles
3.000569616 CPU2 247,277,700 cycles
3.000569616 CPU3 149,629,989 cycles
3.000735323 CPU0 269,675 cycles
3.000735323 CPU1 425,302 cycles
3.000735323 CPU2 364,169 cycles
3.000735323 CPU3 96,670 cycles
Cc: Andi Kleen <andi@firstfloor.org>
Cc: Ulrich Drepper <drepper@gmail.com>
Cc: Will Deacon <will.deacon@arm.com>
Cc: Stephane Eranian <eranian@google.com>
Cc: Don Zickus <dzickus@redhat.com>
Tested-by: Kan Liang <kan.liang@intel.com>
---
tools/perf/builtin-script.c | 36 ++++++++++++++++++++++++++++++++++++
tools/perf/scripts/python/stat-cpi.py | 77 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
tools/perf/util/cpumap.c | 13 +++++++++++--
3 files changed, 124 insertions(+), 2 deletions(-)
^ permalink raw reply [flat|nested] 11+ messages in thread
* [PATCH 1/3] perf tools: Fix cpu conversion in cpu_map__from_entries
2016-01-06 10:49 [PATCHv9 0/3] perf stat: Add scripting support Jiri Olsa
@ 2016-01-06 10:49 ` Jiri Olsa
2016-01-09 16:31 ` [tip:perf/core] perf cpumap: " tip-bot for Jiri Olsa
2016-01-06 10:49 ` [PATCH 2/3] perf script: Display stat events by default Jiri Olsa
` (2 subsequent siblings)
3 siblings, 1 reply; 11+ messages in thread
From: Jiri Olsa @ 2016-01-06 10:49 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: lkml, David Ahern, Ingo Molnar, Namhyung Kim, Peter Zijlstra, Liang, Kan
We can't convert u16 cpu_map_entries::cpu[x] value directly to int,
because it could hold -1, which would be converted as 65535.
Adding special treatment for -1, which is not real cpu number,
to be converted to (int -1).
Link: http://lkml.kernel.org/n/tip-6t5lp407ca76zlikz9rl2lcm@git.kernel.org
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
---
tools/perf/util/cpumap.c | 13 +++++++++++--
1 file changed, 11 insertions(+), 2 deletions(-)
diff --git a/tools/perf/util/cpumap.c b/tools/perf/util/cpumap.c
index a0717b93d8f5..fa935093a599 100644
--- a/tools/perf/util/cpumap.c
+++ b/tools/perf/util/cpumap.c
@@ -188,8 +188,17 @@ static struct cpu_map *cpu_map__from_entries(struct cpu_map_entries *cpus)
if (map) {
unsigned i;
- for (i = 0; i < cpus->nr; i++)
- map->map[i] = (int)cpus->cpu[i];
+ for (i = 0; i < cpus->nr; i++) {
+ /*
+ * Special treatment for -1, which is not real cpu number,
+ * and we need to use (int) -1 to initialize map[i],
+ * otherwise it would become 65535.
+ */
+ if (cpus->cpu[i] == (u16) -1)
+ map->map[i] = -1;
+ else
+ map->map[i] = (int) cpus->cpu[i];
+ }
}
return map;
--
2.4.3
^ permalink raw reply related [flat|nested] 11+ messages in thread
* [PATCH 2/3] perf script: Display stat events by default
2016-01-06 10:49 [PATCHv9 0/3] perf stat: Add scripting support Jiri Olsa
2016-01-06 10:49 ` [PATCH 1/3] perf tools: Fix cpu conversion in cpu_map__from_entries Jiri Olsa
@ 2016-01-06 10:49 ` Jiri Olsa
2016-01-09 16:31 ` [tip:perf/core] " tip-bot for Jiri Olsa
2016-01-06 10:49 ` [PATCH 3/3] perf script: Add stat-cpi.py script Jiri Olsa
2016-01-06 14:18 ` [PATCHv9 0/3] perf stat: Add scripting support Arnaldo Carvalho de Melo
3 siblings, 1 reply; 11+ messages in thread
From: Jiri Olsa @ 2016-01-06 10:49 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: lkml, David Ahern, Ingo Molnar, Namhyung Kim, Peter Zijlstra, Liang, Kan
If no script is specified for stat data, display
stat events in raw form.
$ perf stat record ls
SNIP
Performance counter stats for 'ls':
0.851585 task-clock (msec) # 0.717 CPUs utilized
0 context-switches # 0.000 K/sec
0 cpu-migrations # 0.000 K/sec
114 page-faults # 0.134 M/sec
2,620,918 cycles # 3.078 GHz
<not supported> stalled-cycles-frontend
<not supported> stalled-cycles-backend
2,714,111 instructions # 1.04 insns per cycle
542,434 branches # 636.970 M/sec
15,946 branch-misses # 2.94% of all branches
0.001186954 seconds time elapsed
$ perf script
CPU THREAD VAL ENA RUN TIME EVENT
-1 26185 851585 851585 851585 1186954 task-clock
-1 26185 0 851585 851585 1186954 context-switches
-1 26185 0 851585 851585 1186954 cpu-migrations
-1 26185 114 851585 851585 1186954 page-faults
-1 26185 2620918 853340 853340 1186954 cycles
-1 26185 0 0 0 1186954 stalled-cycles-frontend
-1 26185 0 0 0 1186954 stalled-cycles-backend
-1 26185 2714111 853340 853340 1186954 instructions
-1 26185 542434 853340 853340 1186954 branches
-1 26185 15946 853340 853340 1186954 branch-misses
Tested-by: Kan Liang <kan.liang@intel.com>
Link: http://lkml.kernel.org/n/tip-ph7bpnetmskvmietfwllf6i6@git.kernel.org
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
---
tools/perf/builtin-script.c | 36 ++++++++++++++++++++++++++++++++++++
1 file changed, 36 insertions(+)
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index 521e3e0e7625..c298cdc618e2 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -677,10 +677,46 @@ static void process_event(struct perf_script *script __maybe_unused, union perf_
static struct scripting_ops *scripting_ops;
+static void __process_stat(struct perf_evsel *counter, u64 time)
+{
+ int nthreads = thread_map__nr(counter->threads);
+ int ncpus = perf_evsel__nr_cpus(counter);
+ int cpu, thread;
+ static int header_printed;
+
+ if (counter->system_wide)
+ nthreads = 1;
+
+ if (!header_printed) {
+ printf("%3s %8s %15s %15s %15s %15s %s\n",
+ "CPU", "THREAD", "VAL", "ENA", "RUN", "TIME", "EVENT");
+ header_printed = 1;
+ }
+
+ for (thread = 0; thread < nthreads; thread++) {
+ for (cpu = 0; cpu < ncpus; cpu++) {
+ struct perf_counts_values *counts;
+
+ counts = perf_counts(counter->counts, cpu, thread);
+
+ printf("%3d %8d %15" PRIu64 " %15" PRIu64 " %15" PRIu64 " %15" PRIu64 " %s\n",
+ counter->cpus->map[cpu],
+ thread_map__pid(counter->threads, thread),
+ counts->val,
+ counts->ena,
+ counts->run,
+ time,
+ perf_evsel__name(counter));
+ }
+ }
+}
+
static void process_stat(struct perf_evsel *counter, u64 time)
{
if (scripting_ops && scripting_ops->process_stat)
scripting_ops->process_stat(&stat_config, counter, time);
+ else
+ __process_stat(counter, time);
}
static void process_stat_interval(u64 time)
--
2.4.3
^ permalink raw reply related [flat|nested] 11+ messages in thread
* [PATCH 3/3] perf script: Add stat-cpi.py script
2016-01-06 10:49 [PATCHv9 0/3] perf stat: Add scripting support Jiri Olsa
2016-01-06 10:49 ` [PATCH 1/3] perf tools: Fix cpu conversion in cpu_map__from_entries Jiri Olsa
2016-01-06 10:49 ` [PATCH 2/3] perf script: Display stat events by default Jiri Olsa
@ 2016-01-06 10:49 ` Jiri Olsa
2016-01-09 16:32 ` [tip:perf/core] " tip-bot for Jiri Olsa
2016-01-06 14:18 ` [PATCHv9 0/3] perf stat: Add scripting support Arnaldo Carvalho de Melo
3 siblings, 1 reply; 11+ messages in thread
From: Jiri Olsa @ 2016-01-06 10:49 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: lkml, David Ahern, Ingo Molnar, Namhyung Kim, Peter Zijlstra, Liang, Kan
Adding stat-cpi.py as an example of how to do stat scripting.
It computes the CPI metrics from cycles and instructions
events.
The CPI is based performance metric showing the Cycles Per
Instructions ratio, which helps to identify cycles-hungry code.
Following stat record/report/script combinations could be used:
- get CPI for given workload
$ perf stat -e cycles,instructions record ls
SNIP
Performance counter stats for 'ls':
2,904,431 cycles
3,346,878 instructions # 1.15 insns per cycle
0.001782686 seconds time elapsed
$ perf script -s ./scripts/python/stat-cpi.py
0.001783: cpu -1, thread -1 -> cpi 0.867803 (2904431/3346878)
$ perf stat -e cycles,instructions record ls | perf script -s ./scripts/python/stat-cpi.py
SNIP
0.001730: cpu -1, thread -1 -> cpi 0.869026 (2928292/3369627)
- get CPI systemwide:
$ perf stat -e cycles,instructions -a -I 1000 record sleep 3
# time counts unit events
1.000158618 594,274,711 cycles (100.00%)
1.000158618 441,898,250 instructions
2.000350973 567,649,705 cycles (100.00%)
2.000350973 432,669,206 instructions
3.000559210 561,940,430 cycles (100.00%)
3.000559210 420,403,465 instructions
3.000670798 780,105 cycles (100.00%)
3.000670798 326,516 instructions
$ perf script -s ./scripts/python/stat-cpi.py
1.000159: cpu -1, thread -1 -> cpi 1.344823 (594274711/441898250)
2.000351: cpu -1, thread -1 -> cpi 1.311972 (567649705/432669206)
3.000559: cpu -1, thread -1 -> cpi 1.336669 (561940430/420403465)
3.000671: cpu -1, thread -1 -> cpi 2.389178 (780105/326516)
$ perf stat -e cycles,instructions -a -I 1000 record sleep 3 | perf script -s ./scripts/python/stat-cpi.py
1.000202: cpu -1, thread -1 -> cpi 1.035091 (940778881/908885530)
2.000392: cpu -1, thread -1 -> cpi 1.442600 (627493992/434974455)
3.000545: cpu -1, thread -1 -> cpi 1.353612 (741463930/547766890)
3.000622: cpu -1, thread -1 -> cpi 2.642110 (784083/296764)
Tested-by: Kan Liang <kan.liang@intel.com>
Link: http://lkml.kernel.org/n/tip-15vwwb4yea15wzz6bqbxdpc0@git.kernel.org
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
---
tools/perf/scripts/python/stat-cpi.py | 77 +++++++++++++++++++++++++++++++++++
1 file changed, 77 insertions(+)
create mode 100644 tools/perf/scripts/python/stat-cpi.py
diff --git a/tools/perf/scripts/python/stat-cpi.py b/tools/perf/scripts/python/stat-cpi.py
new file mode 100644
index 000000000000..8b60f343dd07
--- /dev/null
+++ b/tools/perf/scripts/python/stat-cpi.py
@@ -0,0 +1,77 @@
+#!/usr/bin/env python
+
+data = {}
+times = []
+threads = []
+cpus = []
+
+def get_key(time, event, cpu, thread):
+ return "%d-%s-%d-%d" % (time, event, cpu, thread)
+
+def store_key(time, cpu, thread):
+ if (time not in times):
+ times.append(time)
+
+ if (cpu not in cpus):
+ cpus.append(cpu)
+
+ if (thread not in threads):
+ threads.append(thread)
+
+def store(time, event, cpu, thread, val, ena, run):
+ #print "event %s cpu %d, thread %d, time %d, val %d, ena %d, run %d" % \
+ # (event, cpu, thread, time, val, ena, run)
+
+ store_key(time, cpu, thread)
+ key = get_key(time, event, cpu, thread)
+ data[key] = [ val, ena, run]
+
+def get(time, event, cpu, thread):
+ key = get_key(time, event, cpu, thread)
+ return data[key][0]
+
+def stat__cycles_k(cpu, thread, time, val, ena, run):
+ store(time, "cycles", cpu, thread, val, ena, run);
+
+def stat__instructions_k(cpu, thread, time, val, ena, run):
+ store(time, "instructions", cpu, thread, val, ena, run);
+
+def stat__cycles_u(cpu, thread, time, val, ena, run):
+ store(time, "cycles", cpu, thread, val, ena, run);
+
+def stat__instructions_u(cpu, thread, time, val, ena, run):
+ store(time, "instructions", cpu, thread, val, ena, run);
+
+def stat__cycles(cpu, thread, time, val, ena, run):
+ store(time, "cycles", cpu, thread, val, ena, run);
+
+def stat__instructions(cpu, thread, time, val, ena, run):
+ store(time, "instructions", cpu, thread, val, ena, run);
+
+def stat__interval(time):
+ for cpu in cpus:
+ for thread in threads:
+ cyc = get(time, "cycles", cpu, thread)
+ ins = get(time, "instructions", cpu, thread)
+ cpi = 0
+
+ if ins != 0:
+ cpi = cyc/float(ins)
+
+ print "%15f: cpu %d, thread %d -> cpi %f (%d/%d)" % (time/(float(1000000000)), cpu, thread, cpi, cyc, ins)
+
+def trace_end():
+ pass
+# XXX trace_end callback could be used as an alternative place
+# to compute same values as in the script above:
+#
+# for time in times:
+# for cpu in cpus:
+# for thread in threads:
+# cyc = get(time, "cycles", cpu, thread)
+# ins = get(time, "instructions", cpu, thread)
+#
+# if ins != 0:
+# cpi = cyc/float(ins)
+#
+# print "time %.9f, cpu %d, thread %d -> cpi %f" % (time/(float(1000000000)), cpu, thread, cpi)
--
2.4.3
^ permalink raw reply related [flat|nested] 11+ messages in thread
* Re: [PATCHv9 0/3] perf stat: Add scripting support
2016-01-06 10:49 [PATCHv9 0/3] perf stat: Add scripting support Jiri Olsa
` (2 preceding siblings ...)
2016-01-06 10:49 ` [PATCH 3/3] perf script: Add stat-cpi.py script Jiri Olsa
@ 2016-01-06 14:18 ` Arnaldo Carvalho de Melo
2016-01-06 14:38 ` Jiri Olsa
3 siblings, 1 reply; 11+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-01-06 14:18 UTC (permalink / raw)
To: Jiri Olsa
Cc: Andi Kleen, Ulrich Drepper, Will Deacon, Stephane Eranian,
Don Zickus, lkml, David Ahern, Ingo Molnar, Namhyung Kim,
Peter Zijlstra, Liang, Kan
Em Wed, Jan 06, 2016 at 11:49:54AM +0100, Jiri Olsa escreveu:
> hi,
> sending another version of stat scripting.
> v9 changes:
> - rebased on top of accepted patches
> - desribed CPI metric in changelog [Arnaldo]
> - fixed cpu conversion [Arnaldo]
Thanks, applied. Testing the cpi script with an endless:
perf stat record -I 1000 -a | perf script -s ~acme/git/linux/tools/perf/scripts/python/stat-cpi.py
187.151796: cpu -1, thread -1 -> cpi 0.797917 (2568467461/3218963700)
188.151979: cpu -1, thread -1 -> cpi 0.734628 (2714373371/3694892981)
189.152212: cpu -1, thread -1 -> cpi 0.753332 (2958819204/3927644236)
190.152975: cpu -1, thread -1 -> cpi 1.587754 (202360895/127451009)
191.153486: cpu -1, thread -1 -> cpi 1.558219 (290557309/186467579)
in one monitor while trying various workloads in another, to see how it reacts,
and after a while those raw numbers at the end of each line become just noise,
I think they should be shown only under 'stat-cpy -v' (I think we can pass args
to the 'perf script' scripts, right?
Also the 'cpu', 'thread' and '-> cpi' could be turned into headers, like 'perf
stat' does?
Anyway, you called it 'example script' and we can improve it on top of what I
pushed to perf/core, i.e. this patchkit, unchanged, thanks!
- Arnaldo
> v8 changes:
> - check for stat callbacks properly [Namhyung]
> - used '#!/usr/bin/env python' for stat-cpi.py [Namhyung]
> - used tuple_set_u64 for storing u64 into python tuple [Namhyung]
>
> v7 changes:
> - perf stat record/report patches already taken,
> posting the rest of the scripting support
> - rebased to latest Arnaldo's perf/core
>
> v6 changes:
> - several patches from v4 already taken
> - perf stat record can now place 'record' keyword
> anywhere within stat options
> - placed STAT feature checking earlier into record
> patches so commands processing perf.data recognize
> stat data and skip sample_type checking
> - rebased on Arnaldo's perf/stat
> - added Tested-by: Kan Liang <kan.liang@intel.com>
>
> v5 changes:
> - several patches from v4 already taken
> - using u16 for cpu number in cpu_map_event
> - renamed PERF_RECORD_HEADER_ATTR_UPDATE to PERF_RECORD_EVENT_UPDATE
> - moved low hanging fuits patches to the start of the patchset
> - patchset tested by Kan Liang, thanks!
>
> v4 changes:
> - added attr update event for event's cpumask
> - forbig aggregation on task workloads
> - some minor reorders and changelog fixes
>
> v3 changes:
> - added attr update event to handle unit,scale,name for event
> it fixed the uncore_imc_1/cas_count_read/ record/report
> - perf report -D now displays stat related events
> - some minor and changelog fixes
>
> v2 changes:
> - rebased to latest Arnaldo's perf/core
> - patches 1 to 11 already merged in
> - added --per-core/--per-socket/-A options for perf stat report
> command to allow custom aggregation in stat report, please
> check new examples below
> - couple changelogs changes
>
> The initial attempt defined its own formula lang and allowed
> triggering user's script on the end of the stat command:
> http://marc.info/?l=linux-kernel&m=136742146322273&w=2
>
> This patchset abandons the idea of new formula language
> and rather adds support to:
> - store stat data into perf.data file
> - add python support to process stat events
>
> Basically it allows to store stat data into perf.data and
> post process it with python scripts in a similar way we
> do for sampling data.
>
> The stat data are stored in new stat, stat-round, stat-config user events.
> stat - stored for each read syscall of the counter
> stat round - stored for each interval or end of the command invocation
> stat config - stores all the config information needed to process data
> so report tool could restore the same output as record
>
> The python script can now define 'stat__<eventname>_<modifier>' functions
> to get stat events data and 'stat__interval' to get stat-round data.
>
> See CPI script example in scripts/python/stat-cpi.py.
>
> Also available in:
> git://git.kernel.org/pub/scm/linux/kernel/git/jolsa/perf.git
> perf/stat_script
>
> thanks,
> jirka
>
> Examples:
>
> - To record data for command stat workload:
>
> $ perf stat record kill
> ...
>
> Performance counter stats for 'kill':
>
> 0.372007 task-clock (msec) # 0.613 CPUs utilized
> 3 context-switches # 0.008 M/sec
> 0 cpu-migrations # 0.000 K/sec
> 62 page-faults # 0.167 M/sec
> 1,129,973 cycles # 3.038 GHz
> <not supported> stalled-cycles-frontend
> <not supported> stalled-cycles-backend
> 813,313 instructions # 0.72 insns per cycle
> 166,161 branches # 446.661 M/sec
> 8,747 branch-misses # 5.26% of all branches
>
> 0.000607287 seconds time elapsed
>
> - To report perf stat data:
>
> $ perf stat report
>
> Performance counter stats for '/home/jolsa/bin/perf stat record kill':
>
> 0.372007 task-clock (msec) # inf CPUs utilized
> 3 context-switches # 0.008 M/sec
> 0 cpu-migrations # 0.000 K/sec
> 62 page-faults # 0.167 M/sec
> 1,129,973 cycles # 3.038 GHz
> <not supported> stalled-cycles-frontend
> <not supported> stalled-cycles-backend
> 813,313 instructions # 0.72 insns per cycle
> 166,161 branches # 446.661 M/sec
> 8,747 branch-misses # 5.26% of all branches
>
> 0.000000000 seconds time elapsed
>
> - To store system-wide period stat data:
>
> $ perf stat -e cycles:u,instructions:u -a -I 1000 record
> # time counts unit events
> 1.000265471 462,311,482 cycles:u (100.00%)
> 1.000265471 590,037,440 instructions:u
> 2.000483453 722,532,336 cycles:u (100.00%)
> 2.000483453 848,678,197 instructions:u
> 3.000759876 75,990,880 cycles:u (100.00%)
> 3.000759876 86,187,813 instructions:u
> ^C 3.213960893 85,329,533 cycles:u (100.00%)
> 3.213960893 135,954,296 instructions:u
>
> - To report perf stat data:
>
> $ perf stat report
> # time counts unit events
> 1.000265471 462,311,482 cycles:u (100.00%)
> 1.000265471 590,037,440 instructions:u
> 2.000483453 722,532,336 cycles:u (100.00%)
> 2.000483453 848,678,197 instructions:u
> 3.000759876 75,990,880 cycles:u (100.00%)
> 3.000759876 86,187,813 instructions:u
> 3.213960893 85,329,533 cycles:u (100.00%)
> 3.213960893 135,954,296 instructions:u
>
> - To run stat-cpi.py script over perf.data:
>
> $ perf script -s scripts/python/stat-cpi.py
> 1.000265: cpu -1, thread -1 -> cpi 0.783529 (462311482/590037440)
> 2.000483: cpu -1, thread -1 -> cpi 0.851362 (722532336/848678197)
> 3.000760: cpu -1, thread -1 -> cpi 0.881689 (75990880/86187813)
> 3.213961: cpu -1, thread -1 -> cpi 0.627634 (85329533/135954296)
>
> - To pipe data from stat to stat-cpi script:
>
> $ perf stat -e cycles:u,instructions:u -A -C 0 -I 1000 record | perf script -s scripts/python/stat-cpi.py
> 1.000192: cpu 0, thread -1 -> cpi 0.739535 (23921908/32347236)
> 2.000376: cpu 0, thread -1 -> cpi 1.663482 (2519340/1514498)
> 3.000621: cpu 0, thread -1 -> cpi 1.396308 (16162767/11575362)
> 4.000700: cpu 0, thread -1 -> cpi 1.092246 (20077258/18381624)
> 5.000867: cpu 0, thread -1 -> cpi 0.473816 (45157586/95306156)
> 6.001034: cpu 0, thread -1 -> cpi 0.532792 (43701668/82023818)
> 7.001195: cpu 0, thread -1 -> cpi 1.122059 (29890042/26638561)
>
> - Raw script stat data output:
>
> $ perf stat -e cycles:u,instructions:u -A -C 0 -I 1000 record | perf --no-pager script
> CPU THREAD VAL ENA RUN TIME EVENT
> 0 -1 12302059 1000811347 1000810712 1000198821 cycles:u
> 0 -1 2565362 1000823218 1000823218 1000198821 instructions:u
> 0 -1 14453353 1000812704 1000812704 2000382283 cycles:u
> 0 -1 4600932 1000799342 1000799342 2000382283 instructions:u
> 0 -1 15245106 1000774425 1000774425 3000538255 cycles:u
> 0 -1 2624324 1000769310 1000769310 3000538255 instructions:u
>
> - To display different aggregation in report:
>
> $ perf stat -e cycles -a -I 1000 record sleep 3
> # time counts unit events
> 1.000223609 703,427,617 cycles
> 2.000443651 609,975,307 cycles
> 3.000569616 668,479,597 cycles
> 3.000735323 1,155,816 cycles
>
> $ perf stat report
> # time counts unit events
> 1.000223609 703,427,617 cycles
> 2.000443651 609,975,307 cycles
> 3.000569616 668,479,597 cycles
> 3.000735323 1,155,816 cycles
>
> $ perf stat report --per-core
> # time core cpus counts unit events
> 1.000223609 S0-C0 2 327,612,412 cycles
> 1.000223609 S0-C1 2 375,815,205 cycles
> 2.000443651 S0-C0 2 287,462,177 cycles
> 2.000443651 S0-C1 2 322,513,130 cycles
> 3.000569616 S0-C0 2 271,571,908 cycles
> 3.000569616 S0-C1 2 396,907,689 cycles
> 3.000735323 S0-C0 2 694,977 cycles
> 3.000735323 S0-C1 2 460,839 cycles
>
> $ perf stat report --per-socket
> # time socket cpus counts unit events
> 1.000223609 S0 4 703,427,617 cycles
> 2.000443651 S0 4 609,975,307 cycles
> 3.000569616 S0 4 668,479,597 cycles
> 3.000735323 S0 4 1,155,816 cycles
>
> $ perf stat report -A
> # time CPU counts unit events
> 1.000223609 CPU0 205,431,505 cycles
> 1.000223609 CPU1 122,180,907 cycles
> 1.000223609 CPU2 176,649,682 cycles
> 1.000223609 CPU3 199,165,523 cycles
> 2.000443651 CPU0 148,447,922 cycles
> 2.000443651 CPU1 139,014,255 cycles
> 2.000443651 CPU2 204,436,559 cycles
> 2.000443651 CPU3 118,076,571 cycles
> 3.000569616 CPU0 149,788,954 cycles
> 3.000569616 CPU1 121,782,954 cycles
> 3.000569616 CPU2 247,277,700 cycles
> 3.000569616 CPU3 149,629,989 cycles
> 3.000735323 CPU0 269,675 cycles
> 3.000735323 CPU1 425,302 cycles
> 3.000735323 CPU2 364,169 cycles
> 3.000735323 CPU3 96,670 cycles
>
>
> Cc: Andi Kleen <andi@firstfloor.org>
> Cc: Ulrich Drepper <drepper@gmail.com>
> Cc: Will Deacon <will.deacon@arm.com>
> Cc: Stephane Eranian <eranian@google.com>
> Cc: Don Zickus <dzickus@redhat.com>
> Tested-by: Kan Liang <kan.liang@intel.com>
> ---
> tools/perf/builtin-script.c | 36 ++++++++++++++++++++++++++++++++++++
> tools/perf/scripts/python/stat-cpi.py | 77 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
> tools/perf/util/cpumap.c | 13 +++++++++++--
> 3 files changed, 124 insertions(+), 2 deletions(-)
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCHv9 0/3] perf stat: Add scripting support
2016-01-06 14:18 ` [PATCHv9 0/3] perf stat: Add scripting support Arnaldo Carvalho de Melo
@ 2016-01-06 14:38 ` Jiri Olsa
2016-01-06 15:05 ` Arnaldo Carvalho de Melo
0 siblings, 1 reply; 11+ messages in thread
From: Jiri Olsa @ 2016-01-06 14:38 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Jiri Olsa, Andi Kleen, Ulrich Drepper, Will Deacon,
Stephane Eranian, Don Zickus, lkml, David Ahern, Ingo Molnar,
Namhyung Kim, Peter Zijlstra, Liang, Kan
On Wed, Jan 06, 2016 at 11:18:02AM -0300, Arnaldo Carvalho de Melo wrote:
> Em Wed, Jan 06, 2016 at 11:49:54AM +0100, Jiri Olsa escreveu:
> > hi,
> > sending another version of stat scripting.
>
> > v9 changes:
> > - rebased on top of accepted patches
> > - desribed CPI metric in changelog [Arnaldo]
> > - fixed cpu conversion [Arnaldo]
>
> Thanks, applied. Testing the cpi script with an endless:
>
> perf stat record -I 1000 -a | perf script -s ~acme/git/linux/tools/perf/scripts/python/stat-cpi.py
> 187.151796: cpu -1, thread -1 -> cpi 0.797917 (2568467461/3218963700)
> 188.151979: cpu -1, thread -1 -> cpi 0.734628 (2714373371/3694892981)
> 189.152212: cpu -1, thread -1 -> cpi 0.753332 (2958819204/3927644236)
> 190.152975: cpu -1, thread -1 -> cpi 1.587754 (202360895/127451009)
> 191.153486: cpu -1, thread -1 -> cpi 1.558219 (290557309/186467579)
>
> in one monitor while trying various workloads in another, to see how it reacts,
> and after a while those raw numbers at the end of each line become just noise,
> I think they should be shown only under 'stat-cpy -v' (I think we can pass args
> to the 'perf script' scripts, right?
>
> Also the 'cpu', 'thread' and '-> cpi' could be turned into headers, like 'perf
> stat' does?
>
> Anyway, you called it 'example script' and we can improve it on top of what I
> pushed to perf/core, i.e. this patchkit, unchanged, thanks!
yep, it's just noise and it's just an example to show
how the stat scripting works.. we can tune it up with
more ratios ;-)
jirka
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCHv9 0/3] perf stat: Add scripting support
2016-01-06 14:38 ` Jiri Olsa
@ 2016-01-06 15:05 ` Arnaldo Carvalho de Melo
2016-01-06 15:39 ` Jiri Olsa
0 siblings, 1 reply; 11+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-01-06 15:05 UTC (permalink / raw)
To: Jiri Olsa
Cc: Jiri Olsa, Andi Kleen, Ulrich Drepper, Will Deacon,
Stephane Eranian, Don Zickus, lkml, David Ahern, Ingo Molnar,
Namhyung Kim, Peter Zijlstra, Liang, Kan
Em Wed, Jan 06, 2016 at 03:38:53PM +0100, Jiri Olsa escreveu:
> On Wed, Jan 06, 2016 at 11:18:02AM -0300, Arnaldo Carvalho de Melo wrote:
> > Em Wed, Jan 06, 2016 at 11:49:54AM +0100, Jiri Olsa escreveu:
> > > hi,
> > > sending another version of stat scripting.
> >
> > > v9 changes:
> > > - rebased on top of accepted patches
> > > - desribed CPI metric in changelog [Arnaldo]
> > > - fixed cpu conversion [Arnaldo]
> >
> > Thanks, applied. Testing the cpi script with an endless:
> >
> > perf stat record -I 1000 -a | perf script -s ~acme/git/linux/tools/perf/scripts/python/stat-cpi.py
> > 187.151796: cpu -1, thread -1 -> cpi 0.797917 (2568467461/3218963700)
> > 188.151979: cpu -1, thread -1 -> cpi 0.734628 (2714373371/3694892981)
> > 189.152212: cpu -1, thread -1 -> cpi 0.753332 (2958819204/3927644236)
> > 190.152975: cpu -1, thread -1 -> cpi 1.587754 (202360895/127451009)
> > 191.153486: cpu -1, thread -1 -> cpi 1.558219 (290557309/186467579)
> >
> > in one monitor while trying various workloads in another, to see how it reacts,
> > and after a while those raw numbers at the end of each line become just noise,
> > I think they should be shown only under 'stat-cpy -v' (I think we can pass args
> > to the 'perf script' scripts, right?
> >
> > Also the 'cpu', 'thread' and '-> cpi' could be turned into headers, like 'perf
> > stat' does?
> >
> > Anyway, you called it 'example script' and we can improve it on top of what I
> > pushed to perf/core, i.e. this patchkit, unchanged, thanks!
>
> yep, it's just noise and it's just an example to show
Hey, its not "just noise", I meant just the "(2568467461/3218963700)"
part at the end of each line and the repetitive cpu/thread/cpi stuff
that can be moved to the first line, as headers.
> how the stat scripting works.. we can tune it up with
> more ratios ;-)
>
> jirka
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCHv9 0/3] perf stat: Add scripting support
2016-01-06 15:05 ` Arnaldo Carvalho de Melo
@ 2016-01-06 15:39 ` Jiri Olsa
0 siblings, 0 replies; 11+ messages in thread
From: Jiri Olsa @ 2016-01-06 15:39 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Jiri Olsa, Andi Kleen, Ulrich Drepper, Will Deacon,
Stephane Eranian, Don Zickus, lkml, David Ahern, Ingo Molnar,
Namhyung Kim, Peter Zijlstra, Liang, Kan
On Wed, Jan 06, 2016 at 12:05:41PM -0300, Arnaldo Carvalho de Melo wrote:
> Em Wed, Jan 06, 2016 at 03:38:53PM +0100, Jiri Olsa escreveu:
> > On Wed, Jan 06, 2016 at 11:18:02AM -0300, Arnaldo Carvalho de Melo wrote:
> > > Em Wed, Jan 06, 2016 at 11:49:54AM +0100, Jiri Olsa escreveu:
> > > > hi,
> > > > sending another version of stat scripting.
> > >
> > > > v9 changes:
> > > > - rebased on top of accepted patches
> > > > - desribed CPI metric in changelog [Arnaldo]
> > > > - fixed cpu conversion [Arnaldo]
> > >
> > > Thanks, applied. Testing the cpi script with an endless:
> > >
> > > perf stat record -I 1000 -a | perf script -s ~acme/git/linux/tools/perf/scripts/python/stat-cpi.py
> > > 187.151796: cpu -1, thread -1 -> cpi 0.797917 (2568467461/3218963700)
> > > 188.151979: cpu -1, thread -1 -> cpi 0.734628 (2714373371/3694892981)
> > > 189.152212: cpu -1, thread -1 -> cpi 0.753332 (2958819204/3927644236)
> > > 190.152975: cpu -1, thread -1 -> cpi 1.587754 (202360895/127451009)
> > > 191.153486: cpu -1, thread -1 -> cpi 1.558219 (290557309/186467579)
> > >
> > > in one monitor while trying various workloads in another, to see how it reacts,
> > > and after a while those raw numbers at the end of each line become just noise,
> > > I think they should be shown only under 'stat-cpy -v' (I think we can pass args
> > > to the 'perf script' scripts, right?
> > >
> > > Also the 'cpu', 'thread' and '-> cpi' could be turned into headers, like 'perf
> > > stat' does?
> > >
> > > Anyway, you called it 'example script' and we can improve it on top of what I
> > > pushed to perf/core, i.e. this patchkit, unchanged, thanks!
> >
> > yep, it's just noise and it's just an example to show
>
> Hey, its not "just noise", I meant just the "(2568467461/3218963700)"
> part at the end of each line and the repetitive cpu/thread/cpi stuff
> that can be moved to the first line, as headers.
yep, thats what I meant as well
jirka
^ permalink raw reply [flat|nested] 11+ messages in thread
* [tip:perf/core] perf cpumap: Fix cpu conversion in cpu_map__from_entries
2016-01-06 10:49 ` [PATCH 1/3] perf tools: Fix cpu conversion in cpu_map__from_entries Jiri Olsa
@ 2016-01-09 16:31 ` tip-bot for Jiri Olsa
0 siblings, 0 replies; 11+ messages in thread
From: tip-bot for Jiri Olsa @ 2016-01-09 16:31 UTC (permalink / raw)
To: linux-tip-commits
Cc: acme, mingo, namhyung, a.p.zijlstra, acme, dsahern, kan.liang,
tglx, linux-kernel, jolsa, hpa
Commit-ID: 15d2b9956b41ffb5961b897bf61cdc09f722dfbf
Gitweb: http://git.kernel.org/tip/15d2b9956b41ffb5961b897bf61cdc09f722dfbf
Author: Jiri Olsa <jolsa@kernel.org>
AuthorDate: Wed, 6 Jan 2016 11:49:55 +0100
Committer: Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Wed, 6 Jan 2016 20:11:16 -0300
perf cpumap: Fix cpu conversion in cpu_map__from_entries
We can't convert u16 cpu_map_entries::cpu[x] value directly to int,
because it could hold -1, which would be converted as 65535.
Adding special treatment for -1, which is not real cpu number, to be
converted to (int -1).
Reported-by: Arnaldo Carvalho de Melo <acme@kernel.org>
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Kan Liang <kan.liang@intel.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/1452077397-31958-2-git-send-email-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/util/cpumap.c | 13 +++++++++++--
1 file changed, 11 insertions(+), 2 deletions(-)
diff --git a/tools/perf/util/cpumap.c b/tools/perf/util/cpumap.c
index a0717b9..fa93509 100644
--- a/tools/perf/util/cpumap.c
+++ b/tools/perf/util/cpumap.c
@@ -188,8 +188,17 @@ static struct cpu_map *cpu_map__from_entries(struct cpu_map_entries *cpus)
if (map) {
unsigned i;
- for (i = 0; i < cpus->nr; i++)
- map->map[i] = (int)cpus->cpu[i];
+ for (i = 0; i < cpus->nr; i++) {
+ /*
+ * Special treatment for -1, which is not real cpu number,
+ * and we need to use (int) -1 to initialize map[i],
+ * otherwise it would become 65535.
+ */
+ if (cpus->cpu[i] == (u16) -1)
+ map->map[i] = -1;
+ else
+ map->map[i] = (int) cpus->cpu[i];
+ }
}
return map;
^ permalink raw reply related [flat|nested] 11+ messages in thread
* [tip:perf/core] perf script: Display stat events by default
2016-01-06 10:49 ` [PATCH 2/3] perf script: Display stat events by default Jiri Olsa
@ 2016-01-09 16:31 ` tip-bot for Jiri Olsa
0 siblings, 0 replies; 11+ messages in thread
From: tip-bot for Jiri Olsa @ 2016-01-09 16:31 UTC (permalink / raw)
To: linux-tip-commits
Cc: tglx, jolsa, hpa, mingo, a.p.zijlstra, linux-kernel, acme,
dsahern, kan.liang, namhyung
Commit-ID: 36e33c53f4b693d96fb8dd4529fe14306d4e3e76
Gitweb: http://git.kernel.org/tip/36e33c53f4b693d96fb8dd4529fe14306d4e3e76
Author: Jiri Olsa <jolsa@kernel.org>
AuthorDate: Wed, 6 Jan 2016 11:49:56 +0100
Committer: Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Wed, 6 Jan 2016 20:11:16 -0300
perf script: Display stat events by default
If no script is specified for stat data, display stat events in raw
form.
$ perf stat record ls
SNIP
Performance counter stats for 'ls':
0.851585 task-clock (msec) # 0.717 CPUs utilized
0 context-switches # 0.000 K/sec
0 cpu-migrations # 0.000 K/sec
114 page-faults # 0.134 M/sec
2,620,918 cycles # 3.078 GHz
<not supported> stalled-cycles-frontend
<not supported> stalled-cycles-backend
2,714,111 instructions # 1.04 insns per cycle
542,434 branches # 636.970 M/sec
15,946 branch-misses # 2.94% of all branches
0.001186954 seconds time elapsed
$ perf script
CPU THREAD VAL ENA RUN TIME EVENT
-1 26185 851585 851585 851585 1186954 task-clock
-1 26185 0 851585 851585 1186954 context-switches
-1 26185 0 851585 851585 1186954 cpu-migrations
-1 26185 114 851585 851585 1186954 page-faults
-1 26185 2620918 853340 853340 1186954 cycles
-1 26185 0 0 0 1186954 stalled-cycles-frontend
-1 26185 0 0 0 1186954 stalled-cycles-backend
-1 26185 2714111 853340 853340 1186954 instructions
-1 26185 542434 853340 853340 1186954 branches
-1 26185 15946 853340 853340 1186954 branch-misses
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Tested-by: Kan Liang <kan.liang@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/1452077397-31958-3-git-send-email-jolsa@kernel.org
[ Rename 'time' parameter to 'tstamp' to fix build on older distros ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/builtin-script.c | 36 ++++++++++++++++++++++++++++++++++++
1 file changed, 36 insertions(+)
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index 5e18654..5e2f9d2 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -677,10 +677,46 @@ static void process_event(struct perf_script *script __maybe_unused, union perf_
static struct scripting_ops *scripting_ops;
+static void __process_stat(struct perf_evsel *counter, u64 tstamp)
+{
+ int nthreads = thread_map__nr(counter->threads);
+ int ncpus = perf_evsel__nr_cpus(counter);
+ int cpu, thread;
+ static int header_printed;
+
+ if (counter->system_wide)
+ nthreads = 1;
+
+ if (!header_printed) {
+ printf("%3s %8s %15s %15s %15s %15s %s\n",
+ "CPU", "THREAD", "VAL", "ENA", "RUN", "TIME", "EVENT");
+ header_printed = 1;
+ }
+
+ for (thread = 0; thread < nthreads; thread++) {
+ for (cpu = 0; cpu < ncpus; cpu++) {
+ struct perf_counts_values *counts;
+
+ counts = perf_counts(counter->counts, cpu, thread);
+
+ printf("%3d %8d %15" PRIu64 " %15" PRIu64 " %15" PRIu64 " %15" PRIu64 " %s\n",
+ counter->cpus->map[cpu],
+ thread_map__pid(counter->threads, thread),
+ counts->val,
+ counts->ena,
+ counts->run,
+ tstamp,
+ perf_evsel__name(counter));
+ }
+ }
+}
+
static void process_stat(struct perf_evsel *counter, u64 tstamp)
{
if (scripting_ops && scripting_ops->process_stat)
scripting_ops->process_stat(&stat_config, counter, tstamp);
+ else
+ __process_stat(counter, tstamp);
}
static void process_stat_interval(u64 tstamp)
^ permalink raw reply related [flat|nested] 11+ messages in thread
* [tip:perf/core] perf script: Add stat-cpi.py script
2016-01-06 10:49 ` [PATCH 3/3] perf script: Add stat-cpi.py script Jiri Olsa
@ 2016-01-09 16:32 ` tip-bot for Jiri Olsa
0 siblings, 0 replies; 11+ messages in thread
From: tip-bot for Jiri Olsa @ 2016-01-09 16:32 UTC (permalink / raw)
To: linux-tip-commits
Cc: kan.liang, tglx, namhyung, jolsa, acme, mingo, a.p.zijlstra,
linux-kernel, dsahern, hpa
Commit-ID: b8a1962d17b4e3cfdd7b7dc9ebd94affbcb4c1c5
Gitweb: http://git.kernel.org/tip/b8a1962d17b4e3cfdd7b7dc9ebd94affbcb4c1c5
Author: Jiri Olsa <jolsa@kernel.org>
AuthorDate: Wed, 6 Jan 2016 11:49:57 +0100
Committer: Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Wed, 6 Jan 2016 20:11:16 -0300
perf script: Add stat-cpi.py script
Adding stat-cpi.py as an example of how to do stat scripting.
It computes the CPI metrics from cycles and instructions events.
The CPI is based performance metric showing the Cycles Per Instructions
ratio, which helps to identify cycles-hungry code.
Following stat record/report/script combinations could be used:
- get CPI for given workload
$ perf stat -e cycles,instructions record ls
SNIP
Performance counter stats for 'ls':
2,904,431 cycles
3,346,878 instructions # 1.15 insns per cycle
0.001782686 seconds time elapsed
$ perf script -s ./scripts/python/stat-cpi.py
0.001783: cpu -1, thread -1 -> cpi 0.867803 (2904431/3346878)
$ perf stat -e cycles,instructions record ls | perf script -s ./scripts/python/stat-cpi.py
SNIP
0.001730: cpu -1, thread -1 -> cpi 0.869026 (2928292/3369627)
- get CPI systemwide:
$ perf stat -e cycles,instructions -a -I 1000 record sleep 3
# time counts unit events
1.000158618 594,274,711 cycles (100.00%)
1.000158618 441,898,250 instructions
2.000350973 567,649,705 cycles (100.00%)
2.000350973 432,669,206 instructions
3.000559210 561,940,430 cycles (100.00%)
3.000559210 420,403,465 instructions
3.000670798 780,105 cycles (100.00%)
3.000670798 326,516 instructions
$ perf script -s ./scripts/python/stat-cpi.py
1.000159: cpu -1, thread -1 -> cpi 1.344823 (594274711/441898250)
2.000351: cpu -1, thread -1 -> cpi 1.311972 (567649705/432669206)
3.000559: cpu -1, thread -1 -> cpi 1.336669 (561940430/420403465)
3.000671: cpu -1, thread -1 -> cpi 2.389178 (780105/326516)
$ perf stat -e cycles,instructions -a -I 1000 record sleep 3 | perf script -s ./scripts/python/stat-cpi.py
1.000202: cpu -1, thread -1 -> cpi 1.035091 (940778881/908885530)
2.000392: cpu -1, thread -1 -> cpi 1.442600 (627493992/434974455)
3.000545: cpu -1, thread -1 -> cpi 1.353612 (741463930/547766890)
3.000622: cpu -1, thread -1 -> cpi 2.642110 (784083/296764)
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Tested-by: Kan Liang <kan.liang@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/1452077397-31958-4-git-send-email-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/scripts/python/stat-cpi.py | 77 +++++++++++++++++++++++++++++++++++
1 file changed, 77 insertions(+)
diff --git a/tools/perf/scripts/python/stat-cpi.py b/tools/perf/scripts/python/stat-cpi.py
new file mode 100644
index 0000000..8b60f34
--- /dev/null
+++ b/tools/perf/scripts/python/stat-cpi.py
@@ -0,0 +1,77 @@
+#!/usr/bin/env python
+
+data = {}
+times = []
+threads = []
+cpus = []
+
+def get_key(time, event, cpu, thread):
+ return "%d-%s-%d-%d" % (time, event, cpu, thread)
+
+def store_key(time, cpu, thread):
+ if (time not in times):
+ times.append(time)
+
+ if (cpu not in cpus):
+ cpus.append(cpu)
+
+ if (thread not in threads):
+ threads.append(thread)
+
+def store(time, event, cpu, thread, val, ena, run):
+ #print "event %s cpu %d, thread %d, time %d, val %d, ena %d, run %d" % \
+ # (event, cpu, thread, time, val, ena, run)
+
+ store_key(time, cpu, thread)
+ key = get_key(time, event, cpu, thread)
+ data[key] = [ val, ena, run]
+
+def get(time, event, cpu, thread):
+ key = get_key(time, event, cpu, thread)
+ return data[key][0]
+
+def stat__cycles_k(cpu, thread, time, val, ena, run):
+ store(time, "cycles", cpu, thread, val, ena, run);
+
+def stat__instructions_k(cpu, thread, time, val, ena, run):
+ store(time, "instructions", cpu, thread, val, ena, run);
+
+def stat__cycles_u(cpu, thread, time, val, ena, run):
+ store(time, "cycles", cpu, thread, val, ena, run);
+
+def stat__instructions_u(cpu, thread, time, val, ena, run):
+ store(time, "instructions", cpu, thread, val, ena, run);
+
+def stat__cycles(cpu, thread, time, val, ena, run):
+ store(time, "cycles", cpu, thread, val, ena, run);
+
+def stat__instructions(cpu, thread, time, val, ena, run):
+ store(time, "instructions", cpu, thread, val, ena, run);
+
+def stat__interval(time):
+ for cpu in cpus:
+ for thread in threads:
+ cyc = get(time, "cycles", cpu, thread)
+ ins = get(time, "instructions", cpu, thread)
+ cpi = 0
+
+ if ins != 0:
+ cpi = cyc/float(ins)
+
+ print "%15f: cpu %d, thread %d -> cpi %f (%d/%d)" % (time/(float(1000000000)), cpu, thread, cpi, cyc, ins)
+
+def trace_end():
+ pass
+# XXX trace_end callback could be used as an alternative place
+# to compute same values as in the script above:
+#
+# for time in times:
+# for cpu in cpus:
+# for thread in threads:
+# cyc = get(time, "cycles", cpu, thread)
+# ins = get(time, "instructions", cpu, thread)
+#
+# if ins != 0:
+# cpi = cyc/float(ins)
+#
+# print "time %.9f, cpu %d, thread %d -> cpi %f" % (time/(float(1000000000)), cpu, thread, cpi)
^ permalink raw reply related [flat|nested] 11+ messages in thread
end of thread, other threads:[~2016-01-09 16:32 UTC | newest]
Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2016-01-06 10:49 [PATCHv9 0/3] perf stat: Add scripting support Jiri Olsa
2016-01-06 10:49 ` [PATCH 1/3] perf tools: Fix cpu conversion in cpu_map__from_entries Jiri Olsa
2016-01-09 16:31 ` [tip:perf/core] perf cpumap: " tip-bot for Jiri Olsa
2016-01-06 10:49 ` [PATCH 2/3] perf script: Display stat events by default Jiri Olsa
2016-01-09 16:31 ` [tip:perf/core] " tip-bot for Jiri Olsa
2016-01-06 10:49 ` [PATCH 3/3] perf script: Add stat-cpi.py script Jiri Olsa
2016-01-09 16:32 ` [tip:perf/core] " tip-bot for Jiri Olsa
2016-01-06 14:18 ` [PATCHv9 0/3] perf stat: Add scripting support Arnaldo Carvalho de Melo
2016-01-06 14:38 ` Jiri Olsa
2016-01-06 15:05 ` Arnaldo Carvalho de Melo
2016-01-06 15:39 ` Jiri Olsa
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.