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