Sun GlassFish Enterprise Manager DTrace Monitoring 3.0 Beta Installation and Quick Start Guide

Sample D Scripts for Monitoring Enterprise Server

The sample D scripts in this section show how to use Enterprise Server DTrace probes to monitor Enterprise Server.


Example 2 Tracing Network Connection Activity

This example traces network connection activity, such as the opening and closing of network connections, and the addition and removal of tasks from the task queue. Each time an operation on a network connection is performed, the probe for that operation and the probe's parameters are displayed on standard output.

Line breaks are added to the printf() statements in this example to enhance readability. In an actual D script, the added line breaks would cause the script to fail to compile.

#!/usr/sbin/dtrace -Zs

dtrace:::BEGIN {
    printf("%-Y     Starting DTrace...\n", walltimestamp);
	i=0;
}

glassfish*:kernel:connection-queue:connectionAcceptedEvent {
	listenerName=copyinstr(arg0);
	connection=arg1;
	address=copyinstr(arg2);
        printf("connectionAcceptedEvent(listenerName=%s,connection=%d,address=%s)",
        listenerName,connection,address);
}
glassfish*:kernel:connection-queue:connectionClosedEvent {
	listenerName=copyinstr(arg0);
        connection=arg1;
        printf("connectionClosedEvent(listenerName=%s,connection=%d)",listenerName,
        connection);
}
glassfish*:kernel:connection-queue:connectionConnectedEvent {
	listenerName=copyinstr(arg0);
        connection=arg1;
	address=copyinstr(arg2);
        printf("connectionConnectedEvent(listenerName=%s,connection=%d,address=%s)",
        listenerName,connection,address);
}

glassfish*:kernel:connection-queue:onTaskQueuedEvent {
        listenerName=copyinstr(arg0);
        task=copyinstr(arg1);
        printf("onTaskQueuedEvent(listenerName=%s,task=%s)",listenerName,task);
}

glassfish*:kernel:connection-queue:onTaskDequeuedEvent {
	listenerName=copyinstr(arg0);
        task=copyinstr(arg1);
        printf("onTaskDequeuedEvent(listenerName=%s,task=%s)",listenerName,task);
}

glassfish*:kernel:connection-queue:onTaskQueueOverflowEvent {
	listenerName=copyinstr(arg0);
	printf("onTaskQueueOverflowEvent(listenerName=%s)",listenerName);
}

glassfish*:kernel:connection-queue:setMaxTaskQueueSizeEvent {
        listenerName=copyinstr(arg0);
        size=arg1;
        printf("setMaxTaskQueueSizeEvent(listenerName=%s,size%d)",listenerName,size);
}

dtrace:::END {
    printf("%-Y     Finished DTrace of glassfish*...\n", walltimestamp);
}

This script can be run with a command similar to the following:


# /usr/sbin/dtrace -s http-conn.d

Information similar to the following is displayed.


dtrace: script 'http-conn.d' matched 9 probes
CPU     ID                    FUNCTION:NAME
  0      1                           :BEGIN 2009 Dec  2 18:19:27     Starting DTrace...

  0  40548 connection-queue:connectionAcceptedEvent connectionAcceptedEvent(
listenerName=admin-listener,connection=5676699,address=/129.146.11.144:50600)
  0  40549 connection-queue:onTaskQueuedEvent onTaskQueuedEvent(
listenerName=admin-listener,task=13872330)
  0  40550 connection-queue:onTaskDequeuedEvent onTaskDequeuedEvent(
listenerName=admin-listener,task=13872330)
  0  40549 connection-queue:onTaskQueuedEvent onTaskQueuedEvent(
listenerName=admin-listener,task=17098630)
  0  40550 connection-queue:onTaskDequeuedEvent onTaskDequeuedEvent(
listenerName=admin-listener,task=17098630)
  0  40549 connection-queue:onTaskQueuedEvent onTaskQueuedEvent(
listenerName=admin-listener,task=16525461)
  0  40550 connection-queue:onTaskDequeuedEvent onTaskDequeuedEvent(
listenerName=admin-listener,task=16525461)
  0  40548 connection-queue:connectionAcceptedEvent connectionAcceptedEvent(
listenerName=admin-listener,connection=13390280,address=/129.146.11.144:50601)

The script runs until a user types Ctrl-C to stop the script.



Example 3 Tracing HTTP Requests to the Web Container

This example traces HTTP requests to the web container and calculates the time that is required to handle each request. Each time a request is handled, details of the request and the time in microseconds to handle the request are displayed on standard output. When the script is stopped, it displays a summary of the requests that were handled while the script was running.

#!/usr/sbin/dtrace -Zs

dtrace:::BEGIN {   printf ("%-20s \n", "Monitoring Requests");   total = 0; } 

glassfish$1:web:http-service:requestStartEvent {
   self->ts = timestamp;
   trace(probename);
   @counts[probename]=count();
}

glassfish$1:web:http-service:requestEndEvent
/self->ts/
{
   trace(probename);
   printf ("%s %s %d\n", copyinstr(arg0), copyinstr(arg1), arg2);
   @counts[probename]=count();
   @time[execname] = quantize(timestamp - self->ts);
   printf ("time in microseconds: %d\n", (timestamp - self->ts));
   self->ts = 0;
   total++; }
dtrace:::END {   printf ("Total requests = %d\n", total); } 

This script requires the process ID of the Enterprise Server process. The process ID can be obtained with the following command:


# jps | grep ASMain
1086 ASMain

In this example, the process ID of the Enterprise Server process is 1086.

This script can be run with a command similar to the following:


# /usr/sbin/dtrace -s trace-web-requests.d 1086

Information similar to the following is displayed. For better readability, the spacing between columns is reduced.


dtrace: script 'trace-web-requests.d' matched 4 probes
CPU     ID                    FUNCTION:NAME
  0      1                           :BEGIN Monitoring Requests  

  0  41085   http-service:requestStartEvent   requestStartEvent                
  0  41084     http-service:requestEndEvent   requestEndEvent hello server 3418876592
time in microseconds: 70935041

  0  41085   http-service:requestStartEvent   requestStartEvent                
  0  41084     http-service:requestEndEvent   requestEndEvent hello server 3419925040
time in microseconds: 2174591

  0  41085   http-service:requestStartEvent   requestStartEvent                
  0  41084     http-service:requestEndEvent   requestEndEvent hello server 3418876592
time in microseconds: 13554111

  0  41085   http-service:requestStartEvent   requestStartEvent                
  0  41084     http-service:requestEndEvent   requestEndEvent hello server 3419925040
time in microseconds: 2499509

The script runs until a user types Ctrl-C to stop the script. When the script stops, information similar to the following is displayed.


^C
  0      2                             :END Total requests = 4


  requestEndEvent                                                   4
  requestStartEvent                                                 4
  java                                              
           value  ------------- Distribution ------------- count    
         1048576 |                                         0        
         2097152 |@@@@@@@@@@@@@@@@@@@@                     2        
         4194304 |                                         0        
         8388608 |@@@@@@@@@@                               1        
        16777216 |                                         0        
        33554432 |                                         0        
        67108864 |@@@@@@@@@@                               1        
       134217728 |                                         0