Sun Java System Web Server and dtrace.

dtrace is often used to trace kernel and applications. It would be interesing to monitor Web Server using dtrace. Sun Web Server does not contain built in dtrace probes but it is possible to write a small NSAPI plug-in which can be used to monitor Web Server.
In this blog, I will show how to write a small NSAPI plug-in and load the plug-in in to the Web Server and insert a log level hook (AddLog). This NSAPI plug-in will contain a dtrace probe. When plug-in is loaded in to the Web Server, Web Server will register the dtrace probes with kernel. During execution of HTTP request, Web Server will invoke AddLog (at the end of the request) which will fire the dtrace probe. Dtrace probe will provide information about the request and response. Using this probe, it is possible to write "top" like utility for Web Server.
Here is my NSAPI plug-in's code wbdtrace.c

/*
 * Copyright (c) 2005, 2008 Sun Microsystems, Inc. All Rights Reserved.
 * Use is subject to license terms.
 */
#include "nsapi.h"
#include <sys/sdt.h>

int NSAPI_PUBLIC dtrace_log_request(pblock *pb, Session *sn, Request *rq)
{
    DTRACE_PROBE4(sjsws, log__request, 
                  (rq && rq->reqpb) ? pblock_pblock2str((pblock*) rq->reqpb, NULL) : NULL,
                  (rq && rq->headers) ? pblock_pblock2str((pblock*) rq->headers, NULL) : NULL,
                  (rq && rq->srvhdrs) ? pblock_pblock2str((pblock*) rq->srvhdrs, NULL) : NULL,
                  (rq && rq->vars) ? pblock_pblock2str((pblock*) rq->vars, NULL) : NULL,
                  );
    return REQ_NOACTION;
}

Here is the dtrace provider's code sjsws.d

/*
 * Copyright (c) 2005, 2008 Sun Microsystems, Inc. All Rights Reserved.
 * Use is subject to license terms.
 */
provider sjsws {
probe log__request(string, string, string, string);
};

We now need to compile this plug-in and load into the Web Server. Here is how I compiled the plug-in :

$ cc -c -KPIC -mt -DXP_UNIX -I/opt2/installed/ws70u1/include wbdtrace.c
$ dtrace -G -s sjsws.d wbdtrace.o
$ cc -KPIC -mt -G -L/opt2/installed/ws70u1/lib -lCrun -lCstd -ldl -lposix4 -lns-httpd40 -o libwbdtrace.so wbdtrace.o sjsws.o

Now I copied the plug-in to Web Server's plug-in directory :

$ cp libwbdtrace.so /opt/ws70u1/plug-ins/

Now I loaded the plug-in into the Web Server and inserted a AddLog statement into obj.conf file. Here are the configuration changes which are required for this plug-in to work.

magnus.conf :
Init fn="load-modules" shlib="libwbdtrace.so" shlib_flags="(global|now)" funcs="dtrace_log_request"

obj.conf :

<Object name="default">
...
AddLog fn="dtrace_log_request"
</Object>

After making the configuration changes I restarted the Web Server :

$ bin/stopserv; bin/startserv

Web Server is now started and plug-in is loaded. This dtrace NSAPI plug-in will register the dtrace probe (sjsws provider) with kernel. Now let us see how Web Server dtrace probe looks like using "dtrace -l":

# dtrace -l | grep sjsws
53309  sjsws6523    libwbdtrace.so                dtrace_log_request log-request
53310  sjsws6524    libwbdtrace.so                dtrace_log_request log-request

Note that both primordial (53310) and child process (53309) have registered the probe with Solaris kernel. But since only child process will serve the request so only child process will fire the dtrace probes. Now let us write a small dtrace script (viewreq.d) which just print a message whenever our probe is fired.

sjsws*::dtrace_log_request:log-request
{
    @[probefunc] = count();
    printf("\narg0 = %x arg0= %s \n arg1=%s \nargs2=%s arg3 = %s\n",
                    arg0,
                    copyinstr(arg0),
                    copyinstr(arg1),
                    copyinstr(arg2),
                    copyinstr(arg3));
}

dtrace:::END
{
    trace("End of dtrace\n");
}

Now I ran this script and sent a HTTP request "GET /" from browser.

# dtrace -s viewreq.d
dtrace: script 'viewreq.d' matched 3 probes

CPU ID FUNCTION:NAME 
1 53310 dtrace_log_request:log-request
arg0 = 7553c8 arg0= clf-request="GET / HTTP/1.1" ...
^C 
0 2 :END End of dtrace

Now whenever message is logged, our dtrace probe is fired. Our dtrace script just printed the various pblocks.

Based on the above dtrace NSAPI plug-in, it is possible to write monitoring code in scripting languages e.g perl. Here are some of the scripts :
countreq.pl
viewbrowser.pl
viewresponsecodes.pl
wbdtrace.pm
wstop.pl
These are perl scripts which encapsulates the dtrace script. Most of the text processing is written in perl. Dtrace probe provide the pblock content from where request and response information is obtained.

Here is the output of these scripts.

View various types of HTTP requests count with timestamp

# perl countreq.pl

Timestamp GETs POSTs HEADs TRACEs
12:41:13  0    0     0     0
12:41:18  5469 0     0     0
12:41:23  10000 0     0     0

View various types of HTTP requests count with client browsers

# perl viewbrowser.pl
Browser   GETs POSTs HEADs TRACEs
Firefox   19   0     0     0
MSIE      0    0     0     0
Wget      0    0     0     0
Other     303  0     0     0

View HTTP requests' URIs and their response codes

# perl viewresponsecodes.pl
Response Code   Uri                            File Name
200             /index.html                    /index.html
304             /index.html                    /index.html
403             /img/gradation_header_L.gif    /img/gradation_header_L.gif
403             /img/gradation_header_R.gif    /img/gradation_header_R.gif
^C

View HTTP requests' URIs for a particular response code

# perl viewresponsecodes.pl -c 200
Response Code   Uri                            File Name
200             /index.html                    /index.html
^C

A top like utility for Sun Web Server (similar to apachetop)

# perl wstop.pl -d 10
20:10:40  Requests: 4223  (  422/sec) Bytes: 12930794(1293079/sec)
Requests: GETs: 4223   POSTs: 0      HEADs: 0      TRACE: 0
Responses: 1xx:0      2xx:4025   3xx:68     4xx:130    5xx:0

Requests  Reqests/sec  Bytes Sent  URI
601       60           7234838      /index.html
545       54           198925       /img/gradation_header_L.gif
498       49           3988482      /img/side_bg.gif
396       39           930204       /img/sun_logo.gif
359       35           56004        /img/gradation_header-btm.gif
342       34           2394         /cgi-bin/test.pl
250       25           10750        /img/a.gif
240       24           96720        /img/gradation_header_R.gif
206       20           52324        /img/footer_R.gif
191       19           58828        /img/gradation_header.gif
130       13           37960        /notfound.html
115       11           15410        /img/content_hline.gif
113       11           29041        /img/footer_L.gif
109       10           207754       /img/sjsws_title_text.gif
68        6            0            /yahoo
60        6            11160        /img/footer.gif
^C

Here is the compiled binary for the plugin :
Solaris sparc
Solaris x86

Posted at 01:12PM Jun 16, 2008 by Basant Kukreja in Sun Web Server  |  Comments[4]