From 359d5106a2ff4ffa2ba129ec8f54743c341dabfc Mon Sep 17 00:00:00 2001 From: Koki Sanagi Date: Mon, 23 Aug 2010 18:47:09 +0900 Subject: perf: Add a script to show packets processing Add a perf script which shows packets processing and processed time. It helps us to investigate networking or network devices. If you want to use it, install perf and record perf.data like following. If you set script, perf gathers records until it ends. If not, you must Ctrl-C to stop recording. And if you want a report from record, If you use some options, you can limit the output. Option is below. tx: show only tx packets processing rx: show only rx packets processing dev=: show processing on this device debug: work with debug mode. It shows buffer status. For example, if you want to show received packets processing associated with eth4, 106133.171439sec cpu=0 irq_entry(+0.000msec irq=24:eth4) | softirq_entry(+0.006msec) | |---netif_receive_skb(+0.010msec skb=f2d15900 len=100) | | | skb_copy_datagram_iovec(+0.039msec 10291::10291) | napi_poll_exit(+0.022msec eth4) This perf script helps us to analyze the processing time of a transmit/receive sequence. Signed-off-by: Koki Sanagi Acked-by: David S. Miller Cc: Neil Horman Cc: Mathieu Desnoyers Cc: Kaneshige Kenji Cc: Izumo Taku Cc: Kosaki Motohiro Cc: Lai Jiangshan Cc: Scott Mcmillan Cc: Steven Rostedt Cc: Eric Dumazet Cc: Tom Zanussi LKML-Reference: <4C72439D.3040001@jp.fujitsu.com> Signed-off-by: Frederic Weisbecker --- tools/perf/scripts/python/bin/netdev-times-record | 8 ++++++++ tools/perf/scripts/python/bin/netdev-times-report | 5 +++++ 2 files changed, 13 insertions(+) create mode 100644 tools/perf/scripts/python/bin/netdev-times-record create mode 100644 tools/perf/scripts/python/bin/netdev-times-report (limited to 'tools/perf/scripts/python/bin') diff --git a/tools/perf/scripts/python/bin/netdev-times-record b/tools/perf/scripts/python/bin/netdev-times-record new file mode 100644 index 000000000000..d931a828126b --- /dev/null +++ b/tools/perf/scripts/python/bin/netdev-times-record @@ -0,0 +1,8 @@ +#!/bin/bash +perf record -a -e net:net_dev_xmit -e net:net_dev_queue \ + -e net:netif_receive_skb -e net:netif_rx \ + -e skb:consume_skb -e skb:kfree_skb \ + -e skb:skb_copy_datagram_iovec -e napi:napi_poll \ + -e irq:irq_handler_entry -e irq:irq_handler_exit \ + -e irq:softirq_entry -e irq:softirq_exit \ + -e irq:softirq_raise $@ diff --git a/tools/perf/scripts/python/bin/netdev-times-report b/tools/perf/scripts/python/bin/netdev-times-report new file mode 100644 index 000000000000..c3d0a638123d --- /dev/null +++ b/tools/perf/scripts/python/bin/netdev-times-report @@ -0,0 +1,5 @@ +#!/bin/bash +# description: display a process of packet and processing time +# args: [tx] [rx] [dev=] [debug] + +perf trace -s ~/libexec/perf-core/scripts/python/netdev-times.py $@ -- cgit v1.2.3 From 44e668c6faa9a6c477a32788e7e88f0754c54a4e Mon Sep 17 00:00:00 2001 From: Ben Hutchings Date: Sun, 10 Oct 2010 16:10:03 +0100 Subject: perf trace: Use $PERF_EXEC_PATH in canned report scripts Set $PERF_EXEC_PATH before starting the record and report scripts, and make them use it where necessary. Cc: Ingo Molnar Cc: Paul Mackerras Cc: Peter Zijlstra LKML-Reference: <1286723403.2955.205.camel@localhost> Signed-off-by: Ben Hutchings Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 6 +++--- tools/perf/scripts/perl/bin/failed-syscalls-report | 2 +- tools/perf/scripts/perl/bin/rw-by-file-report | 2 +- tools/perf/scripts/perl/bin/rw-by-pid-report | 2 +- tools/perf/scripts/perl/bin/rwtop-report | 2 +- tools/perf/scripts/perl/bin/wakeup-latency-report | 2 +- tools/perf/scripts/perl/bin/workqueue-stats-report | 2 +- tools/perf/scripts/python/bin/failed-syscalls-by-pid-report | 2 +- tools/perf/scripts/python/bin/netdev-times-report | 2 +- tools/perf/scripts/python/bin/sched-migration-report | 2 +- tools/perf/scripts/python/bin/sctop-report | 2 +- tools/perf/scripts/python/bin/syscall-counts-by-pid-report | 2 +- tools/perf/scripts/python/bin/syscall-counts-report | 2 +- 13 files changed, 15 insertions(+), 15 deletions(-) (limited to 'tools/perf/scripts/python/bin') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 40a6a2992d15..3ea62199ffe1 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -46,9 +46,6 @@ static struct scripting_ops *scripting_ops; static void setup_scripting(void) { - /* make sure PERF_EXEC_PATH is set for scripts */ - perf_set_argv_exec_path(perf_exec_path()); - setup_perl_scripting(); setup_python_scripting(); @@ -593,6 +590,9 @@ int cmd_trace(int argc, const char **argv, const char *prefix __used) suffix = REPORT_SUFFIX; } + /* make sure PERF_EXEC_PATH is set for scripts */ + perf_set_argv_exec_path(perf_exec_path()); + if (!suffix && argc >= 2 && strncmp(argv[1], "-", strlen("-")) != 0) { char *record_script_path, *report_script_path; int live_pipe[2]; diff --git a/tools/perf/scripts/perl/bin/failed-syscalls-report b/tools/perf/scripts/perl/bin/failed-syscalls-report index e3a5e55d54ff..4028d92dc4ae 100644 --- a/tools/perf/scripts/perl/bin/failed-syscalls-report +++ b/tools/perf/scripts/perl/bin/failed-syscalls-report @@ -7,4 +7,4 @@ if [ $# -gt 0 ] ; then shift fi fi -perf trace $@ -s ~/libexec/perf-core/scripts/perl/failed-syscalls.pl $comm +perf trace $@ -s "$PERF_EXEC_PATH"/scripts/perl/failed-syscalls.pl $comm diff --git a/tools/perf/scripts/perl/bin/rw-by-file-report b/tools/perf/scripts/perl/bin/rw-by-file-report index d83070b7eeb5..ba25f4d41fb0 100644 --- a/tools/perf/scripts/perl/bin/rw-by-file-report +++ b/tools/perf/scripts/perl/bin/rw-by-file-report @@ -7,7 +7,7 @@ if [ $# -lt 1 ] ; then fi comm=$1 shift -perf trace $@ -s ~/libexec/perf-core/scripts/perl/rw-by-file.pl $comm +perf trace $@ -s "$PERF_EXEC_PATH"/scripts/perl/rw-by-file.pl $comm diff --git a/tools/perf/scripts/perl/bin/rw-by-pid-report b/tools/perf/scripts/perl/bin/rw-by-pid-report index 7ef46983f62f..641a3f5d085c 100644 --- a/tools/perf/scripts/perl/bin/rw-by-pid-report +++ b/tools/perf/scripts/perl/bin/rw-by-pid-report @@ -1,6 +1,6 @@ #!/bin/bash # description: system-wide r/w activity -perf trace $@ -s ~/libexec/perf-core/scripts/perl/rw-by-pid.pl +perf trace $@ -s "$PERF_EXEC_PATH"/scripts/perl/rw-by-pid.pl diff --git a/tools/perf/scripts/perl/bin/rwtop-report b/tools/perf/scripts/perl/bin/rwtop-report index 93e698cd3f38..4918dba77021 100644 --- a/tools/perf/scripts/perl/bin/rwtop-report +++ b/tools/perf/scripts/perl/bin/rwtop-report @@ -17,7 +17,7 @@ if [ "$n_args" -gt 0 ] ; then interval=$1 shift fi -perf trace $@ -s ~/libexec/perf-core/scripts/perl/rwtop.pl $interval +perf trace $@ -s "$PERF_EXEC_PATH"/scripts/perl/rwtop.pl $interval diff --git a/tools/perf/scripts/perl/bin/wakeup-latency-report b/tools/perf/scripts/perl/bin/wakeup-latency-report index a0d898f9ca1d..49052ebcb632 100644 --- a/tools/perf/scripts/perl/bin/wakeup-latency-report +++ b/tools/perf/scripts/perl/bin/wakeup-latency-report @@ -1,6 +1,6 @@ #!/bin/bash # description: system-wide min/max/avg wakeup latency -perf trace $@ -s ~/libexec/perf-core/scripts/perl/wakeup-latency.pl +perf trace $@ -s "$PERF_EXEC_PATH"/scripts/perl/wakeup-latency.pl diff --git a/tools/perf/scripts/perl/bin/workqueue-stats-report b/tools/perf/scripts/perl/bin/workqueue-stats-report index 35081132ef97..df0c65f4ca93 100644 --- a/tools/perf/scripts/perl/bin/workqueue-stats-report +++ b/tools/perf/scripts/perl/bin/workqueue-stats-report @@ -1,6 +1,6 @@ #!/bin/bash # description: workqueue stats (ins/exe/create/destroy) -perf trace $@ -s ~/libexec/perf-core/scripts/perl/workqueue-stats.pl +perf trace $@ -s "$PERF_EXEC_PATH"/scripts/perl/workqueue-stats.pl diff --git a/tools/perf/scripts/python/bin/failed-syscalls-by-pid-report b/tools/perf/scripts/python/bin/failed-syscalls-by-pid-report index 30293545fcc2..03587021463d 100644 --- a/tools/perf/scripts/python/bin/failed-syscalls-by-pid-report +++ b/tools/perf/scripts/python/bin/failed-syscalls-by-pid-report @@ -7,4 +7,4 @@ if [ $# -gt 0 ] ; then shift fi fi -perf trace $@ -s ~/libexec/perf-core/scripts/python/failed-syscalls-by-pid.py $comm +perf trace $@ -s "$PERF_EXEC_PATH"/scripts/python/failed-syscalls-by-pid.py $comm diff --git a/tools/perf/scripts/python/bin/netdev-times-report b/tools/perf/scripts/python/bin/netdev-times-report index c3d0a638123d..4ad361b31249 100644 --- a/tools/perf/scripts/python/bin/netdev-times-report +++ b/tools/perf/scripts/python/bin/netdev-times-report @@ -2,4 +2,4 @@ # description: display a process of packet and processing time # args: [tx] [rx] [dev=] [debug] -perf trace -s ~/libexec/perf-core/scripts/python/netdev-times.py $@ +perf trace -s "$PERF_EXEC_PATH"/scripts/python/netdev-times.py $@ diff --git a/tools/perf/scripts/python/bin/sched-migration-report b/tools/perf/scripts/python/bin/sched-migration-report index 61d05f72e443..df1791f07c24 100644 --- a/tools/perf/scripts/python/bin/sched-migration-report +++ b/tools/perf/scripts/python/bin/sched-migration-report @@ -1,3 +1,3 @@ #!/bin/bash # description: sched migration overview -perf trace $@ -s ~/libexec/perf-core/scripts/python/sched-migration.py +perf trace $@ -s "$PERF_EXEC_PATH"/scripts/python/sched-migration.py diff --git a/tools/perf/scripts/python/bin/sctop-report b/tools/perf/scripts/python/bin/sctop-report index b01c842ae7b4..36b409c05e50 100644 --- a/tools/perf/scripts/python/bin/sctop-report +++ b/tools/perf/scripts/python/bin/sctop-report @@ -21,4 +21,4 @@ elif [ "$n_args" -gt 0 ] ; then interval=$1 shift fi -perf trace $@ -s ~/libexec/perf-core/scripts/python/sctop.py $comm $interval +perf trace $@ -s "$PERF_EXEC_PATH"/scripts/python/sctop.py $comm $interval diff --git a/tools/perf/scripts/python/bin/syscall-counts-by-pid-report b/tools/perf/scripts/python/bin/syscall-counts-by-pid-report index 9e9d8ddd72ce..4eb88c9fc83c 100644 --- a/tools/perf/scripts/python/bin/syscall-counts-by-pid-report +++ b/tools/perf/scripts/python/bin/syscall-counts-by-pid-report @@ -7,4 +7,4 @@ if [ $# -gt 0 ] ; then shift fi fi -perf trace $@ -s ~/libexec/perf-core/scripts/python/syscall-counts-by-pid.py $comm +perf trace $@ -s "$PERF_EXEC_PATH"/scripts/python/syscall-counts-by-pid.py $comm diff --git a/tools/perf/scripts/python/bin/syscall-counts-report b/tools/perf/scripts/python/bin/syscall-counts-report index dc076b618796..cb2f9c5cf17e 100644 --- a/tools/perf/scripts/python/bin/syscall-counts-report +++ b/tools/perf/scripts/python/bin/syscall-counts-report @@ -7,4 +7,4 @@ if [ $# -gt 0 ] ; then shift fi fi -perf trace $@ -s ~/libexec/perf-core/scripts/python/syscall-counts.py $comm +perf trace $@ -s "$PERF_EXEC_PATH"/scripts/python/syscall-counts.py $comm -- cgit v1.2.3 From 00204c3396469f407bac56e1475ea16e4a279b13 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Tue, 26 Oct 2010 17:07:33 -0200 Subject: perf python scripting: Add futex-contention script The equivalent to this SystemTAP script: http://sourceware.org/systemtap/wiki/WSFutexContention [root@doppio ~]# perf trace futex-contention Press control+C to stop and show the summary ^Cnpviewer.bin[15242] lock 7f0a8be19104 contended 29 times, 72806 avg ns npviewer.bin[15242] lock 7f0a8be19130 contended 2 times, 1355 avg ns synergyc[17245] lock f127f4 contended 1 times, 1830569 avg ns firefox[15116] lock 7f2b7238af0c contended 168 times, 1230390 avg ns synergyc[17245] lock f2fc20 contended 1 times, 33149 avg ns npviewer.bin[15255] lock 7f0a8be19074 contended 155 times, 73047 avg ns npviewer.bin[15255] lock 7f0a8be190a0 contended 127 times, 7088 avg ns synergyc[17247] lock f12854 contended 1 times, 46741 avg ns synergyc[17245] lock f12610 contended 1 times, 7358 avg ns [root@doppio ~]# Cc: Frederic Weisbecker Cc: Mike Galbraith Cc: Paul Mackerras Cc: Peter Zijlstra Cc: Stephane Eranian Cc: Tom Zanussi LKML-Reference: Signed-off-by: Arnaldo Carvalho de Melo --- .../python/Perf-Trace-Util/lib/Perf/Trace/Util.py | 18 ++++++++ .../scripts/python/bin/futex-contention-record | 2 + .../scripts/python/bin/futex-contention-report | 4 ++ tools/perf/scripts/python/futex-contention.py | 50 ++++++++++++++++++++++ 4 files changed, 74 insertions(+) create mode 100644 tools/perf/scripts/python/bin/futex-contention-record create mode 100644 tools/perf/scripts/python/bin/futex-contention-report create mode 100644 tools/perf/scripts/python/futex-contention.py (limited to 'tools/perf/scripts/python/bin') diff --git a/tools/perf/scripts/python/Perf-Trace-Util/lib/Perf/Trace/Util.py b/tools/perf/scripts/python/Perf-Trace-Util/lib/Perf/Trace/Util.py index 99ff1b7a0d2c..13cc02b5893a 100644 --- a/tools/perf/scripts/python/Perf-Trace-Util/lib/Perf/Trace/Util.py +++ b/tools/perf/scripts/python/Perf-Trace-Util/lib/Perf/Trace/Util.py @@ -8,6 +8,12 @@ import errno, os +FUTEX_WAIT = 0 +FUTEX_WAKE = 1 +FUTEX_PRIVATE_FLAG = 128 +FUTEX_CLOCK_REALTIME = 256 +FUTEX_CMD_MASK = ~(FUTEX_PRIVATE_FLAG | FUTEX_CLOCK_REALTIME) + NSECS_PER_SEC = 1000000000 def avg(total, n): @@ -26,6 +32,18 @@ def nsecs_str(nsecs): str = "%5u.%09u" % (nsecs_secs(nsecs), nsecs_nsecs(nsecs)), return str +def add_stats(dict, key, value): + if not dict.has_key(key): + dict[key] = (value, value, value, 1) + else: + min, max, avg, count = dict[key] + if value < min: + min = value + if value > max: + max = value + avg = (avg + value) / 2 + dict[key] = (min, max, avg, count + 1) + def clear_term(): print("\x1b[H\x1b[2J") diff --git a/tools/perf/scripts/python/bin/futex-contention-record b/tools/perf/scripts/python/bin/futex-contention-record new file mode 100644 index 000000000000..5ecbb433caf4 --- /dev/null +++ b/tools/perf/scripts/python/bin/futex-contention-record @@ -0,0 +1,2 @@ +#!/bin/bash +perf record -a -e syscalls:sys_enter_futex -e syscalls:sys_exit_futex $@ diff --git a/tools/perf/scripts/python/bin/futex-contention-report b/tools/perf/scripts/python/bin/futex-contention-report new file mode 100644 index 000000000000..c8268138fb7e --- /dev/null +++ b/tools/perf/scripts/python/bin/futex-contention-report @@ -0,0 +1,4 @@ +#!/bin/bash +# description: futext contention measurement + +perf trace $@ -s "$PERF_EXEC_PATH"/scripts/python/futex-contention.py diff --git a/tools/perf/scripts/python/futex-contention.py b/tools/perf/scripts/python/futex-contention.py new file mode 100644 index 000000000000..11e70a388d41 --- /dev/null +++ b/tools/perf/scripts/python/futex-contention.py @@ -0,0 +1,50 @@ +# futex contention +# (c) 2010, Arnaldo Carvalho de Melo +# Licensed under the terms of the GNU GPL License version 2 +# +# Translation of: +# +# http://sourceware.org/systemtap/wiki/WSFutexContention +# +# to perf python scripting. +# +# Measures futex contention + +import os, sys +sys.path.append(os.environ['PERF_EXEC_PATH'] + '/scripts/python/Perf-Trace-Util/lib/Perf/Trace') +from Util import * + +process_names = {} +thread_thislock = {} +thread_blocktime = {} + +lock_waits = {} # long-lived stats on (tid,lock) blockage elapsed time +process_names = {} # long-lived pid-to-execname mapping + +def syscalls__sys_enter_futex(event, ctxt, cpu, s, ns, tid, comm, + nr, uaddr, op, val, utime, uaddr2, val3): + cmd = op & FUTEX_CMD_MASK + if cmd != FUTEX_WAIT: + return # we don't care about originators of WAKE events + + process_names[tid] = comm + thread_thislock[tid] = uaddr + thread_blocktime[tid] = nsecs(s, ns) + +def syscalls__sys_exit_futex(event, ctxt, cpu, s, ns, tid, comm, + nr, ret): + if thread_blocktime.has_key(tid): + elapsed = nsecs(s, ns) - thread_blocktime[tid] + add_stats(lock_waits, (tid, thread_thislock[tid]), elapsed) + del thread_blocktime[tid] + del thread_thislock[tid] + +def trace_begin(): + print "Press control+C to stop and show the summary" + +def trace_end(): + for (tid, lock) in lock_waits: + min, max, avg, count = lock_waits[tid, lock] + print "%s[%d] lock %x contended %d times, %d avg ns" % \ + (process_names[tid], tid, lock, count, avg) + -- cgit v1.2.3