xref: /illumos-gate/usr/src/test/zfs-tests/tests/perf/scripts/io.d (revision 66582b606a8194f7f3ba5b3a3a6dca5b0d346361)
1 /*
2  * This file and its contents are supplied under the terms of the
3  * Common Development and Distribution License ("CDDL"), version 1.0.
4  * You may only use this file in accordance with the terms of version
5  * 1.0 of the CDDL.
6  *
7  * A full copy of the text of the CDDL should have accompanied this
8  * source.  A copy of the CDDL is also available via the Internet at
9  * http://www.illumos.org/license/CDDL.
10  */
11 
12 /*
13  * Copyright (c) 2013, 2016 by Delphix. All rights reserved.
14  */
15 
16 /*
17  * This measures the IO operations as seen by the ZPL layer (e.g.
18  * zfs_read and zfs_write), as well as the underlying block layer (e.g.
19  * the "io" dtrace provider).
20  *
21  * time: The number of seconds elapsed since the epoch
22  * @ops: collects the count of each metric (e.g. count of zfs_read calls)
23  * @latencies: collects the latency information of each metric
24  * @histograms: collects histograms of the latency for each metric
25  * @bytes: collects the throughput information for each metric
26  */
27 
28 #include <sys/file.h>
29 #include <sys/fs/zfs.h>
30 
31 #pragma D option aggsortkey
32 #pragma D option quiet
33 
34 BEGIN
35 {
36 	@ops["read"] = count();
37 	@ops["write"] = count();
38 	@ops["zfs_read"] = count();
39 	@ops["zfs_write"] = count();
40 	@ops["zfs_write_sync"] = count();
41 	@ops["zfs_write_async"] = count();
42 	@latencies["read"] = avg(0);
43 	@latencies["write"] = avg(0);
44 	@latencies["zfs_read"] = avg(0);
45 	@latencies["zfs_write"] = avg(0);
46 	@latencies["zfs_write_sync"] = avg(0);
47 	@latencies["zfs_write_async"] = avg(0);
48 	@histograms["read"] = quantize(0);
49 	@histograms["write"] = quantize(0);
50 	@histograms["zfs_read"] = quantize(0);
51 	@histograms["zfs_write"] = quantize(0);
52 	@histograms["zfs_write_sync"] = quantize(0);
53 	@histograms["zfs_write_async"] = quantize(0);
54 	@bytes["read"] = sum(0);
55 	@bytes["write"] = sum(0);
56 	@bytes["zfs_read"] = sum(0);
57 	@bytes["zfs_write"] = sum(0);
58 	@bytes["zfs_write_sync"] = sum(0);
59 	@bytes["zfs_write_async"] = sum(0);
60 	clear(@ops);
61 	clear(@latencies);
62 	clear(@histograms);
63 	clear(@bytes);
64 }
65 
66 fbt:zfs:zfs_read:entry,
67 fbt:zfs:zfs_write:entry
68 {
69 	this->zp = (znode_t *)args[0]->v_data;
70 	self->os = this->zp->z_zfsvfs->z_os;
71 	self->poolname = stringof(self->os->os_spa->spa_name);
72 }
73 
74 fbt:zfs:zfs_read:entry,
75 fbt:zfs:zfs_write:entry
76 / self->poolname == $$1 /
77 {
78 	self->zfs_rw = timestamp;
79 	self->bytes = args[1]->uio_resid;
80 }
81 
82 fbt:zfs:zfs_write:entry
83 / self->zfs_rw != 0 /
84 {
85 	self->flag = self->os->os_sync == ZFS_SYNC_ALWAYS ? "sync" :
86 	    (args[2] & (FSYNC | FDSYNC)) ? "sync" : "async";
87 }
88 
89 fbt:zfs:zfs_write:return
90 / self->zfs_rw != 0 /
91 {
92 	if (self->flag == "sync") {
93 		this->name = "zfs_write_sync"
94 	} else {
95 		this->name = "zfs_write_async"
96 	}
97 
98 	@ops[this->name] = count();
99 	@bytes[this->name] = sum(self->bytes);
100 	this->elapsed = timestamp - self->zfs_rw;
101 	@latencies[this->name] = avg(this->elapsed);
102 	@histograms[this->name] = quantize(this->elapsed);
103 }
104 
105 fbt:zfs:zfs_read:return,
106 fbt:zfs:zfs_write:return
107 / self->zfs_rw != 0 /
108 {
109 	@ops[probefunc] = count();
110 	@bytes[probefunc] = sum(self->bytes);
111 	this->elapsed = timestamp - self->zfs_rw;
112 	@latencies[probefunc] = avg(this->elapsed);
113 	@histograms[probefunc] = quantize(this->elapsed);
114 	self->zfs_rw = 0;
115 }
116 
117 io:::start
118 / strstr($$2, args[1]->dev_statname) != NULL /
119 {
120 	start[args[0]->b_edev, args[0]->b_blkno] = timestamp;
121 }
122 
123 io:::done
124 / start[args[0]->b_edev, args[0]->b_blkno] /
125 {
126 	this->elapsed = timestamp - start[args[0]->b_edev, args[0]->b_blkno];
127 	this->name = args[0]->b_flags & B_READ ? "read" : "write";
128 	@ops[this->name] = count();
129 	@bytes[this->name] = sum(args[0]->b_bcount);
130 	@latencies[this->name] = avg(this->elapsed);
131 	@histograms[this->name] = quantize(this->elapsed);
132 	start[args[0]->b_edev, args[0]->b_blkno] = 0;
133 }
134 
135 tick-$3s
136 {
137 	printf("%u\n", `time);
138 	printa("ops_%-21s%@u\n", @ops);
139 	printa("bytes_%-21s%@u\n", @bytes);
140 	printa("latencies_%-21s%@u\n", @latencies);
141 	printa("histograms_%-21s%@u\n", @histograms);
142 
143 	clear(@ops);
144 	clear(@bytes);
145 	clear(@latencies);
146 	clear(@histograms);
147 }
148 
149 ERROR
150 {
151 	trace(arg1);
152 	trace(arg2);
153 	trace(arg3);
154 	trace(arg4);
155 	trace(arg5);
156 }
157