diff options
-rwxr-xr-x | nfsdcalltimes | 149 | ||||
-rwxr-xr-x | rpccalltimes | 149 | ||||
-rwxr-xr-x | syscalltimes | 248 |
3 files changed, 546 insertions, 0 deletions
diff --git a/nfsdcalltimes b/nfsdcalltimes new file mode 100755 index 0000000..dafa592 --- /dev/null +++ b/nfsdcalltimes @@ -0,0 +1,149 @@ +#!/bin/bash +do_sort=0 +sort_ave=0 +sort_cnt=0 +sort_min=0 +sort_max=0 +sort_tot=0 +show_all=1 +verbose="" +function usage { + echo "Usage: nfsdcalltimes [-Aachnmtv]" + echo " -A - Do all possible sorting" + echo " -a - sort by Ave ns" + echo " -c - sort by Count" + echo " -n - sort by Min ns" + echo " -m - sort by Max ns" + echo " -t - sort by Total ns" + echo " -v - turn on SystemTap debugging" + echo " -h - print this help text" +} +while getopts Aachnmtv option; do + case $option in + A) sort_ave=1; sort_cnt=1; sort_min=1; + sort_max=1; sort_tot=1; do_sort=1;; + a) sort_ave=1; do_sort=1;; + c) sort_cnt=1; do_sort=1 ;; + n) sort_min=1; do_sort=1 ;; + m) sort_max=1; do_sort=1 ;; + t) sort_tot=1; do_sort=1 ;; + v) verbose="-v "$verbose ;; + h|?|*) usage + exit 1;; + esac +done + +if [ $do_sort -eq 1 ]; then + show_all=0 +fi +echo "Creating and building SystemTap module..." + +stap "$verbose" -e ' +global timebyfunc, top +global start + +probe begin { + printf("Collecting nfsd data - type Ctrl-C to print output and exit...\n") +} + +probe module("nfsd").function("*@fs/nfsd/*") +{ + start[probefunc(), tid()] = gettimeofday_ns() +} +probe module("nfsd").function("*@fs/nfsd/*").return +{ + if (!([probefunc(), tid()] in start)) next + + delta = gettimeofday_ns() - start[probefunc(), tid()] + timebyfunc[probefunc()] <<< delta + + delete start[probefunc(), tid()] +} +function print_header() { + printf("%-26s %10s %12s %12s %12s %12s\n", + "Call", "Count", "Total ns", + "Avg ns", "Min ns", "Max ns") +} +probe end { + if ('$sort_ave' != 0) { + printf("\nSorted nfsd data by Avg ns \n") + print_header() + foreach (call in timebyfunc) + top[call] = @avg(timebyfunc[call]) + foreach (call in top- limit 20) + printf("%-26s %10d %12d %12d %12d %12d\n", call, + @count(timebyfunc[call]), + @sum(timebyfunc[call]), + @avg(timebyfunc[call]), + @min(timebyfunc[call]), + @max(timebyfunc[call])) + delete top + } + if ('$sort_cnt' != 0) { + printf("\nSorted nfsd data by Count\n") + print_header() + foreach (call in timebyfunc) + top[call] = @count(timebyfunc[call]) + foreach (call in top- limit 20) + printf("%-26s %10d %12d %12d %12d %12d\n", call, + @count(timebyfunc[call]), + @sum(timebyfunc[call]), + @avg(timebyfunc[call]), + @min(timebyfunc[call]), + @max(timebyfunc[call])) + delete top + } + if ('$sort_tot' != 0) { + printf("\nSorted nfsd data by Total ns\n") + print_header() + foreach (call in timebyfunc) + top[call] = @sum(timebyfunc[call]) + foreach (call in top- limit 20) + printf("%-26s %10d %12d %12d %12d %12d\n", call, + @count(timebyfunc[call]), + @sum(timebyfunc[call]), + @avg(timebyfunc[call]), + @min(timebyfunc[call]), + @max(timebyfunc[call])) + delete top + } + if ('$sort_min' != 0) { + printf("\nSorted nfsd data by Min ns\n") + print_header() + foreach (call in timebyfunc) + top[call] = @min(timebyfunc[call]) + foreach (call in top- limit 20) + printf("%-26s %10d %12d %12d %12d %12d\n", call, + @count(timebyfunc[call]), + @sum(timebyfunc[call]), + @avg(timebyfunc[call]), + @min(timebyfunc[call]), + @max(timebyfunc[call])) + delete top + } + if ('$sort_max' != 0) { + printf("\nSorted nfsd data by Max ns\n") + print_header() + foreach (call in timebyfunc) + top[call] = @min(timebyfunc[call]) + foreach (call in top- limit 20) + printf("%-26s %10d %12d %12d %12d %12d\n", call, + @count(timebyfunc[call]), + @sum(timebyfunc[call]), + @avg(timebyfunc[call]), + @min(timebyfunc[call]), + @max(timebyfunc[call])) + delete top + } + if ('$show_all' != 0) { + print_header() + foreach (call in timebyfunc) + printf("%-26s %10d %12d %12d %12d %12d\n", call, + @count(timebyfunc[call]), + @sum(timebyfunc[call]), + @avg(timebyfunc[call]), + @min(timebyfunc[call]), + @max(timebyfunc[call])) + } + delete timebyfunc +}' diff --git a/rpccalltimes b/rpccalltimes new file mode 100755 index 0000000..fcf3fe5 --- /dev/null +++ b/rpccalltimes @@ -0,0 +1,149 @@ +#!/bin/bash +do_sort=0 +sort_ave=0 +sort_cnt=0 +sort_min=0 +sort_max=0 +sort_tot=0 +show_all=1 +verbose="" +function usage { + echo "Usage: rpccalltimes [-Aachnmtv]" + echo " -A - Do all possible sorting" + echo " -a - sort by Ave ns" + echo " -c - sort by Count" + echo " -n - sort by Min ns" + echo " -m - sort by Max ns" + echo " -t - sort by Total ns" + echo " -v - turn on SystemTap debugging" + echo " -h - print this help text" +} +while getopts Aachnmtv option; do + case $option in + A) sort_ave=1; sort_cnt=1; sort_min=1; + sort_max=1; sort_tot=1; do_sort=1;; + a) sort_ave=1; do_sort=1;; + c) sort_cnt=1; do_sort=1 ;; + n) sort_min=1; do_sort=1 ;; + m) sort_max=1; do_sort=1 ;; + t) sort_tot=1; do_sort=1 ;; + v) verbose="-v "$verbose ;; + h|?|*) usage + exit 1;; + esac +done + +if [ $do_sort -eq 1 ]; then + show_all=0 +fi +echo "Creating and building SystemTap module..." + +stap "$verbose" -e ' +global timebyfunc, top +global start + +probe begin { + printf("Collecting rpc data - type Ctrl-C to print output and exit...\n") +} + +probe module("sunrpc").function("*@net/sunrpc/*") +{ + start[probefunc(), tid()] = gettimeofday_ns() +} +probe module("sunrpc").function("*@net/sunrpc/*").return +{ + if (!([probefunc(), tid()] in start)) next + + delta = gettimeofday_ns() - start[probefunc(), tid()] + timebyfunc[probefunc()] <<< delta + + delete start[probefunc(), tid()] +} +function print_header() { + printf("%-26s %10s %12s %12s %12s %12s\n", + "Call", "Count", "Total ns", + "Avg ns", "Min ns", "Max ns") +} +probe end { + if ('$sort_ave' != 0) { + printf("\nSorted rpc data by Avg ns \n") + print_header() + foreach (call in timebyfunc) + top[call] = @avg(timebyfunc[call]) + foreach (call in top- limit 20) + printf("%-26s %10d %12d %12d %12d %12d\n", call, + @count(timebyfunc[call]), + @sum(timebyfunc[call]), + @avg(timebyfunc[call]), + @min(timebyfunc[call]), + @max(timebyfunc[call])) + delete top + } + if ('$sort_cnt' != 0) { + printf("\nSorted rpc data by Count\n") + print_header() + foreach (call in timebyfunc) + top[call] = @count(timebyfunc[call]) + foreach (call in top- limit 20) + printf("%-26s %10d %12d %12d %12d %12d\n", call, + @count(timebyfunc[call]), + @sum(timebyfunc[call]), + @avg(timebyfunc[call]), + @min(timebyfunc[call]), + @max(timebyfunc[call])) + delete top + } + if ('$sort_tot' != 0) { + printf("\nSorted rpc data by Total ns\n") + print_header() + foreach (call in timebyfunc) + top[call] = @sum(timebyfunc[call]) + foreach (call in top- limit 20) + printf("%-26s %10d %12d %12d %12d %12d\n", call, + @count(timebyfunc[call]), + @sum(timebyfunc[call]), + @avg(timebyfunc[call]), + @min(timebyfunc[call]), + @max(timebyfunc[call])) + delete top + } + if ('$sort_min' != 0) { + printf("\nSorted rpc data by Min ns\n") + print_header() + foreach (call in timebyfunc) + top[call] = @min(timebyfunc[call]) + foreach (call in top- limit 20) + printf("%-26s %10d %12d %12d %12d %12d\n", call, + @count(timebyfunc[call]), + @sum(timebyfunc[call]), + @avg(timebyfunc[call]), + @min(timebyfunc[call]), + @max(timebyfunc[call])) + delete top + } + if ('$sort_max' != 0) { + printf("\nSorted rpc data by Max ns\n") + print_header() + foreach (call in timebyfunc) + top[call] = @min(timebyfunc[call]) + foreach (call in top- limit 20) + printf("%-26s %10d %12d %12d %12d %12d\n", call, + @count(timebyfunc[call]), + @sum(timebyfunc[call]), + @avg(timebyfunc[call]), + @min(timebyfunc[call]), + @max(timebyfunc[call])) + delete top + } + if ('$show_all' != 0) { + print_header() + foreach (call in timebyfunc) + printf("%-26s %10d %12d %12d %12d %12d\n", call, + @count(timebyfunc[call]), + @sum(timebyfunc[call]), + @avg(timebyfunc[call]), + @min(timebyfunc[call]), + @max(timebyfunc[call])) + } + delete timebyfunc +}' diff --git a/syscalltimes b/syscalltimes new file mode 100755 index 0000000..84ca77a --- /dev/null +++ b/syscalltimes @@ -0,0 +1,248 @@ +#!/bin/bash + +# Syscalltimes systemtap script +# Copyright (C) 2007 IBM Corp. +# +# This file is part of systemtap, and is free software. You can +# redistribute it and/or modify it under the terms of the GNU General +# Public License (GPL); either version 2, or (at your option) any +# later version. + +### +### syscalltime - Combination shell/systemtap script to measure system call +### counts and times. Can be filtered by process IDs, process +### names and users. +### + +# Filter options +F_PIDSTR=""; F_PID=0 # Filter by process ID +F_EXECSTR=""; F_EXEC=0 # Filter by process name +F_UIDSTR=""; F_UID=0 # Filter by user +FILTER=0 # Any filters specified? + +# Print options +P_TOTALS=0 # Print totals +P_VERBOSE_STR="" # Print verbose build output + +DELIM="," + +function usage { + echo "USAGE: syscalltimes [-n pname]... [-p pid]... [-u username]..." + echo " [-v]... [-t] [-h]" + echo " -n pname # filter by this process name" + echo " -p pid # filter by this process ID" + echo " -u username # filter by this user" + echo " -t # print totals (default with filters: OFF" + echo " default without filters: ON)" + echo " -v # print verbose output during SystemTap module creation" + echo " -h # print this help text" + echo "" + echo "NOTE: This script can take long time to build. Use -v[vv] to monitor" + echo " the module creation and build process." +} + +# Process options +while getopts n:p:u:vth option; do + case $option in + n) let "F_EXEC++" + F_EXECSTR=$OPTARG$DELIM$F_EXECSTR ;; + + p) let "F_PID++" + F_PIDSTR=$OPTARG$DELIM$F_PIDSTR ;; + + u) uid=`awk -F: '$1 == name {print $3}' name=$OPTARG /etc/passwd` + if [[ $uid != "" ]]; then + let "F_UID++" + F_UIDSTR=$uid$DELIM$F_UIDSTR + else + echo "ERROR: Unknown user:" $OPTARG + let "ERROR++" + fi ;; + + v) P_VERBOSE_STR="-v "$P_VERBOSE_STR ;; + + t) P_TOTALS=1 ;; + + h|?|*) usage + exit 1 ;; + esac +done + +if [[ $ERROR > 0 ]]; then + exit 1 +fi + +if [[ $F_EXEC > 0 || $F_PID > 0 || $F_UID > 0 ]]; then + FILTER=1 +fi + +echo "Creating and building SystemTap module..." + +# +# SystemTap script +# +stap $P_VERBOSE_STR -e ' +global start, timebycall, timebypid, timebyuid, timebyexec +global f_exec_str, f_pid_str, f_uid_str +global f_exec, f_pid, f_uid +global prt_totals, filter_str + +probe begin { + printf("Collecting data - type Ctrl-C to print output and exit...\n") + + # If no filters specified, skip filter processing + if ('$FILTER' == 0) { + filter_str = " (unfiltered)" + prt_totals = 1 // On by default if no filtering + next + } else + filter_str = " (filtered)" + + prt_totals = '$P_TOTALS' + f_exec_str = "'$F_EXECSTR'" + f_pid_str = "'$F_PIDSTR'" + f_uid_str = "'$F_UIDSTR'" + + delim = "'$DELIM'" + + # Process names + if ('$F_EXEC') { + pname = tokenize(f_exec_str, delim) + while (pname != "") { + f_exec[pname] = 1 + pname = tokenize("", delim) + } + } + + # Process IDs + if ('$F_PID') { + pid = tokenize(f_pid_str, delim) + while (pid != "") { + f_pid[strtol(pid, 10)] = 1 + pid = tokenize("", delim) + } + } + + # User IDs + if ('$F_UID') { + uid = tokenize(f_uid_str, delim) + while (uid != "") { + f_uid[strtol(uid, 10)] = 1 + uid = tokenize("", delim) + } + } +} + +probe syscall.* { + start[name, tid()] = gettimeofday_ns() +} + +probe syscall.*.return { + # Skip if we have not seen this before + if (!([name, tid()] in start)) next + + delta = gettimeofday_ns() - start[name, tid()] + + # Check filters + if ('$FILTER') { + target = 0 + if (pid() in f_pid) { + timebypid[name, pid()] <<< delta + target = 1 + } + if (uid() in f_uid) { + timebyuid[name, uid()] <<< delta + target = 1 + } + if (execname() in f_exec) { + timebyexec[name, execname()] <<< delta + target = 1 + } + } else + target = 1 + + # Totals + if (target && prt_totals) + timebycall[name] <<< delta + + delete start[name, tid()] +} + +function print_header() { + printf("%22s %10s %12s %12s %12s %12s\n", + "System Call", "Count", "Total ns", + "Avg ns", "Min ns", "Max ns") +} + +probe end { + if (prt_totals) { + printf("\nTimes for all processes%s:\n\n", filter_str) + print_header() + foreach (call in timebycall) + printf("%22s %10d %12d %12d %12d %12d\n", call, + @count(timebycall[call]), + @sum(timebycall[call]), + @avg(timebycall[call]), + @min(timebycall[call]), + @max(timebycall[call])) + } + + if ('$F_PID') { + curpid = -1 + foreach ([call, pid-] in timebypid) { + if (curpid != pid) { + curpid = pid + printf("\nTimes for process ID %d:\n\n", curpid) + print_header() + } + printf("%22s %10d %12d %12d %12d %12d\n", call, + @count(timebypid[call, pid]), + @sum(timebypid[call, pid]), + @avg(timebypid[call, pid]), + @min(timebypid[call, pid]), + @max(timebypid[call, pid])) + } + printf("\n") + } + + if ('$F_EXEC') { + curexec = "" + foreach ([call, exec-] in timebyexec) { + if (curexec != exec) { + curexec = exec + printf("\nTimes for process name %s:\n\n", curexec) + print_header() + } + printf("%22s %10d %12d %12d %12d %12d\n", call, + @count(timebyexec[call, exec]), + @sum(timebyexec[call, exec]), + @avg(timebyexec[call, exec]), + @min(timebyexec[call, exec]), + @max(timebyexec[call, exec])) + } + printf("\n") + } + + if ('$F_UID') { + curuid = -1 + foreach ([call, uid-] in timebyuid) { + if (curuid != uid) { + curuid = uid + printf("\nTimes for user ID %d:\n\n", curuid) + print_header() + } + printf("%22s %10d %12d %12d %12d %12d\n", call, + @count(timebyuid[call, uid]), + @sum(timebyuid[call, uid]), + @avg(timebyuid[call, uid]), + @min(timebyuid[call, uid]), + @max(timebyuid[call, uid])) + } + printf("\n") + } + + delete timebycall + delete timebypid + delete timebyuid + delete timebyexec +}' |