3 # dtruss - print process system call time details.
4 # Written using DTrace (Solaris 10 3/05).
6 # $Id: dtruss 9 2007-08-07 10:21:07Z brendan $
8 # USAGE: dtruss [-acdeflhoLs] [-t syscall] { -p PID | -n name | command }
10 # -p PID # examine this PID
11 # -n name # examine this process name
12 # -t syscall # examine this syscall only
13 # -a # print all details
14 # -c # print system call counts
15 # -d # print relative timestamps (us)
16 # -e # print elapsed times (us)
17 # -f # follow children as they are forked
18 # -l # force printing of pid/lwpid per line
19 # -o # print on cpu times (us)
20 # -s # print stack backtraces
21 # -L # don't print pid/lwpid per line
22 # -b bufsize # dynamic variable buf size (default is "4m")
24 # dtruss df -h # run and examine the "df -h" command
25 # dtruss -p 1871 # examine PID 1871
26 # dtruss -n tar # examine all processes called "tar"
27 # dtruss -f test.sh # run test.sh and follow children
29 # See the man page dtruss(1M) for further details.
31 # SEE ALSO: procsystime # DTraceToolkit
32 # dapptrace # DTraceToolkit
35 # COPYRIGHT: Copyright (c) 2005, 2006, 2007 Brendan Gregg.
39 # The contents of this file are subject to the terms of the
40 # Common Development and Distribution License, Version 1.0 only
41 # (the "License"). You may not use this file except in compliance
44 # You can obtain a copy of the license at Docs/cddl1.txt
45 # or http://www.opensolaris.org/os/licensing.
46 # See the License for the specific language governing permissions
47 # and limitations under the License.
51 # TODO: Track signals, more output formatting.
53 # 29-Apr-2005 Brendan Gregg Created this.
54 # 09-May-2005 " " Fixed evaltime (thanks Adam L.)
55 # 16-May-2005 " " Added -t syscall tracing.
56 # 17-Jun-2005 " " Added -s stack backtraces.
57 # 17-Jun-2005 " " Last update.
58 # 29-Jun-2007 " " Used progenyof() (thanks Aaron Gutman).
59 # 06-Aug-2007 " " Various updates.
63 ##############################
64 # --- Process Arguments ---
68 opt_pid=0; opt_name=0; pid=0; pname="."; opt_elapsed=0; opt_cpu=0
69 opt_counts=0; opt_relative=0; opt_printid=0; opt_follow=0; opt_command=0
70 command=""; opt_buf=0; buf="4m"; opt_trace=0; trace="."; opt_stack=0
73 while getopts ab:cdefhln:op:st:L name
76 b) opt_buf=1; buf=$OPTARG ;;
77 p) opt_pid=1; pid=$OPTARG ;;
78 n) opt_name=1; pname=$OPTARG ;;
79 t) opt_trace=1; trace=$OPTARG ;;
80 a) opt_counts=1; opt_relative=1; opt_elapsed=1; opt_follow=1
81 opt_printid=1; opt_cpu=1 ;;
91 USAGE: dtruss [-acdefholLs] [-t syscall] { -p PID | -n name | command }
93 -p PID # examine this PID
94 -n name # examine this process name
95 -t syscall # examine this syscall only
96 -a # print all details
97 -c # print syscall counts
98 -d # print relative times (us)
99 -e # print elapsed times (us)
100 -f # follow children (-p or cmd only)
101 -l # force printing pid/lwpid
102 -o # print on cpu times
103 -s # print stack backtraces
104 -L # don't print pid/lwpid
105 -b bufsize # dynamic variable buf size
107 dtruss df -h # run and examine "df -h"
108 dtruss -p 1871 # examine PID 1871
109 dtruss -n tar # examine all processes called "tar"
110 dtruss -f test.sh # run test.sh and follow children
115 shift `expr $OPTIND - 1`
118 if [ $opt_pid -eq 0 -a $opt_name -eq 0 ]; then
120 if [ "$*" = "" ]; then
124 command="$*" # yes, I meant $*!
126 if [ $opt_follow -eq 1 -o $opt_name -eq 1 ]; then
127 if [ $opt_printid -ne -1 ]; then
133 if [ $opt_follow -eq 1 -a $opt_name -eq 1 ]; then
134 echo "ERROR: -f option cannot be used with -n (use -p or cmd instead)."
138 ### Option translation
139 if [ "$trace" = "exec" ]; then trace="exece"; fi
140 if [ "$trace" = "time" ]; then trace="gtime"; fi
141 if [ "$trace" = "exit" ]; then trace="rexit"; fi
144 #################################
145 # --- Main Program, DTrace ---
150 #pragma D option quiet
151 #pragma D option switchrate=10
154 * Command line arguments
156 inline int OPT_command = '$opt_command';
157 inline int OPT_follow = '$opt_follow';
158 inline int OPT_printid = '$opt_printid';
159 inline int OPT_relative = '$opt_relative';
160 inline int OPT_elapsed = '$opt_elapsed';
161 inline int OPT_cpu = '$opt_cpu';
162 inline int OPT_counts = '$opt_counts';
163 inline int OPT_pid = '$opt_pid';
164 inline int OPT_name = '$opt_name';
165 inline int OPT_trace = '$opt_trace';
166 inline int OPT_stack = '$opt_stack';
167 inline string NAME = "'$pname'";
168 inline string TRACE = "'$trace'";
173 OPT_printid ? printf("%-9s ", "PID/LWP") : 1;
174 OPT_relative ? printf("%8s ", "RELATIVE") : 1;
175 OPT_elapsed ? printf("%7s ", "ELAPSD") : 1;
176 OPT_cpu ? printf("%6s ", "CPU") : 1;
177 printf("SYSCALL(args) \t\t = return\n");
181 * Save syscall entry info
184 /((OPT_command || OPT_pid) && pid == $target) ||
185 (OPT_name && execname == NAME) ||
186 (OPT_follow && progenyof($target))/
188 /* set start details */
189 self->start = timestamp;
190 self->vstart = vtimestamp;
195 /* count occurances */
196 OPT_counts == 1 ? @Counts[probefunc] = count() : 1;
202 syscall::fork*:return
203 /(OPT_follow && progenyof($target)) && (!OPT_trace || (TRACE == probefunc))/
206 self->code = errno == 0 ? "" : "Err#";
207 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
208 OPT_relative ? printf("%8d: ", vtimestamp/1000) : 1;
209 OPT_elapsed ? printf("%7d: ", 0) : 1;
210 OPT_cpu ? printf("%6d ", 0) : 1;
211 printf("%s(0x%X, 0x%X, 0x%X)\t\t = %d %s%d\n", probefunc,
212 self->arg0, self->arg1, self->arg2, (int)arg0, self->code,
217 * Check for syscall tracing
220 /OPT_trace && probefunc != TRACE/
235 * The following code is written in an intentionally repetative way.
236 * The first versions had no code redundancies, but performed badly during
237 * benchmarking. The priority here is speed, not cleverness. I know there
238 * are many obvious shortcuts to this code, I have tried them. This style has
239 * shown in benchmarks to be the fastest (fewest probes fired, fewest actions).
242 /* print 3 args, return as hex */
243 syscall::lwp_sigmask:return
246 /* calculate elapsed time */
247 this->elapsed = timestamp - self->start;
249 this->cpu = vtimestamp - self->vstart;
251 self->code = errno == 0 ? "" : "Err#";
253 /* print optional fields */
254 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
255 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
256 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
257 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
259 /* print main data */
260 printf("%s(0x%X, 0x%X, 0x%X)\t\t = 0x%X %s%d\n", probefunc,
261 (int)self->arg0, self->arg1, self->arg2, (int)arg0,
262 self->code, (int)errno);
263 OPT_stack ? ustack() : 1;
264 OPT_stack ? trace("\n") : 1;
270 /* print 3 args, arg0 as a string */
271 syscall::stat*:return,
272 syscall::lstat*:return,
273 syscall::open*:return,
274 syscall::resolvepath:return
277 /* calculate elapsed time */
278 this->elapsed = timestamp - self->start;
280 this->cpu = vtimestamp - self->vstart;
282 self->code = errno == 0 ? "" : "Err#";
284 /* print optional fields */
285 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
286 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
287 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
288 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
290 /* print main data */
291 printf("%s(\"%S\", 0x%X, 0x%X)\t\t = %d %s%d\n", probefunc,
292 copyinstr(self->arg0), self->arg1, self->arg2, (int)arg0,
293 self->code, (int)errno);
294 OPT_stack ? ustack() : 1;
295 OPT_stack ? trace("\n") : 1;
301 /* print 3 args, arg1 as a string */
302 syscall::write:return,
303 syscall::pwrite:return,
304 syscall::*read*:return
307 /* calculate elapsed time */
308 this->elapsed = timestamp - self->start;
310 this->cpu = vtimestamp - self->vstart;
312 self->code = errno == 0 ? "" : "Err#";
314 /* print optional fields */
315 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
316 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
317 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
318 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
320 /* print main data */
321 printf("%s(0x%X, \"%S\", 0x%X)\t\t = %d %s%d\n", probefunc, self->arg0,
322 stringof(copyin(self->arg1, self->arg2)), self->arg2, (int)arg0,
323 self->code, (int)errno);
324 OPT_stack ? ustack() : 1;
325 OPT_stack ? trace("\n") : 1;
331 /* print 0 arg output */
332 syscall::gtime:return,
333 syscall::*fork*:return
336 /* calculate elapsed time */
337 this->elapsed = timestamp - self->start;
339 this->cpu = vtimestamp - self->vstart;
341 self->code = errno == 0 ? "" : "Err#";
343 /* print optional fields */
344 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
345 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
346 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
347 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
349 /* print main data */
350 printf("%s()\t\t = %d %s%d\n", probefunc,
351 (int)arg0, self->code, (int)errno);
352 OPT_stack ? ustack() : 1;
353 OPT_stack ? trace("\n") : 1;
359 /* print 1 arg output */
361 syscall::times:return,
362 syscall::stime:return,
363 syscall::close:return
366 /* calculate elapsed time */
367 this->elapsed = timestamp - self->start;
369 this->cpu = vtimestamp - self->vstart;
371 self->code = errno == 0 ? "" : "Err#";
373 /* print optional fields */
374 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
375 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
376 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
377 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
379 /* print main data */
380 printf("%s(0x%X)\t\t = %d %s%d\n", probefunc, self->arg0,
381 (int)arg0, self->code, (int)errno);
382 OPT_stack ? ustack() : 1;
383 OPT_stack ? trace("\n") : 1;
389 /* print 2 arg output */
390 syscall::utime:return,
391 syscall::munmap:return
394 /* calculate elapsed time */
395 this->elapsed = timestamp - self->start;
397 this->cpu = vtimestamp - self->vstart;
399 self->code = errno == 0 ? "" : "Err#";
401 /* print optional fields */
402 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
403 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
404 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
405 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
407 /* print main data */
408 printf("%s(0x%X, 0x%X)\t\t = %d %s%d\n", probefunc, self->arg0,
409 self->arg1, (int)arg0, self->code, (int)errno);
410 OPT_stack ? ustack() : 1;
411 OPT_stack ? trace("\n") : 1;
417 /* print 3 arg output - default */
421 /* calculate elapsed time */
422 this->elapsed = timestamp - self->start;
424 this->cpu = vtimestamp - self->vstart;
426 self->code = errno == 0 ? "" : "Err#";
428 /* print optional fields */
429 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1;
430 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1;
431 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1;
432 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1;
434 /* print main data */
435 printf("%s(0x%X, 0x%X, 0x%X)\t\t = %d %s%d\n", probefunc, self->arg0,
436 self->arg1, self->arg2, (int)arg0, self->code, (int)errno);
437 OPT_stack ? ustack() : 1;
438 OPT_stack ? trace("\n") : 1;
446 /(OPT_command || OPT_pid) && pid == $target/
454 OPT_counts == 1 ? printf("\n%-32s %16s\n", "CALL", "COUNT") : 1;
455 OPT_counts == 1 ? printa("%-32s %@16d\n", @Counts) : 1;
460 if [ $opt_command -eq 1 ]; then
461 /usr/sbin/dtrace -x dynvarsize=$buf -x evaltime=exec -n "$dtrace" \
463 elif [ $opt_pid -eq 1 ]; then
464 /usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" -p "$pid" >&2
466 /usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" >&2