#!/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.
#
# $Id: dapptrace,v 1.1.1.1 2015/09/30 22:01:07 christos Exp $
#
# 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.
# 17-Jul-2005 " " Last update.
#
##############################
# --- 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