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