Home | History | Annotate | Line # | Download | only in Bin
      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