0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen# procsystime - print process system call time details.
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen# Written using DTrace (Solaris 10 3/05).
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen# $Id: procsystime 4 2007-08-01 11:01:38Z brendan $
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen# USAGE: procsystime [-acehoT] [ -p PID | -n name | command ]
5fb3bff645380804c9db2510940c41db6b8fdb01Timo Sirainen# -p PID # examine this PID
15b9759df8e4f6fb00c115353827a2aebbebfebcTimo Sirainen# -n name # examine this process name
15b9759df8e4f6fb00c115353827a2aebbebfebcTimo Sirainen# -a # print all details
15b9759df8e4f6fb00c115353827a2aebbebfebcTimo Sirainen# -c # print syscall counts
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen# -e # print elapsed times
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen# -o # print CPU times
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen# -T # print totals
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen# procsystime -p 1871 # examine PID 1871
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen# procsystime -n tar # examine processes called "tar"
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen# procsystime -aTn bash # print all details for bash shells
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen# procsystime df -h # run and examine "df -h"
d6badc27cd6e8d3398877b6766cb0aaeef3a7800Timo Sirainen# The elapsed times are interesting, to help identify syscalls that take
d6badc27cd6e8d3398877b6766cb0aaeef3a7800Timo Sirainen# some time to complete (during which the process may have slept). CPU time
d6badc27cd6e8d3398877b6766cb0aaeef3a7800Timo Sirainen# helps us identify syscalls that are consuming CPU cycles to run.
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen# SYSCALL System call name
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen# TIME (ns) Total time, nanoseconds
6ef7e31619edfaa17ed044b45861d106a86191efTimo Sirainen# COUNT Number of occurrences
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen# COPYRIGHT: Copyright (c) 2005 Brendan Gregg.
04ab375449dd97eed50ada88dd0df2abab01cfeeTimo Sirainen# CDDL HEADER START
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen# The contents of this file are subject to the terms of the
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen# Common Development and Distribution License, Version 1.0 only
6ef7e31619edfaa17ed044b45861d106a86191efTimo Sirainen# (the "License"). You may not use this file except in compliance
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen# with the License.
6ef7e31619edfaa17ed044b45861d106a86191efTimo Sirainen# You can obtain a copy of the license at Docs/cddl1.txt
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen# See the License for the specific language governing permissions
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen# and limitations under the License.
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen# CDDL HEADER END
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen# Author: Brendan Gregg [Sydney, Australia]
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen# 27-Apr-2005 Brendan Gregg Created this.
57a8c6a95e4bce3eeaba36985adb81c07dd683ffTimo Sirainen# 08-Jun-2005 " " Added command option.
a27e065f1a1f91c7fbdf7c2ea1c387441af0cbb3Timo Sirainen# 22-Sep-2005 " " Allowed systemwide tracing.
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen# 22-Sep-2005 " " Last update.
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen##############################
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen# --- Process Arguments ---
ccc895c0358108d2304239063e940b7d75f364abTimo Sirainen### Default variables
ccc895c0358108d2304239063e940b7d75f364abTimo Sirainenopt_filter=0; opt_pid=0; opt_name=0; pid=0; pname=".";
8d630c15a8ed6f85553467c3a231a273defca5f6Timo Sirainenopt_elapsed=0; opt_cpu=0; opt_counts=0; opt_totals=0
c5ab90cfad9cc3e33bcb1baeb30ffc82a7b7053aTimo Sirainen### Process options
ab0155cbec1286e1cd00a0e01d78e0f3ca34cea6Timo Sirainen a) opt_totals=1; opt_elapsed=1; opt_cpu=1; opt_counts=1 ;;
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen USAGE: procsystime [-aceho] [ -p PID | -n name | command ]
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen -p PID # examine this PID
6ef7e31619edfaa17ed044b45861d106a86191efTimo Sirainen -n name # examine this process name
6ef7e31619edfaa17ed044b45861d106a86191efTimo Sirainen -a # print all details
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen -e # print elapsed times
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen -c # print syscall counts
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen -o # print CPU times
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen -T # print totals
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen procsystime -p 1871 # examine PID 1871
d756ebcfa96bd7cff02097c8f26df9df368b81b1Timo Sirainen procsystime -n tar # examine processes called "tar"
d756ebcfa96bd7cff02097c8f26df9df368b81b1Timo Sirainen procsystime -aTn bash # print all details for bash
d756ebcfa96bd7cff02097c8f26df9df368b81b1Timo Sirainen procsystime df -h # run and examine "df -h"
d756ebcfa96bd7cff02097c8f26df9df368b81b1Timo Sirainenshift `expr $OPTIND - 1`
f81f4bc282cd1944cec187bae89c0701a416ed2aTimo Sirainen### Option logic
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainenif [ $opt_pid -eq 0 -a $opt_name -eq 0 -a "$*" != "" ]; then
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen opt_command=1
b2c1349cf07410aefab0f5b17153af9e5cfcf48fTimo Sirainenif [ $opt_elapsed -eq 0 -a $opt_cpu -eq 0 -a $opt_counts -eq 0 ]; then
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen opt_elapsed=1;
16c89b1260c9d07c01c83a9219424d3727069b2eTimo Sirainen#################################
faed8babca9914257f34fb2e603d74016d563b2dTimo Sirainen# --- Main Program, DTrace ---
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen #pragma D option quiet
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen * Command line arguments
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen inline int OPT_elapsed = '$opt_elapsed';
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen inline int OPT_cpu = '$opt_cpu';
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen inline int OPT_counts = '$opt_counts';
e015e2f7e7f48874495f9df8b0dd192b7ffcb5ccTimo Sirainen inline int OPT_filter = '$opt_filter';
e015e2f7e7f48874495f9df8b0dd192b7ffcb5ccTimo Sirainen inline int OPT_pid = '$opt_pid';
e015e2f7e7f48874495f9df8b0dd192b7ffcb5ccTimo Sirainen inline int OPT_name = '$opt_name';
e015e2f7e7f48874495f9df8b0dd192b7ffcb5ccTimo Sirainen inline int OPT_totals = '$opt_totals';
e015e2f7e7f48874495f9df8b0dd192b7ffcb5ccTimo Sirainen inline int OPT_command = '$opt_command';
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen inline int PID = '$pid';
e015e2f7e7f48874495f9df8b0dd192b7ffcb5ccTimo Sirainen inline string NAME = "'$pname'";
e015e2f7e7f48874495f9df8b0dd192b7ffcb5ccTimo Sirainen inline string COMMAND = "'$command'";
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen dtrace:::BEGIN
42507d758b053bb483de58fba55c73a9eb5d3fbaTimo Sirainen self->start = 0;
a3ee5ce6ecc8e228ee69300fdd562d7ac8be89a7Timo Sirainen self->vstart = 0;
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen dtrace:::BEGIN
4981827cb5e32cf767b7b0e3070137e6b36f42afTimo Sirainen /! OPT_command/
4981827cb5e32cf767b7b0e3070137e6b36f42afTimo Sirainen printf("Tracing... Hit Ctrl-C to end...\n");
2ebeb22b9a8a8bb7fbe2f2e2908478a220792b87Timo Sirainen * Set start timestamp and counts
2ebeb22b9a8a8bb7fbe2f2e2908478a220792b87Timo Sirainen syscall:::entry
a423d985ba7261661475811c22b21b80ec765a71Timo Sirainen /(! OPT_filter) ||
a423d985ba7261661475811c22b21b80ec765a71Timo Sirainen (OPT_pid && pid == PID) ||
345212e8f61ebf14ff4f80df26df9e655eb5121eTimo Sirainen (OPT_name && execname == NAME) ||
c13f3df87bc8ec1fb279fc0ffa6e8517f74dc07cTimo Sirainen (OPT_command && pid == $target)/
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen self->ok = 1;
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen syscall:::entry
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen OPT_counts ? @Counts[probefunc] = count() : 1;
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen (OPT_counts && OPT_totals) ? @Counts["TOTAL:"] = count() : 1;
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen OPT_elapsed ? self->start = timestamp : 1;
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen OPT_cpu ? self->vstart = vtimestamp : 1;
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen self->ok = 0;
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen * Calculate time deltas
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen syscall:::return
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen /self->start/
42507d758b053bb483de58fba55c73a9eb5d3fbaTimo Sirainen this->elapsed = timestamp - self->start;
f81f4bc282cd1944cec187bae89c0701a416ed2aTimo Sirainen @Elapsed[probefunc] = sum(this->elapsed);
f81f4bc282cd1944cec187bae89c0701a416ed2aTimo Sirainen OPT_totals ? @Elapsed["TOTAL:"] = sum(this->elapsed) : 1;
f81f4bc282cd1944cec187bae89c0701a416ed2aTimo Sirainen self->start = 0;
f81f4bc282cd1944cec187bae89c0701a416ed2aTimo Sirainen syscall:::return
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen /self->vstart/
5fb3bff645380804c9db2510940c41db6b8fdb01Timo Sirainen this->cpu = vtimestamp - self->vstart;
5fb3bff645380804c9db2510940c41db6b8fdb01Timo Sirainen @CPU[probefunc] = sum(this->cpu);
5fb3bff645380804c9db2510940c41db6b8fdb01Timo Sirainen OPT_totals ? @CPU["TOTAL:"] = sum(this->cpu) : 1;
5fb3bff645380804c9db2510940c41db6b8fdb01Timo Sirainen self->vstart = 0;
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen * Elapsed time report
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen /OPT_elapsed/
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen printf("\nElapsed Times for ");
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen OPT_pid ? printf("PID %d,\n\n",PID) : 1;
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen OPT_name ? printf("processes %s,\n\n",NAME) : 1;
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen OPT_command ? printf("command %s,\n\n",COMMAND) : 1;
90adcaa0a00eba29b7fbd50ca66be11c8d086d6aTimo Sirainen (! OPT_filter) ? printf("all processes,\n\n") : 1;
90adcaa0a00eba29b7fbd50ca66be11c8d086d6aTimo Sirainen printf("%16s %18s\n","SYSCALL","TIME (ns)");
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen printa("%16s %@18d\n",@Elapsed);
87460b08cb97b31cde640d4975a6aa2c1d0e7226Timo Sirainen * CPU time report
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen printf("\nCPU Times for ");
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen OPT_pid ? printf("PID %d,\n\n",PID) : 1;
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen OPT_name ? printf("processes %s,\n\n",NAME) : 1;
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen OPT_command ? printf("command %s,\n\n",COMMAND) : 1;
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen (! OPT_filter) ? printf("all processes,\n\n") : 1;
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen printf("%16s %18s\n","SYSCALL","TIME (ns)");
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen printa("%16s %@18d\n",@CPU);
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen * Syscall count report
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen printf("\nSyscall Counts for ");
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen OPT_pid ? printf("PID %d,\n\n",PID) : 1;
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen OPT_name ? printf("processes %s,\n\n",NAME) : 1;
8e371a3ce32bd64288786855b8ce0cb63f19f7d1Timo Sirainen OPT_command ? printf("command %s,\n\n",COMMAND) : 1;
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen (! OPT_filter) ? printf("all processes,\n\n") : 1;
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen printf("%16s %18s\n","SYSCALL","COUNT");
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen OPT_counts ? printa("%16s %@18d\n",@Counts) : 1;
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainen### Run DTrace
fdc557286bc9f92c5f3bb49096ff6e2bcec0ea79Timo Sirainenif [ $opt_command -eq 1 ]; then
0cb2e8eb55e70f8ebe1e8349bdf49e4cbe5d8834Timo Sirainen /usr/sbin/dtrace -n "$dtrace" -x evaltime=exec -c "$command" >&2
e4c90f0b88e40a8f92b8f5e1f1a3ea701e5c965cTimo Sirainen /usr/sbin/dtrace -n "$dtrace" >&2