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