diff options
Diffstat (limited to 'testsuite/systemtap.examples')
| -rw-r--r-- | testsuite/systemtap.examples/index.html | 3 | ||||
| -rw-r--r-- | testsuite/systemtap.examples/index.txt | 10 | ||||
| -rw-r--r-- | testsuite/systemtap.examples/keyword-index.html | 12 | ||||
| -rw-r--r-- | testsuite/systemtap.examples/keyword-index.txt | 40 | ||||
| -rw-r--r-- | testsuite/systemtap.examples/process/schedtimes.meta | 13 | ||||
| -rwxr-xr-x | testsuite/systemtap.examples/process/schedtimes.stp | 154 |
6 files changed, 232 insertions, 0 deletions
diff --git a/testsuite/systemtap.examples/index.html b/testsuite/systemtap.examples/index.html index 0df681ac..e5673138 100644 --- a/testsuite/systemtap.examples/index.html +++ b/testsuite/systemtap.examples/index.html @@ -112,6 +112,9 @@ keywords: <a href="keyword-index.html#SYSCALL">SYSCALL</a> <a href="keyword-inde <li><a href="process/pf2.stp">process/pf2.stp</a> - Profile kernel functions<br> keywords: <a href="keyword-index.html#PROFILING">PROFILING</a> <br> <p>The pf2.stp script sets up time-based sampling. Every five seconds it prints out a sorted list with the top ten kernel functions with samples.</p></li> +<li><a href="process/schedtimes.stp">process/schedtimes.stp</a> - Track Time Processes Spend in Various States using Tracepoints<br> +keywords: <a href="keyword-index.html#PROCESS">PROCESS</a> <a href="keyword-index.html#SCHEDULER">SCHEDULER</a> <a href="keyword-index.html#TIME">TIME</a> <a href="keyword-index.html#TRACEPOINT">TRACEPOINT</a> <br> +<p>The schedtimes.stp script instruments the scheduler to track the amount of time that each process spends running, sleeping, queued, and waiting for io. On exit the script prints out the accumulated time for each state of processes observed. Optionally, this script can be used with the '-c' or '-x' options to focus on a specific PID.</p></li> <li><a href="process/sig_by_pid.stp">process/sig_by_pid.stp</a> - Signal Counts by Process ID<br> keywords: <a href="keyword-index.html#SIGNALS">SIGNALS</a> <br> <p>Print signal counts by process ID in descending order.</p></li> diff --git a/testsuite/systemtap.examples/index.txt b/testsuite/systemtap.examples/index.txt index fa344933..4eef904c 100644 --- a/testsuite/systemtap.examples/index.txt +++ b/testsuite/systemtap.examples/index.txt @@ -224,6 +224,16 @@ keywords: profiling samples. +process/schedtimes.stp - Track Time Processes Spend in Various States using Tracepoints +keywords: process scheduler time tracepoint + + The schedtimes.stp script instruments the scheduler to track the + amount of time that each process spends running, sleeping, queued, + and waiting for io. On exit the script prints out the accumulated + time for each state of processes observed. Optionally, this script + can be used with the '-c' or '-x' options to focus on a specific PID. + + process/sig_by_pid.stp - Signal Counts by Process ID keywords: signals diff --git a/testsuite/systemtap.examples/keyword-index.html b/testsuite/systemtap.examples/keyword-index.html index 7edbec21..b7f52246 100644 --- a/testsuite/systemtap.examples/keyword-index.html +++ b/testsuite/systemtap.examples/keyword-index.html @@ -189,6 +189,9 @@ keywords: <a href="keyword-index.html#NETWORK">NETWORK</a> <a href="keyword-inde <li><a href="process/errsnoop.stp">process/errsnoop.stp</a> - tabulate system call errors<br> keywords: <a href="keyword-index.html#PROCESS">PROCESS</a> <a href="keyword-index.html#SYSCALL">SYSCALL</a> <br> <p>The script prints a periodic tabular report about failing system calls, by process and by syscall failure. The first optional argument specifies the reporting interval (in seconds, default 5); the second optional argument gives a screen height (number of lines in the report, default 20).</p></li> +<li><a href="process/schedtimes.stp">process/schedtimes.stp</a> - Track Time Processes Spend in Various States using Tracepoints<br> +keywords: <a href="keyword-index.html#PROCESS">PROCESS</a> <a href="keyword-index.html#SCHEDULER">SCHEDULER</a> <a href="keyword-index.html#TIME">TIME</a> <a href="keyword-index.html#TRACEPOINT">TRACEPOINT</a> <br> +<p>The schedtimes.stp script instruments the scheduler to track the amount of time that each process spends running, sleeping, queued, and waiting for io. On exit the script prints out the accumulated time for each state of processes observed. Optionally, this script can be used with the '-c' or '-x' options to focus on a specific PID.</p></li> </ul> <h3><a name="PROFILING">PROFILING</a></h3> <ul> @@ -219,6 +222,9 @@ keywords: <a href="keyword-index.html#SYSCALL">SYSCALL</a> <a href="keyword-inde </ul> <h3><a name="SCHEDULER">SCHEDULER</a></h3> <ul> +<li><a href="process/schedtimes.stp">process/schedtimes.stp</a> - Track Time Processes Spend in Various States using Tracepoints<br> +keywords: <a href="keyword-index.html#PROCESS">PROCESS</a> <a href="keyword-index.html#SCHEDULER">SCHEDULER</a> <a href="keyword-index.html#TIME">TIME</a> <a href="keyword-index.html#TRACEPOINT">TRACEPOINT</a> <br> +<p>The schedtimes.stp script instruments the scheduler to track the amount of time that each process spends running, sleeping, queued, and waiting for io. On exit the script prints out the accumulated time for each state of processes observed. Optionally, this script can be used with the '-c' or '-x' options to focus on a specific PID.</p></li> <li><a href="process/sleepingBeauties.stp">process/sleepingBeauties.stp</a> - Generating Backtraces of Threads Waiting for IO Operations<br> keywords: <a href="keyword-index.html#IO">IO</a> <a href="keyword-index.html#SCHEDULER">SCHEDULER</a> <a href="keyword-index.html#BACKTRACE">BACKTRACE</a> <br> <p>The script monitors the time that threads spend waiting for IO operations (in "D" state) in the wait_for_completion function. If a thread spends over 10ms, its name and backtrace is printed, and later so is the total delay.</p></li> @@ -294,6 +300,9 @@ keywords: <a href="keyword-index.html#NETWORK">NETWORK</a> <a href="keyword-inde <li><a href="io/iotime.stp">io/iotime.stp</a> - Trace Time Spent in Read and Write for Files <br> keywords: <a href="keyword-index.html#SYSCALL">SYSCALL</a> <a href="keyword-index.html#READ">READ</a> <a href="keyword-index.html#WRITE">WRITE</a> <a href="keyword-index.html#TIME">TIME</a> <a href="keyword-index.html#IO">IO</a> <br> <p>The script watches each open, close, read, and write syscalls on the system. For each file the scripts observes opened it accumulates the amount of wall clock time spend in read and write operations and the number of bytes read and written. When a file is closed the script prints out a pair of lines for the file. Both lines begin with a timestamp in microseconds, the PID number, and the executable name in parenthesese. The first line with the "access" keyword lists the file name, the attempted number of bytes for the read and write operations. The second line with the "iotime" keyword list the file name and the number of microseconds accumulated in the read and write syscalls.</p></li> +<li><a href="process/schedtimes.stp">process/schedtimes.stp</a> - Track Time Processes Spend in Various States using Tracepoints<br> +keywords: <a href="keyword-index.html#PROCESS">PROCESS</a> <a href="keyword-index.html#SCHEDULER">SCHEDULER</a> <a href="keyword-index.html#TIME">TIME</a> <a href="keyword-index.html#TRACEPOINT">TRACEPOINT</a> <br> +<p>The schedtimes.stp script instruments the scheduler to track the amount of time that each process spends running, sleeping, queued, and waiting for io. On exit the script prints out the accumulated time for each state of processes observed. Optionally, this script can be used with the '-c' or '-x' options to focus on a specific PID.</p></li> </ul> <h3><a name="TRACE">TRACE</a></h3> <ul> @@ -306,6 +315,9 @@ keywords: <a href="keyword-index.html#TRACE">TRACE</a> <a href="keyword-index.ht <li><a href="network/dropwatch.stp">network/dropwatch.stp</a> - Watch Where Socket Buffers are Freed in the Kernel<br> keywords: <a href="keyword-index.html#NETWORK">NETWORK</a> <a href="keyword-index.html#TRACEPOINT">TRACEPOINT</a> <a href="keyword-index.html#BUFFER">BUFFER</a> <a href="keyword-index.html#FREE">FREE</a> <br> <p>Every five seconds the dropwatch.stp script lists the number of socket buffers freed at locations in the kernel.</p></li> +<li><a href="process/schedtimes.stp">process/schedtimes.stp</a> - Track Time Processes Spend in Various States using Tracepoints<br> +keywords: <a href="keyword-index.html#PROCESS">PROCESS</a> <a href="keyword-index.html#SCHEDULER">SCHEDULER</a> <a href="keyword-index.html#TIME">TIME</a> <a href="keyword-index.html#TRACEPOINT">TRACEPOINT</a> <br> +<p>The schedtimes.stp script instruments the scheduler to track the amount of time that each process spends running, sleeping, queued, and waiting for io. On exit the script prints out the accumulated time for each state of processes observed. Optionally, this script can be used with the '-c' or '-x' options to focus on a specific PID.</p></li> </ul> <h3><a name="TRAFFIC">TRAFFIC</a></h3> <ul> diff --git a/testsuite/systemtap.examples/keyword-index.txt b/testsuite/systemtap.examples/keyword-index.txt index b53e776f..c0082e36 100644 --- a/testsuite/systemtap.examples/keyword-index.txt +++ b/testsuite/systemtap.examples/keyword-index.txt @@ -337,6 +337,16 @@ keywords: process syscall in the report, default 20). +process/schedtimes.stp - Track Time Processes Spend in Various States using Tracepoints +keywords: process scheduler time tracepoint + + The schedtimes.stp script instruments the scheduler to track the + amount of time that each process spends running, sleeping, queued, + and waiting for io. On exit the script prints out the accumulated + time for each state of processes observed. Optionally, this script + can be used with the '-c' or '-x' options to focus on a specific PID. + + = PROFILING = io/iostats.stp - List Executables Reading and Writing the Most Data @@ -417,6 +427,16 @@ keywords: syscall read write time io = SCHEDULER = +process/schedtimes.stp - Track Time Processes Spend in Various States using Tracepoints +keywords: process scheduler time tracepoint + + The schedtimes.stp script instruments the scheduler to track the + amount of time that each process spends running, sleeping, queued, + and waiting for io. On exit the script prints out the accumulated + time for each state of processes observed. Optionally, this script + can be used with the '-c' or '-x' options to focus on a specific PID. + + process/sleepingBeauties.stp - Generating Backtraces of Threads Waiting for IO Operations keywords: io scheduler backtrace @@ -606,6 +626,16 @@ keywords: syscall read write time io syscalls. +process/schedtimes.stp - Track Time Processes Spend in Various States using Tracepoints +keywords: process scheduler time tracepoint + + The schedtimes.stp script instruments the scheduler to track the + amount of time that each process spends running, sleeping, queued, + and waiting for io. On exit the script prints out the accumulated + time for each state of processes observed. Optionally, this script + can be used with the '-c' or '-x' options to focus on a specific PID. + + = TRACE = general/para-callgraph.stp - Callgraph tracing with arguments @@ -628,6 +658,16 @@ keywords: network tracepoint buffer free socket buffers freed at locations in the kernel. +process/schedtimes.stp - Track Time Processes Spend in Various States using Tracepoints +keywords: process scheduler time tracepoint + + The schedtimes.stp script instruments the scheduler to track the + amount of time that each process spends running, sleeping, queued, + and waiting for io. On exit the script prints out the accumulated + time for each state of processes observed. Optionally, this script + can be used with the '-c' or '-x' options to focus on a specific PID. + + = TRAFFIC = network/nettop.stp - Periodic Listing of Processes Using Network Interfaces diff --git a/testsuite/systemtap.examples/process/schedtimes.meta b/testsuite/systemtap.examples/process/schedtimes.meta new file mode 100644 index 00000000..0074731f --- /dev/null +++ b/testsuite/systemtap.examples/process/schedtimes.meta @@ -0,0 +1,13 @@ +title: Track Time Processes Spend in Various States using Tracepoints +name: schedtimes.stp +version: 1.0 +author: Jason Baron +keywords: process scheduler time tracepoint +subsystem: scheduler +status: production +exit: user-controlled +output: sorted-list +scope: system-wide +description: The schedtimes.stp script instruments the scheduler to track the amount of time that each process spends running, sleeping, queued, and waiting for io. On exit the script prints out the accumulated time for each state of processes observed. Optionally, this script can be used with the '-c' or '-x' options to focus on a specific PID. +test_check: stap -p4 schedtimes.stp +test_installcheck: stap schedtimes.stp -c "sleep 1" diff --git a/testsuite/systemtap.examples/process/schedtimes.stp b/testsuite/systemtap.examples/process/schedtimes.stp new file mode 100755 index 00000000..e964dd58 --- /dev/null +++ b/testsuite/systemtap.examples/process/schedtimes.stp @@ -0,0 +1,154 @@ +#! /usr/bin/env stap + +############################################################ +# Schedtimes.stp +# Author: Jason Baron <jbaron@redhat.com> +# profiles threads and displays their run times, queued times, +# wait times, including i/o wait times. +# Has two modes. When no arguments are given it profiles all +# threads. Alternatively, you can pass -c "program name" +############################################################ + +//constants +global RUNNING=0, QUEUED=1, SLEEPING=2 + +global traced_pid +global run_time, queued_time, sleep_time, io_wait_time +global pid_state, pid_names +global previous_timestamp +global io_wait_count +global io_wait_incremented + +function get_iowait:long(queue:long) +{ + return @cast(queue,"rq","kernel")->nr_iowait->counter; +} + +probe kernel.trace("sched_switch") { + previous_pid = $prev->pid; + next_pid = $next->pid; + if (traced_pid) { + if (previous_pid != traced_pid) { + previous_pid = 0; + } + if (next_pid != traced_pid) { + next_pid = 0; + } + } + if (previous_pid) { + if (!([previous_pid] in pid_state)) { + //use this state as entry into state machine + previous_timestamp[previous_pid] = gettimeofday_us(); + pid_names[previous_pid] = kernel_string($prev->comm); + if ($prev->state > 0) { + pid_state[previous_pid] = SLEEPING; + } else if ($prev->state == 0) { + pid_state[previous_pid] = QUEUED; + } else { + printf("unknown transition:\n"); + printf("pid state: %d our state: %d\n", + $prev->state, pid_state[previous_pid]); + } + } else if (pid_state[previous_pid] == RUNNING) { + pid_names[previous_pid] = kernel_string($prev->comm); + t = gettimeofday_us(); + run_time[previous_pid] += (t - previous_timestamp[previous_pid]); + previous_timestamp[previous_pid] = t; + if ($prev->state > 0) { + if ((get_iowait($rq) - io_wait_count[previous_pid]) > 0) + io_wait_incremented[previous_pid] = 1; + pid_state[previous_pid] = SLEEPING; + } else if ($prev->state == 0) { + pid_state[previous_pid] = QUEUED; + } else { + printf("unknown transition:\n"); + printf("pid state: %d our state: %d\n", + $prev->state, pid_state[previous_pid]); + } + } else { + printf("unknown transition:\n"); + printf("%s pid state: %d our state: %d\n", + pid_names[previous_pid], + $prev->state, pid_state[previous_pid]); + } + } + if (next_pid) { + io_wait_count[next_pid] = get_iowait($rq); + if (!([next_pid] in pid_state)) { + //use this state as entry into state machine + previous_timestamp[next_pid] = gettimeofday_us(); + pid_state[next_pid] = RUNNING; + pid_names[next_pid] = kernel_string($next->comm); + } else if (pid_state[next_pid] == QUEUED) { + t = gettimeofday_us(); + queued_time[next_pid] += (t - previous_timestamp[next_pid]); + previous_timestamp[next_pid] = t; + pid_state[next_pid] = RUNNING; + pid_names[next_pid] = kernel_string($next->comm); + } else { + printf("unknown transition:\n"); + printf("%s pid state: %d our state: %d\n", + pid_names[next_pid], + $next->state, pid_state[next_pid]); + } + } +} + +probe kernel.trace("sched_wakeup") { + wakeup_pid = $p->pid; + if (traced_pid && (wakeup_pid != traced_pid)) next + if ((!$success) && (pid_state[wakeup_pid] != SLEEPING)) next + if (!wakeup_pid) next + + if (!([wakeup_pid] in pid_state)) { + //use this state as entry into state machine + previous_timestamp[wakeup_pid] = gettimeofday_us(); + pid_state[wakeup_pid] = QUEUED; + pid_names[wakeup_pid] = kernel_string($p->comm); + } else if (pid_state[wakeup_pid] == SLEEPING) { + t = gettimeofday_us(); + sleep_time[wakeup_pid] += (t - previous_timestamp[wakeup_pid]); + if (io_wait_incremented[wakeup_pid] == 1) { + io_wait_time[wakeup_pid] += (t - previous_timestamp[wakeup_pid]); + io_wait_incremented[wakeup_pid] = 0; + } + previous_timestamp[wakeup_pid] = t; + pid_state[wakeup_pid] = QUEUED; + pid_names[wakeup_pid] = kernel_string($p->comm); + } else { + printf("unknown transition:\n"); + printf("pid state: %d our state: %d\n", + $p->state, pid_state[wakeup_pid]); + } +} + +probe begin { + traced_pid = target(); + if (traced_pid == 0) { + printf("all mode\n"); + } else { + printf("target mode\n"); + printf("traced pid: %d\n", traced_pid); + } +} + +probe end { + t = gettimeofday_us(); + foreach (pid in pid_state) { + if (pid_state[pid] == SLEEPING) + sleep_time[pid] += (t - previous_timestamp[pid]); + if (pid_state[pid] == QUEUED) + queued_time[pid] += (t - previous_timestamp[pid]); + if (pid_state[pid] == RUNNING) + run_time[pid] += (t - previous_timestamp[pid]); + } + printf ("%16s: %6s %10s %10s %10s %10s %10s\n\n", + "execname", "pid", "run(us)", "sleep(us)", "io_wait(us)", + "queued(us)", "total(us)") + foreach (pid+ in run_time) { + printf("%16s: %6d %10d %10d %10d %10d %10d\n", + pid_names[pid], pid, run_time[pid], sleep_time[pid], + io_wait_time[pid], queued_time[pid], + (run_time[pid] + sleep_time[pid] + queued_time[pid])); + } +} |