1#!/bin/sh
2# #!/usr/bin/sh
3#
4# dapptrace - trace user and library function usage.
5#             Written using DTrace (Solaris 10 3/05).
6#
7# The default output traces user functions as they are called. Options
8#  can be used to examine libraries and timestamps.
9#
10# 17-Jun-2005, ver 0.61         (early release! check for newer versions)
11#
12# USAGE: dapptrace [-acdeFlhoU] [-u lib] { -p PID | command }
13#
14#          -p PID          # examine this PID
15#          -a              # print all details
16#          -c              # print call counts
17#          -d              # print relative timestamps (us)
18#          -e              # print elapsed times (us)
19#          -F              # print flow indentation
20#          -l              # print pid/lwpid per line
21#          -o              # print on cpu times (us)
22#          -u lib          # trace this library instead
23#          -U              # trace all libraries + user functions
24#          -b bufsize      # dynamic variable buf size (default is "4m")
25#  eg,
26#       dapptrace df -h       # run and examine the "df -h" command
27#       dapptrace -p 1871     # examine PID 1871
28#       dapptrace -Fp 1871    # print using flow indents
29#       dapptrace -eop 1871   # print elapsed and CPU times
30#
31# The elapsed times are interesting, to help identify calls that take
32#  some time to complete (during which the process may have context
33#  switched off the CPU). 
34#
35# SEE ALSO: dappprof       # DTraceToolkit
36#           dtruss         # DTraceToolkit
37#           apptrace
38#
39# COPYRIGHT: Copyright (c) 2005 Brendan Gregg.
40#
41# CDDL HEADER START
42#
43#  The contents of this file are subject to the terms of the
44#  Common Development and Distribution License, Version 1.0 only
45#  (the "License").  You may not use this file except in compliance
46#  with the License.
47#
48#  You can obtain a copy of the license at Docs/cddl1.txt
49#  or http://www.opensolaris.org/os/licensing.
50#  See the License for the specific language governing permissions
51#  and limitations under the License.
52#
53# CDDL HEADER END
54#
55# Author: Brendan Gregg  [Sydney, Australia]
56#
57# 16-May-2005   Brendan Gregg   Created this.
58#
59
60
61##############################
62# --- Process Arguments ---
63#
64
65### Default variables
66opt_pid=0; pid=0; opt_indent=0; opt_lib=0; lib=""
67opt_elapsed=0; opt_cpu=0; opt_counts=0; 
68opt_relative=0; opt_printid=0; opt_liball=0
69opt_command=0; command=""; opt_buf=0; buf="4m"
70
71### Process options
72while getopts ab:cdeFhlop:u:U name
73do
74        case $name in
75        a)      opt_liball=1; opt_counts=1; opt_relative=1; opt_elapsed=1
76		opt_indent=1; opt_printid=1; opt_cpu=1 ;; 
77	b)	opt_buf=1; buf=$OPTARG ;;
78        p)      opt_pid=1; pid=$OPTARG ;;
79        u)      opt_lib=1; lib=$OPTARG ;;
80        U)      opt_liball=1 ;; 
81	c)	opt_counts=1 ;;
82	d)	opt_relative=1 ;;
83	e)	opt_elapsed=1 ;;
84	F)	opt_indent=1 ;;
85	l)	opt_printid=1 ;;
86	o)	opt_cpu=1 ;;
87        h|?)    cat <<-END >&2
88		USAGE: dapptrace [-acdeholFLU] [-u lib] { -p PID | command }
89
90		          -p PID          # examine this PID
91		          -a              # print all details
92		          -c              # print syscall counts
93		          -d              # print relative times (us)
94		          -e              # print elapsed times (us)
95		          -F              # print flow indentation
96		          -l              # print pid/lwpid
97		          -o              # print CPU on cpu times
98		          -u lib          # trace this library instead
99		          -U              # trace all libraries + user funcs
100		          -b bufsize      # dynamic variable buf size
101		   eg,
102		       dapptrace df -h       # run and examine "df -h"
103		       dapptrace -p 1871     # examine PID 1871
104		       dapptrace -Fp 1871    # print using flow indents
105		       dapptrace -eop 1871   # print elapsed and CPU times
106		END
107		exit 1
108        esac
109done
110shift `expr $OPTIND - 1`
111
112### Option logic
113if [ $opt_pid -eq 0 ]; then
114	opt_command=1
115	if [ "$*" = "" ]; then
116		$0 -h
117		exit
118	fi
119	command="$*"
120fi
121
122### Probe logic
123if [ $opt_liball -eq 1 ]; then
124	probe_entry='pid$target:::entry'
125	probe_return='pid$target:::return'
126elif [ $opt_lib -eq 1 ]; then
127	probe_entry='pid$target:'$lib'::entry'
128	probe_return='pid$target:'$lib'::return'
129else
130 	probe_entry='pid$target:a.out::entry'
131 	probe_return='pid$target:a.out::return'
132fi
133
134#################################
135# --- Main Program, DTrace ---
136#
137
138### Define D Script
139dtrace='
140 #pragma D option quiet
141
142 /*
143  * Command line arguments
144  */
145 inline int OPT_command   = '$opt_command';
146 inline int OPT_liball    = '$opt_liball';
147 inline int OPT_indent    = '$opt_indent';
148 inline int OPT_printid   = '$opt_printid';
149 inline int OPT_relative  = '$opt_relative';
150 inline int OPT_elapsed   = '$opt_elapsed';
151 inline int OPT_cpu       = '$opt_cpu';
152 inline int OPT_counts    = '$opt_counts';
153 inline int OPT_pid       = '$opt_pid';
154 inline int PID           = '$pid';
155 inline string NAME       = "'$pname'";
156
157 dtrace:::BEGIN 
158 {
159	/* print header */
160	/* SOLARIS: OPT_printid  ? printf("%-8s  ","PID/LWP") : 1; */
161	OPT_printid  ? printf("%-8s  ","PID/THRD") : 1;
162	OPT_relative ? printf("%8s ","RELATIVE") : 1;
163	OPT_elapsed  ? printf("%7s ","ELAPSD") : 1;
164	OPT_cpu      ? printf("%6s ","CPU") : 1;
165	printf("CALL(args) \t\t = return\n");
166
167	/* indent depth */
168	depth = 0;
169 }
170
171 /*
172  * Save syscall entry info
173  */
174 '$probe_entry'
175 {
176	/* set function depth */
177	this->fdepth = ++fdepth[probefunc];
178	depth += 2;
179
180	/* set start details */
181	self->start[probefunc,this->fdepth] = timestamp;
182	self->vstart[probefunc,this->fdepth] = vtimestamp;
183
184	/* count occurances */
185	OPT_counts && OPT_liball ? @Counts[probemod,probefunc] = count() : 1;
186	OPT_counts && ! OPT_liball ? @Counts[probefunc] = count() : 1;
187
188	/* print optional fields */
189	/* SOLARIS: OPT_printid  ? printf("%5d/%d:  ",pid,tid) : 1; */
190	OPT_printid  ? printf("%5d/0x%x:  ",pid,tid) : 1;
191	OPT_relative ? printf("%8d ",vtimestamp/1000) : 1;
192	OPT_elapsed  ? printf("      . ") : 1;
193	OPT_cpu      ? printf("     . ") : 1;
194	OPT_indent   ? printf("%*s",depth,"") : 1;
195
196	/* print main data */
197	printf("-> ");
198	OPT_liball ? printf("%s:",probemod) : 1;
199	printf("%s(0x%X, 0x%X, 0x%X)\t\t\n",probefunc,arg0,arg1,arg2);
200
201 }
202
203 /*
204  * Print return data
205  */
206 /* print 3 arg output - default */
207 '$probe_return'
208 /self->start[probefunc,fdepth[probefunc]]/
209 {
210	/* fetch function depth */
211	this->fdepth = fdepth[probefunc];
212
213	/* calculate elapsed time */
214	this->elapsed = timestamp - self->start[probefunc,this->fdepth];
215	self->start[probefunc,this->fdepth] = 0;
216	this->cpu = vtimestamp - self->vstart[probefunc,this->fdepth];
217	self->vstart[probefunc,this->fdepth] = 0;
218
219	/* print optional fields */
220	/* SOLARIS: OPT_printid  ? printf("%5d/%d:  ",pid,tid) : 1; */
221	OPT_printid  ? printf("%5d/0x%x:  ",pid,tid) : 1;
222	OPT_relative ? printf("%8d ",vtimestamp/1000) : 1;
223	OPT_elapsed  ? printf("%7d ",this->elapsed/1000) : 1;
224	OPT_cpu      ? printf("%6d ",this->cpu/1000) : 1;
225	OPT_indent   ? printf("%*s",depth,"") : 1;
226
227	/* print main data */
228	printf("<- ");
229	OPT_liball ? printf("%s:",probemod) : 1;
230	printf("%s = %d\n",probefunc,(int)arg0);
231	depth -= 2;
232	fdepth[probefunc]--;
233 }
234
235 /* reset indent depth */
236 /* SOLARIS: profile:::tick-1sec */
237 profile:::tick-10Hz
238 {
239	/* 
240	 * some probes generated by the pid provider have entries
241 	 * but not returns. this is a klude to fix that problem. this
242	 * also explains fdepth[probefunc] rather than a single depth.
243	 */
244	depth = 0;
245 }
246
247 /* print counts */
248 dtrace:::END
249 {
250	OPT_counts ? printf("\n%-49s %16s\n","CALL","COUNT") : 1;
251	OPT_counts && OPT_liball ? printa("%-16s %-32s %@16d\n",@Counts) : 1;
252	OPT_counts && ! OPT_liball ? printa("%-49s %@16d\n",@Counts) : 1;
253 }
254'
255
256### Run DTrace
257if [ $opt_command -eq 1 ]; then
258	/usr/sbin/dtrace -x dynvarsize=$buf -x evaltime=exec -n "$dtrace" \
259	    -c "$command" >&2
260else
261	/usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" -p "$pid" >&2
262fi
263
264