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:09 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 66opt_pid=0; pid=0; opt_indent=0; opt_lib=0; lib="" 67opt_elapsed=0; opt_cpu=0; opt_counts=0; 68opt_relative=0; opt_printid=0; opt_liball=0 69opt_command=0; command=""; opt_buf=0; buf="4m" 70 71### Process options 72while getopts ab:cdeFhlop:u:U name 73do 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 109done 110shift `expr $OPTIND - 1` 111 112### Option logic 113if [ $opt_pid -eq 0 ]; then 114 opt_command=1 115 if [ "$*" = "" ]; then 116 $0 -h 117 exit 118 fi 119 command="$*" 120fi 121 122### Probe logic 123if [ $opt_liball -eq 1 ]; then 124 probe_entry='pid$target:::entry' 125 probe_return='pid$target:::return' 126elif [ $opt_lib -eq 1 ]; then 127 probe_entry='pid$target:'$lib'::entry' 128 probe_return='pid$target:'$lib'::return' 129else 130 probe_entry='pid$target:a.out::entry' 131 probe_return='pid$target:a.out::return' 132fi 133 134################################# 135# --- Main Program, DTrace --- 136# 137 138### Define D Script 139dtrace=' 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 253if [ $opt_command -eq 1 ]; then 254 /usr/sbin/dtrace -x dynvarsize=$buf -x evaltime=exec -n "$dtrace" \ 255 -c "$command" >&2 256else 257 /usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" -p "$pid" >&2 258fi 259 260