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