#!/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. # # 20-Mar-2006, ver 0.50 # # 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. ############################## # --- 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("Sampling "); 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 ? "" : 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); } '