aboutsummaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorRui Paulo <rpaulo@FreeBSD.org>2010-08-21 13:15:56 +0000
committerRui Paulo <rpaulo@FreeBSD.org>2010-08-21 13:15:56 +0000
commit87c8f7aa3a46118212b99f0d58b18aa93c06b02a (patch)
treea66d96e1cc69ebeae36292bc69cc8331b99dbb40
downloadsrc-87c8f7aa3a46118212b99f0d58b18aa93c06b02a.tar.gz
src-87c8f7aa3a46118212b99f0d58b18aa93c06b02a.zip
Import dtruss from Brendan Gregg's DTraceToolkit.
Sponsored by: The FreeBSD Foundation
Notes
Notes: svn path=/vendor/dtracetoolkit/dist/; revision=211557
-rwxr-xr-xdtruss467
1 files changed, 467 insertions, 0 deletions
diff --git a/dtruss b/dtruss
new file mode 100755
index 000000000000..f4b5e45a30df
--- /dev/null
+++ b/dtruss
@@ -0,0 +1,467 @@
+#!/usr/bin/sh
+#
+# dtruss - print process system call time details.
+# Written using DTrace (Solaris 10 3/05).
+#
+# $Id: dtruss 9 2007-08-07 10:21:07Z brendan $
+#
+# USAGE: dtruss [-acdeflhoLs] [-t syscall] { -p PID | -n name | command }
+#
+# -p PID # examine this PID
+# -n name # examine this process name
+# -t syscall # examine this syscall only
+# -a # print all details
+# -c # print system call counts
+# -d # print relative timestamps (us)
+# -e # print elapsed times (us)
+# -f # follow children as they are forked
+# -l # force printing of pid/lwpid per line
+# -o # print on cpu times (us)
+# -s # print stack backtraces
+# -L # don't print pid/lwpid per line
+# -b bufsize # dynamic variable buf size (default is "4m")
+# eg,
+# dtruss df -h # run and examine the "df -h" command
+# dtruss -p 1871 # examine PID 1871
+# dtruss -n tar # examine all processes called "tar"
+# dtruss -f test.sh # run test.sh and follow children
+#
+# See the man page dtruss(1M) for further details.
+#
+# SEE ALSO: procsystime # DTraceToolkit
+# dapptrace # DTraceToolkit
+# truss
+#
+# COPYRIGHT: Copyright (c) 2005, 2006, 2007 Brendan Gregg.
+#
+# CDDL HEADER START
+#
+# The contents of this file are subject to the terms of the
+# Common Development and Distribution License, Version 1.0 only
+# (the "License"). You may not use this file except in compliance
+# with the License.
+#
+# You can obtain a copy of the license at Docs/cddl1.txt
+# or http://www.opensolaris.org/os/licensing.
+# See the License for the specific language governing permissions
+# and limitations under the License.
+#
+# CDDL HEADER END
+#
+# TODO: Track signals, more output formatting.
+#
+# 29-Apr-2005 Brendan Gregg Created this.
+# 09-May-2005 " " Fixed evaltime (thanks Adam L.)
+# 16-May-2005 " " Added -t syscall tracing.
+# 17-Jun-2005 " " Added -s stack backtraces.
+# 17-Jun-2005 " " Last update.
+# 29-Jun-2007 " " Used progenyof() (thanks Aaron Gutman).
+# 06-Aug-2007 " " Various updates.
+#
+
+
+##############################
+# --- Process Arguments ---
+#
+
+### Default variables
+opt_pid=0; opt_name=0; pid=0; pname="."; opt_elapsed=0; opt_cpu=0
+opt_counts=0; opt_relative=0; opt_printid=0; opt_follow=0; opt_command=0
+command=""; opt_buf=0; buf="4m"; opt_trace=0; trace="."; opt_stack=0
+
+### Process options
+while getopts ab:cdefhln:op:st:L name
+do
+ case $name in
+ b) opt_buf=1; buf=$OPTARG ;;
+ p) opt_pid=1; pid=$OPTARG ;;
+ n) opt_name=1; pname=$OPTARG ;;
+ t) opt_trace=1; trace=$OPTARG ;;
+ a) opt_counts=1; opt_relative=1; opt_elapsed=1; opt_follow=1
+ opt_printid=1; opt_cpu=1 ;;
+ c) opt_counts=1 ;;
+ d) opt_relative=1 ;;
+ e) opt_elapsed=1 ;;
+ f) opt_follow=1 ;;
+ l) opt_printid=1 ;;
+ o) opt_cpu=1 ;;
+ L) opt_printid=-1 ;;
+ s) opt_stack=-1 ;;
+ h|?) cat <<-END >&2
+ USAGE: dtruss [-acdefholLs] [-t syscall] { -p PID | -n name | command }
+
+ -p PID # examine this PID
+ -n name # examine this process name
+ -t syscall # examine this syscall only
+ -a # print all details
+ -c # print syscall counts
+ -d # print relative times (us)
+ -e # print elapsed times (us)
+ -f # follow children (-p or cmd only)
+ -l # force printing pid/lwpid
+ -o # print on cpu times
+ -s # print stack backtraces
+ -L # don't print pid/lwpid
+ -b bufsize # dynamic variable buf size
+ eg,
+ dtruss df -h # run and examine "df -h"
+ dtruss -p 1871 # examine PID 1871
+ dtruss -n tar # examine all processes called "tar"
+ dtruss -f test.sh # run test.sh and follow children
+ END
+ exit 1
+ esac
+done
+shift `expr $OPTIND - 1`
+
+### Option logic
+if [ $opt_pid -eq 0 -a $opt_name -eq 0 ]; then
+ opt_command=1
+ if [ "$*" = "" ]; then
+ $0 -h
+ exit
+ fi
+ command="$*" # yes, I meant $*!
+fi
+if [ $opt_follow -eq 1 -o $opt_name -eq 1 ]; then
+ if [ $opt_printid -ne -1 ]; then
+ opt_printid=1
+ else
+ opt_printid=0
+ fi
+fi
+if [ $opt_follow -eq 1 -a $opt_name -eq 1 ]; then
+ echo "ERROR: -f option cannot be used with -n (use -p or cmd instead)."
+ exit 1
+fi
+
+### Option translation
+if [ "$trace" = "exec" ]; then trace="exece"; fi
+if [ "$trace" = "time" ]; then trace="gtime"; fi
+if [ "$trace" = "exit" ]; then trace="rexit"; fi
+
+
+#################################
+# --- Main Program, DTrace ---
+#
+
+### Define D Script
+dtrace='
+#pragma D option quiet
+#pragma D option switchrate=10
+
+/*
+ * Command line arguments
+ */
+inline int OPT_command = '$opt_command';
+inline int OPT_follow = '$opt_follow';
+inline int OPT_printid = '$opt_printid';
+inline int OPT_relative = '$opt_relative';
+inline int OPT_elapsed = '$opt_elapsed';
+inline int OPT_cpu = '$opt_cpu';
+inline int OPT_counts = '$opt_counts';
+inline int OPT_pid = '$opt_pid';
+inline int OPT_name = '$opt_name';
+inline int OPT_trace = '$opt_trace';
+inline int OPT_stack = '$opt_stack';
+inline string NAME = "'$pname'";
+inline string TRACE = "'$trace'";
+
+dtrace:::BEGIN
+{
+ /* print header */
+ OPT_printid ? printf("%-9s ", "PID/LWP") : 1;
+ OPT_relative ? printf("%8s ", "RELATIVE") : 1;
+ OPT_elapsed ? printf("%7s ", "ELAPSD") : 1;
+ OPT_cpu ? printf("%6s ", "CPU") : 1;
+ printf("SYSCALL(args) \t\t = return\n");
+}
+
+/*
+ * Save syscall entry info
+ */
+syscall:::entry
+/((OPT_command || OPT_pid) && pid == $target) ||
+ (OPT_name && execname == NAME) ||
+ (OPT_follow && progenyof($target))/
+{
+ /* set start details */
+ self->start = timestamp;
+ self->vstart = vtimestamp;
+ self->arg0 = arg0;
+ self->arg1 = arg1;
+ self->arg2 = arg2;
+
+ /* count occurances */
+ OPT_counts == 1 ? @Counts[probefunc] = count() : 1;
+}
+
+/*
+ * Follow children
+ */
+syscall::fork*:return
+/(OPT_follow && progenyof($target)) && (!OPT_trace || (TRACE == probefunc))/
+{
+ /* print output */
+ self->code = errno == 0 ? "" : "Err#";
+ OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
+ OPT_relative ? printf("%8d: ", vtimestamp/1000) : 1;
+ OPT_elapsed ? printf("%7d: ", 0) : 1;
+ OPT_cpu ? printf("%6d ", 0) : 1;
+ printf("%s(0x%X, 0x%X, 0x%X)\t\t = %d %s%d\n", probefunc,
+ self->arg0, self->arg1, self->arg2, (int)arg0, self->code,
+ (int)errno);
+}
+
+/*
+ * Check for syscall tracing
+ */
+syscall:::entry
+/OPT_trace && probefunc != TRACE/
+{
+ /* drop info */
+ self->start = 0;
+ self->vstart = 0;
+ self->arg0 = 0;
+ self->arg1 = 0;
+ self->arg2 = 0;
+}
+
+/*
+ * Print return data
+ */
+
+/*
+ * The following code is written in an intentionally repetative way.
+ * The first versions had no code redundancies, but performed badly during
+ * benchmarking. The priority here is speed, not cleverness. I know there
+ * are many obvious shortcuts to this code, I have tried them. This style has
+ * shown in benchmarks to be the fastest (fewest probes fired, fewest actions).
+ */
+
+/* print 3 args, return as hex */
+syscall::lwp_sigmask:return
+/self->start/
+{
+ /* calculate elapsed time */
+ this->elapsed = timestamp - self->start;
+ self->start = 0;
+ this->cpu = vtimestamp - self->vstart;
+ self->vstart = 0;
+ self->code = errno == 0 ? "" : "Err#";
+
+ /* print optional fields */
+ OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
+ OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
+ OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
+ OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
+
+ /* print main data */
+ printf("%s(0x%X, 0x%X, 0x%X)\t\t = 0x%X %s%d\n", probefunc,
+ (int)self->arg0, self->arg1, self->arg2, (int)arg0,
+ self->code, (int)errno);
+ OPT_stack ? ustack() : 1;
+ OPT_stack ? trace("\n") : 1;
+ self->arg0 = 0;
+ self->arg1 = 0;
+ self->arg2 = 0;
+}
+
+/* print 3 args, arg0 as a string */
+syscall::stat*:return,
+syscall::lstat*:return,
+syscall::open*:return,
+syscall::resolvepath:return
+/self->start/
+{
+ /* calculate elapsed time */
+ this->elapsed = timestamp - self->start;
+ self->start = 0;
+ this->cpu = vtimestamp - self->vstart;
+ self->vstart = 0;
+ self->code = errno == 0 ? "" : "Err#";
+
+ /* print optional fields */
+ OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
+ OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
+ OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
+ OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
+
+ /* print main data */
+ printf("%s(\"%S\", 0x%X, 0x%X)\t\t = %d %s%d\n", probefunc,
+ copyinstr(self->arg0), self->arg1, self->arg2, (int)arg0,
+ self->code, (int)errno);
+ OPT_stack ? ustack() : 1;
+ OPT_stack ? trace("\n") : 1;
+ self->arg0 = 0;
+ self->arg1 = 0;
+ self->arg2 = 0;
+}
+
+/* print 3 args, arg1 as a string */
+syscall::write:return,
+syscall::pwrite:return,
+syscall::*read*:return
+/self->start/
+{
+ /* calculate elapsed time */
+ this->elapsed = timestamp - self->start;
+ self->start = 0;
+ this->cpu = vtimestamp - self->vstart;
+ self->vstart = 0;
+ self->code = errno == 0 ? "" : "Err#";
+
+ /* print optional fields */
+ OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
+ OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
+ OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
+ OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
+
+ /* print main data */
+ printf("%s(0x%X, \"%S\", 0x%X)\t\t = %d %s%d\n", probefunc, self->arg0,
+ stringof(copyin(self->arg1, self->arg2)), self->arg2, (int)arg0,
+ self->code, (int)errno);
+ OPT_stack ? ustack() : 1;
+ OPT_stack ? trace("\n") : 1;
+ self->arg0 = 0;
+ self->arg1 = 0;
+ self->arg2 = 0;
+}
+
+/* print 0 arg output */
+syscall::gtime:return,
+syscall::*fork*:return
+/self->start/
+{
+ /* calculate elapsed time */
+ this->elapsed = timestamp - self->start;
+ self->start = 0;
+ this->cpu = vtimestamp - self->vstart;
+ self->vstart = 0;
+ self->code = errno == 0 ? "" : "Err#";
+
+ /* print optional fields */
+ OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
+ OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
+ OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
+ OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
+
+ /* print main data */
+ printf("%s()\t\t = %d %s%d\n", probefunc,
+ (int)arg0, self->code, (int)errno);
+ OPT_stack ? ustack() : 1;
+ OPT_stack ? trace("\n") : 1;
+ self->arg0 = 0;
+ self->arg1 = 0;
+ self->arg2 = 0;
+}
+
+/* print 1 arg output */
+syscall::brk:return,
+syscall::times:return,
+syscall::stime:return,
+syscall::close:return
+/self->start/
+{
+ /* calculate elapsed time */
+ this->elapsed = timestamp - self->start;
+ self->start = 0;
+ this->cpu = vtimestamp - self->vstart;
+ self->vstart = 0;
+ self->code = errno == 0 ? "" : "Err#";
+
+ /* print optional fields */
+ OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
+ OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
+ OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
+ OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
+
+ /* print main data */
+ printf("%s(0x%X)\t\t = %d %s%d\n", probefunc, self->arg0,
+ (int)arg0, self->code, (int)errno);
+ OPT_stack ? ustack() : 1;
+ OPT_stack ? trace("\n") : 1;
+ self->arg0 = 0;
+ self->arg1 = 0;
+ self->arg2 = 0;
+}
+
+/* print 2 arg output */
+syscall::utime:return,
+syscall::munmap:return
+/self->start/
+{
+ /* calculate elapsed time */
+ this->elapsed = timestamp - self->start;
+ self->start = 0;
+ this->cpu = vtimestamp - self->vstart;
+ self->vstart = 0;
+ self->code = errno == 0 ? "" : "Err#";
+
+ /* print optional fields */
+ OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
+ OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
+ OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
+ OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
+
+ /* print main data */
+ printf("%s(0x%X, 0x%X)\t\t = %d %s%d\n", probefunc, self->arg0,
+ self->arg1, (int)arg0, self->code, (int)errno);
+ OPT_stack ? ustack() : 1;
+ OPT_stack ? trace("\n") : 1;
+ self->arg0 = 0;
+ self->arg1 = 0;
+ self->arg2 = 0;
+}
+
+/* print 3 arg output - default */
+syscall:::return
+/self->start/
+{
+ /* calculate elapsed time */
+ this->elapsed = timestamp - self->start;
+ self->start = 0;
+ this->cpu = vtimestamp - self->vstart;
+ self->vstart = 0;
+ self->code = errno == 0 ? "" : "Err#";
+
+ /* print optional fields */
+ OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
+ OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
+ OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
+ OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
+
+ /* print main data */
+ printf("%s(0x%X, 0x%X, 0x%X)\t\t = %d %s%d\n", probefunc, self->arg0,
+ self->arg1, self->arg2, (int)arg0, self->code, (int)errno);
+ OPT_stack ? ustack() : 1;
+ OPT_stack ? trace("\n") : 1;
+ self->arg0 = 0;
+ self->arg1 = 0;
+ self->arg2 = 0;
+}
+
+/* program exited */
+proc:::exit
+/(OPT_command || OPT_pid) && pid == $target/
+{
+ exit(0);
+}
+
+/* print counts */
+dtrace:::END
+{
+ OPT_counts == 1 ? printf("\n%-32s %16s\n", "CALL", "COUNT") : 1;
+ OPT_counts == 1 ? printa("%-32s %@16d\n", @Counts) : 1;
+}
+'
+
+### Run DTrace
+if [ $opt_command -eq 1 ]; then
+ /usr/sbin/dtrace -x dynvarsize=$buf -x evaltime=exec -n "$dtrace" \
+ -c "$command" >&2
+elif [ $opt_pid -eq 1 ]; then
+ /usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" -p "$pid" >&2
+else
+ /usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" >&2
+fi