1#!/usr/sbin/dtrace -s
2/*
3 * weblatency.d - website latency statistics.
4 *		  Written using DTrace (Solaris 10 3/05).
5 *
6 * 20-Apr-2006, ver 0.61        (early release)
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 */
53
54#pragma D option quiet
55
56/* browser's execname */
57inline string BROWSER = "Safari";
58
59/* maximum expected hostname length + "GET http://" */
60inline int MAX_REQ = 64;
61
62dtrace:::BEGIN
63{
64	printf("Tracing... Hit Ctrl-C to end.\n");
65}
66
67/*
68 * Trace brower request
69 *
70 * This is achieved by matching writes for the browser's execname that
71 * start with "GET", and then timing from the return of the write to
72 * the return of the next read in the same thread. Various stateful flags
73 * are used: self->fd, self->read.
74 *
75 * For performance reasons, I'd like to only process writes that follow a
76 * connect(), however this approach fails to process keepalives.
77 */
78syscall::write_nocancel:entry,
79syscall::write:entry
80/execname == BROWSER/
81{
82	self->buf = arg1;
83	self->fd = arg0 + 1;
84	self->nam = "";
85}
86
87syscall::write_nocancel:return,
88syscall::write:return
89/self->fd/
90{
91	this->str = (char *)copyin(self->buf, MAX_REQ);
92	this->str[4] = '\0';
93	self->fd = stringof(this->str) == "GET " ? self->fd : 0;
94}
95
96syscall::write_nocancel:return,
97syscall::write:return
98/self->fd/
99{
100	/* fetch browser request */
101	this->str = (char *)copyin(self->buf, MAX_REQ);
102	this->str[MAX_REQ] = '\0';
103
104	self->nam = strtok(&(this->str[4])," ?");
105
106	/* start the timer */
107	start[pid, self->fd - 1] = timestamp;
108	host[pid, self->fd - 1] = self->nam;
109	self->buf = 0;
110	self->fd  = 0;
111	self->req = 0;
112	self->nam = 0;
113}
114
115/* this one wasn't a GET */
116syscall::write_nocancel:return,
117syscall::write:return
118/self->buf/
119{
120	self->buf = 0;
121	self->fd  = 0;
122}
123
124syscall::read_nocancel:entry,
125syscall::read:entry
126/execname == BROWSER && start[pid, arg0]/
127{
128	self->fd = arg0 + 1;
129}
130
131/*
132 * Record host details
133 */
134syscall::read_nocancel:return,
135syscall::read:return
136/self->fd/
137{
138	/* fetch details */
139	self->host = stringof(host[pid, self->fd - 1]);
140	this->start = start[pid, self->fd - 1];
141
142	/* save details */
143	@Avg[self->host] = avg((timestamp - this->start)/1000000);
144	@Max[self->host] = max((timestamp - this->start)/1000000);
145	@Num[self->host] = count();
146
147	/* clear vars */
148	start[pid, self->fd - 1] = 0;
149	host[pid, self->fd - 1] = 0;
150	self->host = 0;
151	self->fd = 0;
152}
153
154/*
155 * Output report
156 */
157dtrace:::END
158{
159	printf("%-32s %11s\n", "HOST", "NUM");
160	printa("%-32s %@11d\n", @Num);
161
162	printf("\n%-32s %11s\n", "HOST", "AVGTIME(ms)");
163	printa("%-32s %@11d\n", @Avg);
164
165	printf("\n%-32s %11s\n", "HOST", "MAXTIME(ms)");
166	printa("%-32s %@11d\n", @Max);
167}
168