cddl/contrib/dtracetoolkit/Proc/dapptrace

   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 65 2007-10-04 11:09:40Z brendan $
  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