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# 20-Mar-2006, ver 0.50
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
42
43##############################
44# --- Process Arguments ---
45#
46
47### Default variables
48opt_read=0; opt_write=0
49
50### Process options
51while getopts hrw name
52do
53	case $name in
54	r)      opt_read=1 ;;
55	w)      opt_write=1 ;;
56	h|?)    cat <<-END >&2
57		USAGE: pfilestat [-r|-w] pid
58		              -r           # reads only
59		              -w           # writes only
60		  eg,
61		       pfilestat pid       # default, r+w counts
62		       pfilestat -r pid    # read count only
63		END
64		exit 1
65	esac
66done
67shift `expr $OPTIND - 1`
68
69PID=$1
70clearstr=`clear`
71
72if [ -z "$PID" ]
73then
74	echo "Must supply pid"
75	exit 1
76fi
77
78### Option logic
79if [ $opt_read -eq 0 -a $opt_write -eq 0 ]; then
80	opt_read=1; opt_write=1
81fi
82
83
84#################################
85# --- Main Program, DTrace ---
86#
87/usr/sbin/dtrace -n '
88 #pragma D option quiet
89
90 inline string CLEAR   = "'$clearstr'";
91 inline int OPT_read   = '$opt_read';
92 inline int OPT_write  = '$opt_write';
93 inline int PID        = '$PID';
94
95 unsigned long long totaltime;
96 unsigned long long totalbytes;
97
98 enum runstate {
99	READ,
100	WRITE,
101	OTHER
102 };
103
104 /* print header */
105 dtrace:::BEGIN
106 {
107	printf("Sampling ");
108	OPT_read && OPT_write ? printf("reads and writes") : 1;
109	OPT_read && ! OPT_write ? printf("reads") : 1;
110	! OPT_read && OPT_write ? printf("writes") : 1;
111	printf("...");
112	totaltime = 0;
113	totalbytes = 0;
114	last = timestamp;
115	stamp = timestamp;
116 }
117
118 /* sample reads */
119 syscall::read:entry,
120 syscall::pread*:entry
121 /pid == PID && OPT_read/
122 {
123	runstate = READ;
124	@logical["running", (uint64_t)0, ""] = sum(timestamp - last);
125	totaltime += timestamp - last;
126	last = timestamp;
127
128	self->fd = arg0 + 1;
129 }
130
131 fbt::fop_read:entry,
132 fbt::fop_write:entry
133 /self->fd/
134 {
135	self->path = args[0]->v_path == 0 ? "<none>" : 
136	    cleanpath(args[0]->v_path);
137 }
138
139 syscall::read:return,
140 syscall::pread*:return
141 /pid == PID && OPT_read/
142 {
143	runstate = OTHER;
144	this->bytes = (int)arg0 > 0 ? (int)arg0 : 0;
145	@logical["read", self->fd - 1, self->path] = sum(timestamp - last);
146	@bytes["read", self->fd - 1, self->path] = sum(this->bytes);
147	totalbytes += this->bytes;
148	totaltime += timestamp - last;
149	last = timestamp;
150	self->path = 0;
151	self->fd = 0;
152 }
153
154
155 /* sample writes */
156 syscall::write:entry,
157 syscall::pwrite*:entry
158 /pid == PID && OPT_write/
159 {
160	runstate = WRITE;
161	@logical["running", (uint64_t)0, ""] = sum(timestamp - last);
162	totaltime += timestamp - last;
163	last = timestamp;
164
165	self->fd = (int)arg0 + 1;
166 }
167
168 syscall::write:return,
169 syscall::pwrite*:return
170 /pid == PID && OPT_write/
171 {
172	runstate = OTHER;
173	this->bytes = (int)arg0 > 0 ? (int)arg0 : 0;
174	@logical["write", self->fd - 1, self->path] = sum(timestamp - last);
175	@bytes["write", self->fd - 1, self->path] = sum(this->bytes);
176	totalbytes += this->bytes;
177	totaltime += timestamp - last;
178	last = timestamp;
179	self->path = 0;
180	self->fd = 0;
181 }
182
183 sched:::on-cpu
184 /pid == PID/
185 {
186	@logical["waitcpu", (uint64_t)0, ""] = sum(timestamp - last);
187	totaltime += timestamp - last;
188	last = timestamp;
189 }
190
191
192 sched:::off-cpu
193 /pid == PID/
194 {
195	@logical["running", (uint64_t)0, ""] = sum(timestamp - last);
196	totaltime += timestamp - last;
197	last = timestamp;
198 }
199
200 sched:::sleep
201 /pid == PID/
202 {
203	@logical["running", (uint64_t)0, ""] = sum(timestamp - last);
204	totaltime += timestamp - last;
205	last = timestamp;
206 }
207
208 sched:::wakeup
209 /args[1]->pr_pid == PID && runstate == OTHER/
210 {
211	@logical["sleep", (uint64_t)0, ""] = sum(timestamp - last);
212	totaltime += timestamp - last;
213	last = timestamp;
214 }
215
216 sched:::wakeup
217 /args[1]->pr_pid == PID && runstate == READ/
218 {
219	@logical["sleep-r", (uint64_t)0, ""] = sum(timestamp - last);
220	totaltime += timestamp - last;
221	last = timestamp;
222 }
223
224 sched:::wakeup
225 /args[1]->pr_pid == PID && runstate == WRITE/
226 {
227	@logical["sleep-w", (uint64_t)0, ""] = sum(timestamp - last);
228	totaltime += timestamp - last;
229	last = timestamp;
230 }
231
232 sched:::enqueue
233 /args[1]->pr_pid == PID/
234 {
235	@logical["waitcpu", (uint64_t)0, ""] = sum(timestamp - last);
236	totaltime += timestamp - last;
237	last = timestamp;
238 }
239
240 sched:::dequeue
241 /args[1]->pr_pid == PID/
242 {
243	@logical["waitcpu", (uint64_t)0, ""] = sum(timestamp - last);
244	totaltime += timestamp - last;
245	last = timestamp;
246 }
247
248 /* print report */
249 profile:::tick-5s
250 {
251	printf("%s", CLEAR);
252	normalize(@logical, totaltime / 100);
253	trunc(@logical, 10);
254	printf("%10s %7s %9s %-44s\n", "STATE", "FDNUM", "Time", "Filename");
255	printa("%10s %7d %@8d%% %-44.44s\n", @logical);
256	trunc(@logical);
257
258	delta = timestamp - stamp;
259	stamp = timestamp;
260	normalize(@bytes, (1024 * delta) / 1000000000);
261	trunc(@bytes, 10);
262	printf("\n%10s %7s %9s %-44s\n", "STATE", "FDNUM", "KB/s",
263	    "Filename");
264	printa("%10s %7d %@9d %-44.44s\n", @bytes);
265	trunc(@bytes);
266
267	printf("\nTotal event time (ms): %d   Total Mbytes/sec: %d\n",
268	    totaltime / 1000000,
269	    (totalbytes * 1000000000) / (delta * 1048576));
270
271	totaltime = 0;
272	totalbytes = 0;
273	last = timestamp;
274 }
275
276 dtrace:::END
277 {
278	trunc(@logical);
279	trunc(@bytes);
280 }
281'
282