1#!/bin/sh
2# #!/usr/bin/sh
3#
4# dappprof - profile 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-Jul-2005, ver 0.62         (early release! check for newer versions)
11#
12# USAGE: dappprof [-acehoTU] [-u lib] { -p PID | command }
13#
14#          -p PID          # examine this PID
15#          -a              # print all details
16#          -c              # print call counts
17#          -e              # print elapsed times (us)
18#          -o              # print on cpu times (us)
19#          -T              # print totals
20#          -u lib          # trace this library instead
21#          -U              # trace all libraries + user functions
22#          -b bufsize      # dynamic variable buf size (default is "4m")
23#  eg,
24#       dappprof df -h       # run and examine the "df -h" command
25#       dappprof -p 1871     # examine PID 1871
26#
27# The elapsed times are interesting, to help identify calls that take
28#  some time to complete (during which the process may have context
29#  switched off the CPU). 
30#
31# SEE ALSO: dapptrace      # DTraceToolkit
32#           dtruss         # DTraceToolkit
33#           apptrace           
34#
35# COPYRIGHT: Copyright (c) 2005 Brendan Gregg.
36#
37# CDDL HEADER START
38#
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
42#  with the License.
43#
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.
48#
49# CDDL HEADER END
50#
51# Author: Brendan Gregg  [Sydney, Australia]
52#
53# 16-May-2005   Brendan Gregg   Created this.
54#
55
56
57##############################
58# --- Process Arguments ---
59#
60
61### Default variables
62opt_totals=0; opt_pid=0; pid=0; opt_lib=0; lib=""
63opt_elapsed=0; opt_cpu=0; opt_counts=0; opt_liball=0
64opt_command=0; command=""; opt_buf=0; buf="4m"
65
66### Process options
67while getopts ab:cehop:Tu:U name
68do
69        case $name in
70        a)      opt_liball=1; opt_counts=1; opt_elapsed=1; opt_cpu=1 
71		opt_totals=1 ;;
72	b)	opt_buf=1; buf=$OPTARG ;;
73        p)      opt_pid=1; pid=$OPTARG ;;
74        u)      opt_lib=1; lib=$OPTARG ;;
75        U)      opt_liball=1 ;; 
76	c)	opt_counts=1 ;;
77	e)	opt_elapsed=1 ;;
78	o)	opt_cpu=1 ;;
79	T)	opt_totals=1 ;;
80        h|?)    cat <<-END >&2
81		USAGE: dappprof [-cehoTU] [-u lib] { -p PID | command }
82
83		          -p PID          # examine this PID
84		          -a              # print all details
85		          -c              # print syscall counts
86		          -e              # print elapsed times (us)
87		          -o              # print on cpu times
88		          -T              # print totals
89		          -u lib          # trace this library instead
90		          -U              # trace all libraries + user funcs
91		          -b bufsize      # dynamic variable buf size
92		   eg,
93		       dappprof df -h       # run and examine "df -h"
94		       dappprof -p 1871     # examine PID 1871
95		       dappprof -ap 1871    # print all data
96		END
97		exit 1
98        esac
99done
100shift `expr $OPTIND - 1`
101
102### Option logic
103if [ $opt_pid -eq 0 ]; then
104	opt_command=1
105	if [ "$*" = "" ]; then
106		$0 -h
107		exit
108	fi
109	command="$*"
110fi
111if [ $opt_elapsed -eq 0 -a $opt_cpu -eq 0 -a $opt_counts -eq 0 ]; then
112        opt_elapsed=1;
113fi
114
115
116### Probe logic
117if [ $opt_liball -eq 1 ]; then
118	probe_entry='pid$target:::entry'
119	probe_return='pid$target:::return'
120elif [ $opt_lib -eq 1 ]; then
121	probe_entry='pid$target:'$lib'::entry'
122	probe_return='pid$target:'$lib'::return'
123else
124 	probe_entry='pid$target:a.out::entry'
125 	probe_return='pid$target:a.out::return'
126fi
127
128#################################
129# --- Main Program, DTrace ---
130#
131
132### Define D Script
133dtrace='
134 #pragma D option quiet
135
136 /*
137  * Command line arguments
138  */
139 inline int OPT_command   = '$opt_command';
140 inline int OPT_liball    = '$opt_liball';
141 inline int OPT_elapsed   = '$opt_elapsed';
142 inline int OPT_cpu       = '$opt_cpu';
143 inline int OPT_counts    = '$opt_counts';
144 inline int OPT_totals    = '$opt_totals';
145 inline int OPT_pid       = '$opt_pid';
146 inline int PID           = '$pid';
147 inline string NAME       = "'$pname'";
148
149 dtrace:::BEGIN 
150 /! OPT_command/
151 {
152	printf("Hit Ctrl-C to stop sampling...\n");
153 }
154
155 /*
156  * Save syscall entry info
157  */
158 '$probe_entry'
159 {
160        /* set function depth */
161        this->fdepth = ++fdepth[probefunc];
162
163	/* set start details */
164	self->start[probefunc,this->fdepth] = timestamp;
165	self->vstart[probefunc,this->fdepth] = vtimestamp;
166
167	/* count occurances */
168	OPT_counts && OPT_liball ? @Counts[probemod,probefunc] = count() : 1;
169	OPT_counts && ! OPT_liball ? @Counts[probefunc] = count() : 1;
170	OPT_counts && OPT_totals && OPT_liball ? 
171	    @Counts["TOTAL:",""] = count() : 1;
172	OPT_counts && OPT_totals && ! OPT_liball ? 
173	    @Counts["TOTAL:"] = count() : 1;
174 }
175
176 /*
177  * Print return data
178  */
179 /* print 3 arg output - default */
180 '$probe_return'
181 /self->start[probefunc,fdepth[probefunc]]/
182 {
183        /* fetch function depth */
184        this->fdepth = fdepth[probefunc];
185
186	/* calculate elapsed time */
187	this->elapsed = timestamp - self->start[probefunc,this->fdepth];
188	self->start[probefunc,this->fdepth] = 0;
189	this->cpu = vtimestamp - self->vstart[probefunc,this->fdepth];
190	self->vstart[probefunc,this->fdepth] = 0;
191
192	/* save elapsed times */
193	OPT_elapsed && OPT_liball ? 
194	    @Elapsed[probemod,probefunc] = sum(this->elapsed) : 1;
195	OPT_elapsed && ! OPT_liball ? 
196	    @Elapsed[probefunc] = sum(this->elapsed) : 1;
197	OPT_elapsed && OPT_totals && OPT_liball ? 
198	    @Elapsed["TOTAL:",""] = sum(this->elapsed) : 1;
199	OPT_elapsed && OPT_totals && ! OPT_liball ? 
200	    @Elapsed["TOTAL:"] = sum(this->elapsed) : 1;
201
202	/* save cpu times */
203	OPT_cpu && OPT_liball ? @CPU[probemod,probefunc] = sum(this->cpu) : 1;
204	OPT_cpu && ! OPT_liball ? @CPU[probefunc] = sum(this->cpu) : 1;
205	OPT_cpu && OPT_totals && OPT_liball ? 
206	    @CPU["TOTAL:",""] = sum(this->cpu) : 1;
207	OPT_cpu && OPT_totals && ! OPT_liball ? 
208	    @CPU["TOTAL:"] = sum(this->cpu) : 1;
209	
210 }
211
212 /* print counts */
213 dtrace:::END
214 {
215	/* print counts */
216	OPT_counts ? printf("\n%-49s %16s\n","CALL","COUNT") : 1;
217	OPT_counts && OPT_liball ? printa("%-16s %-32s %@16d\n",@Counts) : 1;
218	OPT_counts && ! OPT_liball ? printa("%-49s %@16d\n",@Counts) : 1;
219
220	/* print elapsed times */
221	OPT_elapsed ? printf("\n%-49s %16s\n","CALL","ELAPSED") : 1;
222	OPT_elapsed && OPT_liball ? printa("%-16s %-32s %@16d\n",@Elapsed) : 1;
223	OPT_elapsed && ! OPT_liball ? printa("%-49s %@16d\n",@Elapsed) : 1;
224
225	/* print cpu times */
226	OPT_cpu ? printf("\n%-49s %16s\n","CALL","CPU") : 1;
227	OPT_cpu && OPT_liball ? printa("%-16s %-32s %@16d\n",@CPU) : 1;
228	OPT_cpu && ! OPT_liball ? printa("%-49s %@16d\n",@CPU) : 1;
229 }
230'
231
232### Run DTrace
233if [ $opt_command -eq 1 ]; then
234	/usr/sbin/dtrace -x dynvarsize=$buf -x evaltime=exec -n "$dtrace" \
235	    -c "$command" >&2
236else
237	/usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" -p "$pid" >&2
238fi
239
240