pfilestat revision 285830
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 4 2007-08-01 11:01:38Z brendan $ 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 49opt_read=0; opt_write=0 50 51### Process options 52while getopts hrw name 53do 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 67done 68shift `expr $OPTIND - 1` 69 70PID=$1 71clearstr=`clear` 72 73if [ -z "$PID" ] 74then 75 echo "Must supply pid" 76 exit 1 77fi 78 79### Option logic 80if [ $opt_read -eq 0 -a $opt_write -eq 0 ]; then 81 opt_read=1; opt_write=1 82fi 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