#!/usr/bin/sh
#
# pfilestat
#
# This prints I/O statistics for each file descriptor within a process.
# In particular, the time break down during read() and write() events is
# measured.
#
# $Id: pfilestat 4 2007-08-01 11:01:38Z brendan $
#
# USAGE: pfilestat [-r|-w] pid
#
# FIELDS:
# STATE microstate: running, sleeping, waitcpu, read, write
# FDUM File Descriptor ID
# Time Percentage of wallclock time in each STATE
# File Name of file, if known
#
# COPYRIGHT: Copyright (c) 2006 Richard McDougall.
#
# 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
#
# ToDo:
# Trace readv() and writev().
#
# 20-Feb-2006 Richard McDougall created this.
# 24-Feb-2006 Brendan Gregg tweaked code.
# 20-Mar-2006 " " tweaked code.
# 20-Mar-2006 " " last update.
##############################
# --- Process Arguments ---
#
### Default variables
opt_read=0; opt_write=0
### Process options
while getopts hrw name
do
case $name in
r) opt_read=1 ;;
w) opt_write=1 ;;
h|?) cat <<-END >&2
USAGE: pfilestat [-r|-w] pid
-r # reads only
-w # writes only
eg,
pfilestat pid # default, r+w counts
pfilestat -r pid # read count only
END
exit 1
esac
done
shift `expr $OPTIND - 1`
PID=$1
clearstr=`clear`
if [ -z "$PID" ]
then
echo "Must supply pid"
exit 1
fi
### Option logic
if [ $opt_read -eq 0 -a $opt_write -eq 0 ]; then
opt_read=1; opt_write=1
fi
#################################
# --- Main Program, DTrace ---
#
/usr/sbin/dtrace -n '
#pragma D option quiet
inline string CLEAR = "'$clearstr'";
inline int OPT_read = '$opt_read';
inline int OPT_write = '$opt_write';
inline int PID = '$PID';
unsigned long long totaltime;
unsigned long long totalbytes;
enum runstate {
READ,
WRITE,
OTHER
};
/* print header */
dtrace:::BEGIN
{
printf("Tracing ");
OPT_read && OPT_write ? printf("reads and writes") : 1;
OPT_read && ! OPT_write ? printf("reads") : 1;
! OPT_read && OPT_write ? printf("writes") : 1;
printf("...");
totaltime = 0;
totalbytes = 0;
last = timestamp;
stamp = timestamp;
}
/* sample reads */
syscall::read:entry,
syscall::pread*:entry
/pid == PID && OPT_read/
{
runstate = READ;
@logical["running", (uint64_t)0, ""] = sum(timestamp - last);
totaltime += timestamp - last;
last = timestamp;
self->fd = arg0 + 1;
}
fbt::fop_read:entry,
fbt::fop_write:entry
/self->fd/
{
self->path = args[0]->v_path == 0 ? "<none>" :
cleanpath(args[0]->v_path);
}
syscall::read:return,
syscall::pread*:return
/pid == PID && OPT_read/
{
runstate = OTHER;
this->bytes = (int)arg0 > 0 ? (int)arg0 : 0;
@logical["read", self->fd - 1, self->path] = sum(timestamp - last);
@bytes["read", self->fd - 1, self->path] = sum(this->bytes);
totalbytes += this->bytes;
totaltime += timestamp - last;
last = timestamp;
self->path = 0;
self->fd = 0;
}
/* sample writes */
syscall::write:entry,
syscall::pwrite*:entry
/pid == PID && OPT_write/
{
runstate = WRITE;
@logical["running", (uint64_t)0, ""] = sum(timestamp - last);
totaltime += timestamp - last;
last = timestamp;
self->fd = (int)arg0 + 1;
}
syscall::write:return,
syscall::pwrite*:return
/pid == PID && OPT_write/
{
runstate = OTHER;
this->bytes = (int)arg0 > 0 ? (int)arg0 : 0;
@logical["write", self->fd - 1, self->path] = sum(timestamp - last);
@bytes["write", self->fd - 1, self->path] = sum(this->bytes);
totalbytes += this->bytes;
totaltime += timestamp - last;
last = timestamp;
self->path = 0;
self->fd = 0;
}
sched:::on-cpu
/pid == PID/
{
@logical["waitcpu", (uint64_t)0, ""] = sum(timestamp - last);
totaltime += timestamp - last;
last = timestamp;
}
sched:::off-cpu
/pid == PID/
{
@logical["running", (uint64_t)0, ""] = sum(timestamp - last);
totaltime += timestamp - last;
last = timestamp;
}
sched:::sleep
/pid == PID/
{
@logical["running", (uint64_t)0, ""] = sum(timestamp - last);
totaltime += timestamp - last;
last = timestamp;
}
sched:::wakeup
/args[1]->pr_pid == PID && runstate == OTHER/
{
@logical["sleep", (uint64_t)0, ""] = sum(timestamp - last);
totaltime += timestamp - last;
last = timestamp;
}
sched:::wakeup
/args[1]->pr_pid == PID && runstate == READ/
{
@logical["sleep-r", (uint64_t)0, ""] = sum(timestamp - last);
totaltime += timestamp - last;
last = timestamp;
}
sched:::wakeup
/args[1]->pr_pid == PID && runstate == WRITE/
{
@logical["sleep-w", (uint64_t)0, ""] = sum(timestamp - last);
totaltime += timestamp - last;
last = timestamp;
}
sched:::enqueue
/args[1]->pr_pid == PID/
{
@logical["waitcpu", (uint64_t)0, ""] = sum(timestamp - last);
totaltime += timestamp - last;
last = timestamp;
}
sched:::dequeue
/args[1]->pr_pid == PID/
{
@logical["waitcpu", (uint64_t)0, ""] = sum(timestamp - last);
totaltime += timestamp - last;
last = timestamp;
}
/* print report */
profile:::tick-5s
{
printf("%s", CLEAR);
normalize(@logical, totaltime / 100);
trunc(@logical, 10);
printf("%10s %7s %9s %-44s\n", "STATE", "FDNUM", "Time", "Filename");
printa("%10s %7d %@8d%% %-44.44s\n", @logical);
trunc(@logical);
delta = timestamp - stamp;
stamp = timestamp;
normalize(@bytes, (1024 * delta) / 1000000000);
trunc(@bytes, 10);
printf("\n%10s %7s %9s %-44s\n", "STATE", "FDNUM", "KB/s",
"Filename");
printa("%10s %7d %@9d %-44.44s\n", @bytes);
trunc(@bytes);
printf("\nTotal event time (ms): %d Total Mbytes/sec: %d\n",
totaltime / 1000000,
(totalbytes * 1000000000) / (delta * 1048576));
totaltime = 0;
totalbytes = 0;
last = timestamp;
}
dtrace:::END
{
trunc(@logical);
trunc(@bytes);
}
'