From ff90b2974f841b92434cb46d89c39f08d01cc966 Mon Sep 17 00:00:00 2001 From: William Cohen Date: Wed, 28 Jan 2009 16:03:01 -0500 Subject: Add the polling timeout example and update the catalog. --- .../systemtap.examples/profiling/timeout.meta | 13 +++ testsuite/systemtap.examples/profiling/timeout.stp | 102 +++++++++++++++++++++ 2 files changed, 115 insertions(+) create mode 100644 testsuite/systemtap.examples/profiling/timeout.meta create mode 100644 testsuite/systemtap.examples/profiling/timeout.stp (limited to 'testsuite/systemtap.examples/profiling') diff --git a/testsuite/systemtap.examples/profiling/timeout.meta b/testsuite/systemtap.examples/profiling/timeout.meta new file mode 100644 index 00000000..aa683c0a --- /dev/null +++ b/testsuite/systemtap.examples/profiling/timeout.meta @@ -0,0 +1,13 @@ +title: Show Processes Doing Polling Operations +name: timeout.stp +version: 1.0 +author: Uli Drepper and William Cohen +keywords: profiling +subsystem: kernel +status: production +exit: user-controlled +output: sorted-list +scope: system-wide +description: The timeout.stp script is based on a blog entry (http://udrepper.livejournal.com/19041.html) mentioning a need for a tool to help developers find applications that are polling. The timeout.stp script monitors systemcall used for polling and records the systemcalls that timed out rather than returned because some action occurred. The script updates the screen once a second with the top twenty processes. +test_check: stap -p4 timeout.stp +test_installcheck: stap timeout.stp -c "sleep 1" diff --git a/testsuite/systemtap.examples/profiling/timeout.stp b/testsuite/systemtap.examples/profiling/timeout.stp new file mode 100644 index 00000000..48d6d21d --- /dev/null +++ b/testsuite/systemtap.examples/profiling/timeout.stp @@ -0,0 +1,102 @@ +#! /usr/bin/env stap +# Copyright (C) 2009 Red Hat, Inc. +# Written by Ulrich Drepper +# Modified by William Cohen + +global process, timeout_count, to +global poll_timeout, epoll_timeout, select_timeout, itimer_timeout +global nanosleep_timeout, futex_timeout, signal_timeout + +probe syscall.poll, syscall.epoll_wait { + if (timeout) to[pid()]=timeout +} + +probe syscall.poll.return { + p = pid() + if ($return == 0 && to[p] > 0 ) { + poll_timeout[p]++ + timeout_count[p]++ + process[p] = execname() + delete to[p] + } +} + +probe syscall.epoll_wait.return { + p = pid() + if ($return == 0 && to[p] > 0 ) { + epoll_timeout[p]++ + timeout_count[p]++ + process[p] = execname() + delete to[p] + } +} + +probe syscall.select.return { + if ($return == 0) { + p = pid() + select_timeout[p]++ + timeout_count[p]++ + process[p] = execname() + } +} + +probe syscall.futex.return { + if (errno_str($return) == "ETIMEDOUT") { + p = pid() + futex_timeout[p]++ + timeout_count[p]++ + process[p] = execname() + } +} + +probe syscall.nanosleep.return { + if ($return == 0) { + p = pid() + nanosleep_timeout[p]++ + timeout_count[p]++ + process[p] = execname() + } +} + +probe kernel.function("it_real_fn") { + p = pid() + itimer_timeout[p]++ + timeout_count[p]++ + process[p] = execname() +} + +probe syscall.rt_sigtimedwait.return { + if (errno_str($return) == "EAGAIN") { + p = pid() + signal_timeout[p]++ + timeout_count[p]++ + process[p] = execname() + } +} + +probe syscall.exit { + p = pid() + if (p in process) { + delete process[p] + delete timeout_count[p] + delete poll_timeout[p] + delete epoll_timeout[p] + delete select_timeout[p] + delete itimer_timeout[p] + delete futex_timeout[p] + delete nanosleep_timeout[p] + delete signal_timeout[p] + } +} + +probe timer.s(1) { + printf("\033[2J\033[1;1H") /* clear screen */ + printf (" uid | poll select epoll itimer futex nanosle signal| process\n") + foreach (p in timeout_count- limit 20) { + printf ("%5d |%7d %7d %7d %7d %7d %7d %7d| %-.38s\n", p, + poll_timeout[p], select_timeout[p], + epoll_timeout[p], itimer_timeout[p], + futex_timeout[p], nanosleep_timeout[p], + signal_timeout[p], process[p]) + } +} -- cgit From 1bf72dfea404434f954214298367817d5c591903 Mon Sep 17 00:00:00 2001 From: William Cohen Date: Mon, 2 Feb 2009 14:21:25 -0500 Subject: Revised topsys.stp and moved to the testsuite/systemtap.examples directory. --- testsuite/systemtap.examples/profiling/topsys.meta | 13 ++++++++++++ testsuite/systemtap.examples/profiling/topsys.stp | 24 ++++++++++++++++++++++ 2 files changed, 37 insertions(+) create mode 100644 testsuite/systemtap.examples/profiling/topsys.meta create mode 100644 testsuite/systemtap.examples/profiling/topsys.stp (limited to 'testsuite/systemtap.examples/profiling') diff --git a/testsuite/systemtap.examples/profiling/topsys.meta b/testsuite/systemtap.examples/profiling/topsys.meta new file mode 100644 index 00000000..3642713d --- /dev/null +++ b/testsuite/systemtap.examples/profiling/topsys.meta @@ -0,0 +1,13 @@ +title: Show Processes Doing Polling Operations +name: topsys.stp +version: 1.0 +author: anonymous +keywords: profiling +subsystem: kernel syscalls +status: production +exit: user-controlled +output: sorted-list +scope: system-wide +description: The topsys.stp script lists out the top twenty systemcalls for the previous 5 seconds. The output is sorted from most frequent to least frequent. +test_check: stap -p4 topsys.stp +test_installcheck: stap topsys.stp -c "sleep 1" diff --git a/testsuite/systemtap.examples/profiling/topsys.stp b/testsuite/systemtap.examples/profiling/topsys.stp new file mode 100644 index 00000000..34cf826c --- /dev/null +++ b/testsuite/systemtap.examples/profiling/topsys.stp @@ -0,0 +1,24 @@ +#! /usr/bin/env stap +# +# This script continuously lists the top 20 systemcalls in the interval +# 5 seconds +# + +global syscalls_count + +probe syscall.* { + syscalls_count[name]++ +} + +function print_systop () { + printf ("%25s %10s\n", "SYSCALL", "COUNT") + foreach (syscall in syscalls_count- limit 20) { + printf("%25s %10d\n", syscall, syscalls_count[syscall]) + } + delete syscalls_count +} + +probe timer.s(5) { + print_systop () + printf("--------------------------------------------------------------\n") +} -- cgit From 3a66ad568254853a195035bd8deca3d38dde27d2 Mon Sep 17 00:00:00 2001 From: Ananth N Mavinakayanahalli Date: Wed, 11 Feb 2009 11:21:46 +0530 Subject: Probe only calls and not inlines in functioncallcount.stp --- testsuite/systemtap.examples/profiling/functioncallcount.stp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'testsuite/systemtap.examples/profiling') diff --git a/testsuite/systemtap.examples/profiling/functioncallcount.stp b/testsuite/systemtap.examples/profiling/functioncallcount.stp index 9e9ec3fd..31eaee70 100755 --- a/testsuite/systemtap.examples/profiling/functioncallcount.stp +++ b/testsuite/systemtap.examples/profiling/functioncallcount.stp @@ -4,7 +4,7 @@ # # stap functioncallcount.stp "*@mm/*.c" -probe kernel.function(@1) { # probe functions listed on commandline +probe kernel.function(@1).call { # probe functions listed on commandline called[probefunc()] <<< 1 # add a count efficiently } -- cgit From bbc46bf643491173b9086907cf0820b3fd2c1fe3 Mon Sep 17 00:00:00 2001 From: Tim Moore Date: Mon, 2 Feb 2009 15:58:53 +0100 Subject: Use kernel stack backtrace support when available Define new functions that use the kernel support to do a backtrace of other tasks than current. --- testsuite/systemtap.examples/profiling/latencytap.stp | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) (limited to 'testsuite/systemtap.examples/profiling') diff --git a/testsuite/systemtap.examples/profiling/latencytap.stp b/testsuite/systemtap.examples/profiling/latencytap.stp index 96944858..28956129 100644 --- a/testsuite/systemtap.examples/profiling/latencytap.stp +++ b/testsuite/systemtap.examples/profiling/latencytap.stp @@ -22,8 +22,8 @@ function _get_sleep_time:long(rq_param:long, p_param:long) # Get the backtrace from an arbitrary task function task_backtrace:string (task:long) %{ - _stp_stack_snprint(THIS->__retvalue, MAXSTRINGLEN, - task_pt_regs((struct task_struct *)THIS->task), 0, 0, MAXTRACE); + _stp_stack_snprint_tsk(THIS->__retvalue, MAXSTRINGLEN, + (struct task_struct *)THIS->task, 0, MAXTRACE); %} probe kernel.function("enqueue_task_fair") { @@ -41,6 +41,9 @@ global pid_sleep probe timer.ms(1000) { foreach ([pid, backtrace] in sleep_time) { pid_sleep[pid] += sleep_time[pid, backtrace] + printf("%s %d:\n", process_names[pid], pid) + print_stack(backtrace) + printf("\n") } foreach ([pid+] in pid_sleep) { printf("%s %d %d\n", process_names[pid], @max(sleep_agg[pid]) / 1000000, @avg(sleep_agg[pid]) / 1000000) -- cgit