weblatency.d revision 1.1.1.1 1 #!/usr/sbin/dtrace -s
2 /*
3 * weblatency.d - website latency statistics.
4 * Written using DTrace (Solaris 10 3/05).
5 *
6 * $Id: weblatency.d,v 1.1.1.1 2015/09/30 22:01:06 christos Exp $
7 *
8 * USAGE: weblatency.d # hit Ctrl-C to end sample
9 *
10 * See the code below for the "BROWSER" variable, which sets the browser
11 * to trace (currently set to "mozilla-bin").
12 *
13 * This is written as an experimental tool, and may not work at all with
14 * your browser.
15 *
16 * FIELDS:
17 * HOST Hostname from URL
18 * NUM Number of GETs
19 * AVGTIME(ms) Average time for response, ms
20 * MAXTIME(ms) Maximum time for response, ms
21 *
22 * NOTE:
23 *
24 * The latency measured here is from the browser sending the GET
25 * request to when the browser begins to recieve the response. It
26 * is an overall response time for the client, and encompasses
27 * connection speed delays, DNS lookups, proxy delays, and web server
28 * response time.
29 *
30 * IDEA: Bryan Cantrill (who wrote an elegant version for Sol 10 update 1)
31 *
32 * COPYRIGHT: Copyright (c) 2005, 2006 Brendan Gregg.
33 *
34 * CDDL HEADER START
35 *
36 * The contents of this file are subject to the terms of the
37 * Common Development and Distribution License, Version 1.0 only
38 * (the "License"). You may not use this file except in compliance
39 * with the License.
40 *
41 * You can obtain a copy of the license at Docs/cddl1.txt
42 * or http://www.opensolaris.org/os/licensing.
43 * See the License for the specific language governing permissions
44 * and limitations under the License.
45 *
46 * CDDL HEADER END
47 *
48 * ToDo:
49 * Check write fd for socket, not file.
50 *
51 * 30-Nov-2005 Brendan Gregg Created this.
52 * 20-Apr-2006 " " Last update.
53 */
54
55 #pragma D option quiet
56
57 /* browser's execname */
58 inline string BROWSER = "mozilla-bin";
59
60 /* maximum expected hostname length + "GET http://" */
61 inline int MAX_REQ = 64;
62
63 dtrace:::BEGIN
64 {
65 printf("Tracing... Hit Ctrl-C to end.\n");
66 }
67
68 /*
69 * Trace brower request
70 *
71 * This is achieved by matching writes for the browser's execname that
72 * start with "GET", and then timing from the return of the write to
73 * the return of the next read in the same thread. Various stateful flags
74 * are used: self->fd, self->read.
75 *
76 * For performance reasons, I'd like to only process writes that follow a
77 * connect(), however this approach fails to process keepalives.
78 */
79 syscall::write:entry
80 /execname == BROWSER/
81 {
82 self->buf = arg1;
83 self->fd = arg0 + 1;
84 self->nam = "";
85 }
86
87 syscall::write:return
88 /self->fd/
89 {
90 this->str = (char *)copyin(self->buf, MAX_REQ);
91 this->str[4] = '\0';
92 self->fd = stringof(this->str) == "GET " ? self->fd : 0;
93 }
94
95 syscall::write:return
96 /self->fd/
97 {
98 /* fetch browser request */
99 this->str = (char *)copyin(self->buf, MAX_REQ);
100 this->str[MAX_REQ] = '\0';
101
102 /*
103 * This unrolled loop strips down a URL to it's hostname.
104 * We ought to use strtok(), but it's not available on Sol 10 3/05,
105 * so instead I used dirname(). It's not pretty - it's done so that
106 * this works on all Sol 10 versions.
107 */
108 self->req = stringof(this->str);
109 self->nam = strlen(self->req) > 15 ? self->req : self->nam;
110 self->req = dirname(self->req);
111 self->nam = strlen(self->req) > 15 ? self->req : self->nam;
112 self->req = dirname(self->req);
113 self->nam = strlen(self->req) > 15 ? self->req : self->nam;
114 self->req = dirname(self->req);
115 self->nam = strlen(self->req) > 15 ? self->req : self->nam;
116 self->req = dirname(self->req);
117 self->nam = strlen(self->req) > 15 ? self->req : self->nam;
118 self->req = dirname(self->req);
119 self->nam = strlen(self->req) > 15 ? self->req : self->nam;
120 self->req = dirname(self->req);
121 self->nam = strlen(self->req) > 15 ? self->req : self->nam;
122 self->req = dirname(self->req);
123 self->nam = strlen(self->req) > 15 ? self->req : self->nam;
124 self->req = dirname(self->req);
125 self->nam = strlen(self->req) > 15 ? self->req : self->nam;
126 self->nam = basename(self->nam);
127
128 /* start the timer */
129 start[pid, self->fd - 1] = timestamp;
130 host[pid, self->fd - 1] = self->nam;
131 self->buf = 0;
132 self->fd = 0;
133 self->req = 0;
134 self->nam = 0;
135 }
136
137 /* this one wasn't a GET */
138 syscall::write:return
139 /self->buf/
140 {
141 self->buf = 0;
142 self->fd = 0;
143 }
144
145 syscall::read:entry
146 /execname == BROWSER && start[pid, arg0]/
147 {
148 self->fd = arg0 + 1;
149 }
150
151 /*
152 * Record host details
153 */
154 syscall::read:return
155 /self->fd/
156 {
157 /* fetch details */
158 self->host = stringof(host[pid, self->fd - 1]);
159 this->start = start[pid, self->fd - 1];
160
161 /* save details */
162 @Avg[self->host] = avg((timestamp - this->start)/1000000);
163 @Max[self->host] = max((timestamp - this->start)/1000000);
164 @Num[self->host] = count();
165
166 /* clear vars */
167 start[pid, self->fd - 1] = 0;
168 host[pid, self->fd - 1] = 0;
169 self->host = 0;
170 self->fd = 0;
171 }
172
173 /*
174 * Output report
175 */
176 dtrace:::END
177 {
178 printf("%-32s %11s\n", "HOST", "NUM");
179 printa("%-32s %@11d\n", @Num);
180
181 printf("\n%-32s %11s\n", "HOST", "AVGTIME(ms)");
182 printa("%-32s %@11d\n", @Avg);
183
184 printf("\n%-32s %11s\n", "HOST", "MAXTIME(ms)");
185 printa("%-32s %@11d\n", @Max);
186 }
187