weblatency.d   [plain text]


#!/usr/sbin/dtrace -s
/*
 * weblatency.d - website latency statistics.
 *		  Written using DTrace (Solaris 10 3/05).
 *
 * 20-Apr-2006, ver 0.61        (early release)
 *
 * USAGE:	weblatency.d 	# hit Ctrl-C to end sample
 *
 * See the code below for the "BROWSER" variable, which sets the browser
 * to trace (currently set to "mozilla-bin").
 *
 * This is written as an experimental tool, and may not work at all with
 * your browser.
 *
 * FIELDS:
 *		HOST		Hostname from URL
 *		NUM		Number of GETs
 *		AVGTIME(ms)	Average time for response, ms
 *		MAXTIME(ms)	Maximum time for response, ms
 *
 * NOTE:
 *
 * The latency measured here is from the browser sending the GET
 * request to when the browser begins to recieve the response. It
 * is an overall response time for the client, and encompasses
 * connection speed delays, DNS lookups, proxy delays, and web server
 * response time.
 *
 * IDEA: Bryan Cantrill (who wrote an elegant version for Sol 10 update 1)
 *
 * COPYRIGHT: Copyright (c) 2005, 2006 Brendan Gregg.
 *
 * CDDL HEADER START
 *
 *  The contents of this file are subject to the terms of the
 *  Common Development and Distribution License, Version 1.0 only
 *  (the "License").  You may not use this file except in compliance
 *  with the License.
 *
 *  You can obtain a copy of the license at Docs/cddl1.txt
 *  or http://www.opensolaris.org/os/licensing.
 *  See the License for the specific language governing permissions
 *  and limitations under the License.
 *
 * CDDL HEADER END
 *
 * ToDo:
 *	Check write fd for socket, not file.
 *
 * 30-Nov-2005  Brendan Gregg   Created this.
 */

#pragma D option quiet

/* browser's execname */
inline string BROWSER = "Safari";

/* maximum expected hostname length + "GET http://" */
inline int MAX_REQ = 64;

dtrace:::BEGIN
{
	printf("Tracing... Hit Ctrl-C to end.\n");
}

/*
 * Trace brower request
 *
 * This is achieved by matching writes for the browser's execname that
 * start with "GET", and then timing from the return of the write to
 * the return of the next read in the same thread. Various stateful flags
 * are used: self->fd, self->read.
 *
 * For performance reasons, I'd like to only process writes that follow a
 * connect(), however this approach fails to process keepalives.
 */
syscall::write_nocancel:entry,
syscall::write:entry
/execname == BROWSER/
{
	self->buf = arg1;
	self->fd = arg0 + 1;
	self->nam = "";
}

syscall::write_nocancel:return,
syscall::write:return
/self->fd/
{
	this->str = (char *)copyin(self->buf, MAX_REQ);
	this->str[4] = '\0';
	self->fd = stringof(this->str) == "GET " ? self->fd : 0;
}

syscall::write_nocancel:return,
syscall::write:return
/self->fd/
{
	/* fetch browser request */
	this->str = (char *)copyin(self->buf, MAX_REQ);
	this->str[MAX_REQ] = '\0';

	self->nam = strtok(&(this->str[4])," ?");

	/* start the timer */
	start[pid, self->fd - 1] = timestamp;
	host[pid, self->fd - 1] = self->nam;
	self->buf = 0;
	self->fd  = 0;
	self->req = 0;
	self->nam = 0;
}

/* this one wasn't a GET */
syscall::write_nocancel:return,
syscall::write:return
/self->buf/
{
	self->buf = 0;
	self->fd  = 0;
}

syscall::read_nocancel:entry,
syscall::read:entry
/execname == BROWSER && start[pid, arg0]/
{
	self->fd = arg0 + 1;
}

/*
 * Record host details
 */
syscall::read_nocancel:return,
syscall::read:return
/self->fd/
{
	/* fetch details */
	self->host = stringof(host[pid, self->fd - 1]);
	this->start = start[pid, self->fd - 1];

	/* save details */
	@Avg[self->host] = avg((timestamp - this->start)/1000000);
	@Max[self->host] = max((timestamp - this->start)/1000000);
	@Num[self->host] = count();

	/* clear vars */
	start[pid, self->fd - 1] = 0;
	host[pid, self->fd - 1] = 0;
	self->host = 0;
	self->fd = 0;
}

/*
 * Output report
 */
dtrace:::END
{
	printf("%-32s %11s\n", "HOST", "NUM");
	printa("%-32s %@11d\n", @Num);

	printf("\n%-32s %11s\n", "HOST", "AVGTIME(ms)");
	printa("%-32s %@11d\n", @Avg);

	printf("\n%-32s %11s\n", "HOST", "MAXTIME(ms)");
	printa("%-32s %@11d\n", @Max);
}