cddl/contrib/dtracetoolkit/Apps/weblatency.d

   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 3 2007-08-01 10:50:08Z brendan $
   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 }