#!/usr/bin/sh # # dapptrace - trace user and library function usage. # Written using DTrace (Solaris 10 3/05). # # The default output traces user functions as they are called. Options # can be used to examine libraries and timestamps. # # 17-Jun-2005, ver 0.61 (early release! check for newer versions) # # USAGE: dapptrace [-acdeFlhoU] [-u lib] { -p PID | command } # # -p PID # examine this PID # -a # print all details # -c # print call counts # -d # print relative timestamps (us) # -e # print elapsed times (us) # -F # print flow indentation # -l # print pid/lwpid per line # -o # print on cpu times (us) # -u lib # trace this library instead # -U # trace all libraries + user functions # -b bufsize # dynamic variable buf size (default is "4m") # eg, # dapptrace df -h # run and examine the "df -h" command # dapptrace -p 1871 # examine PID 1871 # dapptrace -Fp 1871 # print using flow indents # dapptrace -eop 1871 # print elapsed and CPU times # # The elapsed times are interesting, to help identify calls that take # some time to complete (during which the process may have context # switched off the CPU). # # SEE ALSO: dappprof # DTraceToolkit # dtruss # DTraceToolkit # apptrace # # COPYRIGHT: Copyright (c) 2005 Brendan Gregg. # # CDDL HEADER START # # The contents of this file are subject to the terms of the # Common Development and Distribution License, Version 1.0 only # (the "License"). You may not use this file except in compliance # with the License. # # You can obtain a copy of the license at Docs/cddl1.txt # or http://www.opensolaris.org/os/licensing. # See the License for the specific language governing permissions # and limitations under the License. # # CDDL HEADER END # # Author: Brendan Gregg [Sydney, Australia] # # 16-May-2005 Brendan Gregg Created this. # ############################## # --- Process Arguments --- # ### Default variables opt_pid=0; pid=0; opt_indent=0; opt_lib=0; lib="" opt_elapsed=0; opt_cpu=0; opt_counts=0; opt_relative=0; opt_printid=0; opt_liball=0 opt_command=0; command=""; opt_buf=0; buf="4m" ### Process options while getopts ab:cdeFhlop:u:U name do case $name in a) opt_liball=1; opt_counts=1; opt_relative=1; opt_elapsed=1 opt_indent=1; opt_printid=1; opt_cpu=1 ;; b) opt_buf=1; buf=$OPTARG ;; p) opt_pid=1; pid=$OPTARG ;; u) opt_lib=1; lib=$OPTARG ;; U) opt_liball=1 ;; c) opt_counts=1 ;; d) opt_relative=1 ;; e) opt_elapsed=1 ;; F) opt_indent=1 ;; l) opt_printid=1 ;; o) opt_cpu=1 ;; h|?) cat <<-END >&2 USAGE: dapptrace [-acdeholFLU] [-u lib] { -p PID | command } -p PID # examine this PID -a # print all details -c # print syscall counts -d # print relative times (us) -e # print elapsed times (us) -F # print flow indentation -l # print pid/lwpid -o # print CPU on cpu times -u lib # trace this library instead -U # trace all libraries + user funcs -b bufsize # dynamic variable buf size eg, dapptrace df -h # run and examine "df -h" dapptrace -p 1871 # examine PID 1871 dapptrace -Fp 1871 # print using flow indents dapptrace -eop 1871 # print elapsed and CPU times END exit 1 esac done shift `expr $OPTIND - 1` ### Option logic if [ $opt_pid -eq 0 ]; then opt_command=1 if [ "$*" = "" ]; then $0 -h exit fi command="$*" fi ### Probe logic if [ $opt_liball -eq 1 ]; then probe_entry='pid$target:::entry' probe_return='pid$target:::return' elif [ $opt_lib -eq 1 ]; then probe_entry='pid$target:'$lib'::entry' probe_return='pid$target:'$lib'::return' else probe_entry='pid$target:a.out::entry' probe_return='pid$target:a.out::return' fi ################################# # --- Main Program, DTrace --- # ### Define D Script dtrace=' #pragma D option quiet /* * Command line arguments */ inline int OPT_command = '$opt_command'; inline int OPT_liball = '$opt_liball'; inline int OPT_indent = '$opt_indent'; inline int OPT_printid = '$opt_printid'; inline int OPT_relative = '$opt_relative'; inline int OPT_elapsed = '$opt_elapsed'; inline int OPT_cpu = '$opt_cpu'; inline int OPT_counts = '$opt_counts'; inline int OPT_pid = '$opt_pid'; inline int PID = '$pid'; inline string NAME = "'$pname'"; dtrace:::BEGIN { /* print header */ OPT_printid ? printf("%-8s ","PID/LWP") : 1; OPT_relative ? printf("%8s ","RELATIVE") : 1; OPT_elapsed ? printf("%7s ","ELAPSD") : 1; OPT_cpu ? printf("%6s ","CPU") : 1; printf("CALL(args) \t\t = return\n"); /* indent depth */ depth = 0; } /* * Save syscall entry info */ '$probe_entry' { /* set function depth */ this->fdepth = ++fdepth[probefunc]; depth += 2; /* set start details */ self->start[probefunc,this->fdepth] = timestamp; self->vstart[probefunc,this->fdepth] = vtimestamp; /* count occurances */ OPT_counts && OPT_liball ? @Counts[probemod,probefunc] = count() : 1; OPT_counts && ! OPT_liball ? @Counts[probefunc] = count() : 1; /* print optional fields */ OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; OPT_elapsed ? printf(" . ") : 1; OPT_cpu ? printf(" . ") : 1; OPT_indent ? printf("%*s",depth,"") : 1; /* print main data */ printf("-> "); OPT_liball ? printf("%s:",probemod) : 1; printf("%s(0x%X, 0x%X, 0x%X)\t\t\n",probefunc,arg0,arg1,arg2); } /* * Print return data */ /* print 3 arg output - default */ '$probe_return' /self->start[probefunc,fdepth[probefunc]]/ { /* fetch function depth */ this->fdepth = fdepth[probefunc]; /* calculate elapsed time */ this->elapsed = timestamp - self->start[probefunc,this->fdepth]; self->start[probefunc,this->fdepth] = 0; this->cpu = vtimestamp - self->vstart[probefunc,this->fdepth]; self->vstart[probefunc,this->fdepth] = 0; /* print optional fields */ OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1; OPT_cpu ? printf("%6d ",this->cpu/1000) : 1; OPT_indent ? printf("%*s",depth,"") : 1; /* print main data */ printf("<- "); OPT_liball ? printf("%s:",probemod) : 1; printf("%s = %d\n",probefunc,(int)arg0); depth -= 2; fdepth[probefunc]--; } /* reset indent depth */ profile:::tick-1sec { /* * some probes generated by the pid provider have entries * but not returns. this is a klude to fix that problem. this * also explains fdepth[probefunc] rather than a single depth. */ depth = 0; } /* print counts */ dtrace:::END { OPT_counts ? printf("\n%-49s %16s\n","CALL","COUNT") : 1; OPT_counts && OPT_liball ? printa("%-16s %-32s %@16d\n",@Counts) : 1; OPT_counts && ! OPT_liball ? printa("%-49s %@16d\n",@Counts) : 1; } ' ### Run DTrace if [ $opt_command -eq 1 ]; then /usr/sbin/dtrace -x dynvarsize=$buf -x evaltime=exec -n "$dtrace" \ -c "$command" >&2 else /usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" -p "$pid" >&2 fi