cddl/contrib/dtracetoolkit/Proc/dappprof

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