1 #!/usr/bin/sh 2 # 3 # dappprof - profile 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: dappprof,v 1.1.1.1 2015/09/30 22:01:07 christos Exp $ 10 # 11 # USAGE: dappprof [-acehoTU] [-u lib] { -p PID | command } 12 # 13 # -p PID # examine this PID 14 # -a # print all details 15 # -c # print call counts 16 # -e # print elapsed times (us) 17 # -o # print on cpu times (us) 18 # -T # print totals 19 # -u lib # trace this library instead 20 # -U # trace all libraries + user functions 21 # -b bufsize # dynamic variable buf size (default is "4m") 22 # eg, 23 # dappprof df -h # run and examine the "df -h" command 24 # dappprof -p 1871 # examine PID 1871 25 # 26 # The elapsed times are interesting, to help identify calls that take 27 # some time to complete (during which the process may have context 28 # switched off the CPU). 29 # 30 # SEE ALSO: dapptrace # DTraceToolkit 31 # dtruss # DTraceToolkit 32 # apptrace 33 # 34 # COPYRIGHT: Copyright (c) 2005 Brendan Gregg. 35 # 36 # CDDL HEADER START 37 # 38 # The contents of this file are subject to the terms of the 39 # Common Development and Distribution License, Version 1.0 only 40 # (the "License"). You may not use this file except in compliance 41 # with the License. 42 # 43 # You can obtain a copy of the license at Docs/cddl1.txt 44 # or http://www.opensolaris.org/os/licensing. 45 # See the License for the specific language governing permissions 46 # and limitations under the License. 47 # 48 # CDDL HEADER END 49 # 50 # Author: Brendan Gregg [Sydney, Australia] 51 # 52 # 16-May-2005 Brendan Gregg Created this. 53 # 17-Jul-2005 " " Last update. 54 # 55 56 57 ############################## 58 # --- Process Arguments --- 59 # 60 61 ### Default variables 62 opt_totals=0; opt_pid=0; pid=0; opt_lib=0; lib="" 63 opt_elapsed=0; opt_cpu=0; opt_counts=0; opt_liball=0 64 opt_command=0; command=""; opt_buf=0; buf="4m" 65 66 ### Process options 67 while getopts ab:cehop:Tu:U name 68 do 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 99 done 100 shift `expr $OPTIND - 1` 101 102 ### Option logic 103 if [ $opt_pid -eq 0 ]; then 104 opt_command=1 105 if [ "$*" = "" ]; then 106 $0 -h 107 exit 108 fi 109 command="$*" 110 fi 111 if [ $opt_elapsed -eq 0 -a $opt_cpu -eq 0 -a $opt_counts -eq 0 ]; then 112 opt_elapsed=1; 113 fi 114 115 116 ### Probe logic 117 if [ $opt_liball -eq 1 ]; then 118 probe_entry='pid$target:::entry' 119 probe_return='pid$target:::return' 120 elif [ $opt_lib -eq 1 ]; then 121 probe_entry='pid$target:'$lib'::entry' 122 probe_return='pid$target:'$lib'::return' 123 else 124 probe_entry='pid$target:a.out::entry' 125 probe_return='pid$target:a.out::return' 126 fi 127 128 ################################# 129 # --- Main Program, DTrace --- 130 # 131 132 ### Define D Script 133 dtrace=' 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("Tracing... Hit Ctrl-C to end...\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 233 if [ $opt_command -eq 1 ]; then 234 /usr/sbin/dtrace -x dynvarsize=$buf -x evaltime=exec -n "$dtrace" \ 235 -c "$command" >&2 236 else 237 /usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" -p "$pid" >&2 238 fi 239 240