Home | History | Annotate | Line # | Download | only in Proc
pfilestat revision 1.1.1.1
      1 #!/usr/bin/sh
      2 #
      3 # pfilestat
      4 #
      5 # This prints I/O statistics for each file descriptor within a process.
      6 # In particular, the time break down during read() and write() events is
      7 # measured.
      8 #
      9 # $Id: pfilestat,v 1.1.1.1 2015/09/30 22:01:09 christos Exp $
     10 #
     11 # USAGE:        pfilestat [-r|-w] pid
     12 #
     13 # FIELDS:
     14 #               STATE      microstate: running, sleeping, waitcpu, read, write
     15 #               FDUM       File Descriptor ID
     16 #               Time       Percentage of wallclock time in each STATE
     17 #               File       Name of file, if known
     18 # 
     19 # COPYRIGHT: Copyright (c) 2006 Richard McDougall.
     20 #
     21 # CDDL HEADER START
     22 #
     23 #  The contents of this file are subject to the terms of the
     24 #  Common Development and Distribution License, Version 1.0 only
     25 #  (the "License").  You may not use this file except in compliance
     26 #  with the License.
     27 #
     28 #  You can obtain a copy of the license at Docs/cddl1.txt
     29 #  or http://www.opensolaris.org/os/licensing.
     30 #  See the License for the specific language governing permissions
     31 #  and limitations under the License.
     32 #
     33 # CDDL HEADER END
     34 #
     35 # ToDo:
     36 #	Trace readv() and writev().
     37 #
     38 # 20-Feb-2006   Richard McDougall	created this.
     39 # 24-Feb-2006   Brendan Gregg		tweaked code.
     40 # 20-Mar-2006      "      " 		tweaked code.
     41 # 20-Mar-2006      "      " 		last update.
     42 
     43 
     44 ##############################
     45 # --- Process Arguments ---
     46 #
     47 
     48 ### Default variables
     49 opt_read=0; opt_write=0
     50 
     51 ### Process options
     52 while getopts hrw name
     53 do
     54 	case $name in
     55 	r)      opt_read=1 ;;
     56 	w)      opt_write=1 ;;
     57 	h|?)    cat <<-END >&2
     58 		USAGE: pfilestat [-r|-w] pid
     59 		              -r           # reads only
     60 		              -w           # writes only
     61 		  eg,
     62 		       pfilestat pid       # default, r+w counts
     63 		       pfilestat -r pid    # read count only
     64 		END
     65 		exit 1
     66 	esac
     67 done
     68 shift `expr $OPTIND - 1`
     69 
     70 PID=$1
     71 clearstr=`clear`
     72 
     73 if [ -z "$PID" ]
     74 then
     75 	echo "Must supply pid"
     76 	exit 1
     77 fi
     78 
     79 ### Option logic
     80 if [ $opt_read -eq 0 -a $opt_write -eq 0 ]; then
     81 	opt_read=1; opt_write=1
     82 fi
     83 
     84 
     85 #################################
     86 # --- Main Program, DTrace ---
     87 #
     88 /usr/sbin/dtrace -n '
     89  #pragma D option quiet
     90 
     91  inline string CLEAR   = "'$clearstr'";
     92  inline int OPT_read   = '$opt_read';
     93  inline int OPT_write  = '$opt_write';
     94  inline int PID        = '$PID';
     95 
     96  unsigned long long totaltime;
     97  unsigned long long totalbytes;
     98 
     99  enum runstate {
    100 	READ,
    101 	WRITE,
    102 	OTHER
    103  };
    104 
    105  /* print header */
    106  dtrace:::BEGIN
    107  {
    108 	printf("Tracing ");
    109 	OPT_read && OPT_write ? printf("reads and writes") : 1;
    110 	OPT_read && ! OPT_write ? printf("reads") : 1;
    111 	! OPT_read && OPT_write ? printf("writes") : 1;
    112 	printf("...");
    113 	totaltime = 0;
    114 	totalbytes = 0;
    115 	last = timestamp;
    116 	stamp = timestamp;
    117  }
    118 
    119  /* sample reads */
    120  syscall::read:entry,
    121  syscall::pread*:entry
    122  /pid == PID && OPT_read/
    123  {
    124 	runstate = READ;
    125 	@logical["running", (uint64_t)0, ""] = sum(timestamp - last);
    126 	totaltime += timestamp - last;
    127 	last = timestamp;
    128 
    129 	self->fd = arg0 + 1;
    130  }
    131 
    132  fbt::fop_read:entry,
    133  fbt::fop_write:entry
    134  /self->fd/
    135  {
    136 	self->path = args[0]->v_path == 0 ? "<none>" : 
    137 	    cleanpath(args[0]->v_path);
    138  }
    139 
    140  syscall::read:return,
    141  syscall::pread*:return
    142  /pid == PID && OPT_read/
    143  {
    144 	runstate = OTHER;
    145 	this->bytes = (int)arg0 > 0 ? (int)arg0 : 0;
    146 	@logical["read", self->fd - 1, self->path] = sum(timestamp - last);
    147 	@bytes["read", self->fd - 1, self->path] = sum(this->bytes);
    148 	totalbytes += this->bytes;
    149 	totaltime += timestamp - last;
    150 	last = timestamp;
    151 	self->path = 0;
    152 	self->fd = 0;
    153  }
    154 
    155 
    156  /* sample writes */
    157  syscall::write:entry,
    158  syscall::pwrite*:entry
    159  /pid == PID && OPT_write/
    160  {
    161 	runstate = WRITE;
    162 	@logical["running", (uint64_t)0, ""] = sum(timestamp - last);
    163 	totaltime += timestamp - last;
    164 	last = timestamp;
    165 
    166 	self->fd = (int)arg0 + 1;
    167  }
    168 
    169  syscall::write:return,
    170  syscall::pwrite*:return
    171  /pid == PID && OPT_write/
    172  {
    173 	runstate = OTHER;
    174 	this->bytes = (int)arg0 > 0 ? (int)arg0 : 0;
    175 	@logical["write", self->fd - 1, self->path] = sum(timestamp - last);
    176 	@bytes["write", self->fd - 1, self->path] = sum(this->bytes);
    177 	totalbytes += this->bytes;
    178 	totaltime += timestamp - last;
    179 	last = timestamp;
    180 	self->path = 0;
    181 	self->fd = 0;
    182  }
    183 
    184  sched:::on-cpu
    185  /pid == PID/
    186  {
    187 	@logical["waitcpu", (uint64_t)0, ""] = sum(timestamp - last);
    188 	totaltime += timestamp - last;
    189 	last = timestamp;
    190  }
    191 
    192 
    193  sched:::off-cpu
    194  /pid == PID/
    195  {
    196 	@logical["running", (uint64_t)0, ""] = sum(timestamp - last);
    197 	totaltime += timestamp - last;
    198 	last = timestamp;
    199  }
    200 
    201  sched:::sleep
    202  /pid == PID/
    203  {
    204 	@logical["running", (uint64_t)0, ""] = sum(timestamp - last);
    205 	totaltime += timestamp - last;
    206 	last = timestamp;
    207  }
    208 
    209  sched:::wakeup
    210  /args[1]->pr_pid == PID && runstate == OTHER/
    211  {
    212 	@logical["sleep", (uint64_t)0, ""] = sum(timestamp - last);
    213 	totaltime += timestamp - last;
    214 	last = timestamp;
    215  }
    216 
    217  sched:::wakeup
    218  /args[1]->pr_pid == PID && runstate == READ/
    219  {
    220 	@logical["sleep-r", (uint64_t)0, ""] = sum(timestamp - last);
    221 	totaltime += timestamp - last;
    222 	last = timestamp;
    223  }
    224 
    225  sched:::wakeup
    226  /args[1]->pr_pid == PID && runstate == WRITE/
    227  {
    228 	@logical["sleep-w", (uint64_t)0, ""] = sum(timestamp - last);
    229 	totaltime += timestamp - last;
    230 	last = timestamp;
    231  }
    232 
    233  sched:::enqueue
    234  /args[1]->pr_pid == PID/
    235  {
    236 	@logical["waitcpu", (uint64_t)0, ""] = sum(timestamp - last);
    237 	totaltime += timestamp - last;
    238 	last = timestamp;
    239  }
    240 
    241  sched:::dequeue
    242  /args[1]->pr_pid == PID/
    243  {
    244 	@logical["waitcpu", (uint64_t)0, ""] = sum(timestamp - last);
    245 	totaltime += timestamp - last;
    246 	last = timestamp;
    247  }
    248 
    249  /* print report */
    250  profile:::tick-5s
    251  {
    252 	printf("%s", CLEAR);
    253 	normalize(@logical, totaltime / 100);
    254 	trunc(@logical, 10);
    255 	printf("%10s %7s %9s %-44s\n", "STATE", "FDNUM", "Time", "Filename");
    256 	printa("%10s %7d %@8d%% %-44.44s\n", @logical);
    257 	trunc(@logical);
    258 
    259 	delta = timestamp - stamp;
    260 	stamp = timestamp;
    261 	normalize(@bytes, (1024 * delta) / 1000000000);
    262 	trunc(@bytes, 10);
    263 	printf("\n%10s %7s %9s %-44s\n", "STATE", "FDNUM", "KB/s",
    264 	    "Filename");
    265 	printa("%10s %7d %@9d %-44.44s\n", @bytes);
    266 	trunc(@bytes);
    267 
    268 	printf("\nTotal event time (ms): %d   Total Mbytes/sec: %d\n",
    269 	    totaltime / 1000000,
    270 	    (totalbytes * 1000000000) / (delta * 1048576));
    271 
    272 	totaltime = 0;
    273 	totalbytes = 0;
    274 	last = timestamp;
    275  }
    276 
    277  dtrace:::END
    278  {
    279 	trunc(@logical);
    280 	trunc(@bytes);
    281  }
    282 '
    283