Measuring HTTP Listener Service Time With BTrace

In the last entry, I discussed who BTrace can be used to monitor the HTTP thread pool. Here, I show how a similar script can be used to measure the service time of the HTTP listener.

To reiterate from last time, BTrace puts restrictions on what byte code can be executed in the script. For security reasons, only code from the BTraceUtil class is allowed to be executed.

The script for GlassFish V2 is given below.  For V3, the clazz attribute needs to be changed to com.sun.grizzly.http.ProcessorTask  and the method to doProcess.

package com.sun.btrace.samples;

import static com.sun.btrace.BTraceUtils.\*;
import com.sun.btrace.AnyType;
import com.sun.btrace.BTraceUtils;
import com.sun.btrace.aggregation.\*;
import com.sun.btrace.annotations.\*;

/\*\*
 \* BTrace script to print timings for all executed JDBC statements on an event. Demonstrates
 \* different types of aggregation function.
 \*
 \* @author Binu John
 \*/
@BTrace
public class GFV2HttpListenerServiceTime {
    private static Aggregation histogram = newAggregation(AggregationFunction.QUANTIZE);
    private static Aggregation average = newAggregation(AggregationFunction.AVERAGE);
    private static Aggregation max = newAggregation(AggregationFunction.MAXIMUM);
    private static Aggregation min = newAggregation(AggregationFunction.MINIMUM);
    private static Aggregation count = newAggregation(AggregationFunction.COUNT);

    @TLS
    private static long cEntry;

    private static boolean full = $(2) != null && strcmp("--full", $(2)) == 0;

    @OnMethod(clazz = "com.sun.enterprise.web.connector.grizzly.TaskBase", method="run")
    public static void onWCEntry() {
    cEntry = timeNanos();
    }

    @OnMethod(clazz = "com.sun.enterprise.web.connector.grizzly.TaskBase", method = "run", location = @Location(Kind.RETURN))
    public static void onWCExit() {
    long timeN = timeNanos();
    int totalT = (int) (timeN - cEntry) / 1000;
    AggregationKey key = newAggregationKey("Service time");
    addToAggregation(histogram, key, totalT);
        addToAggregation(average, key, totalT);
        addToAggregation(max, key, totalT);
        addToAggregation(min, key, totalT);
        addToAggregation(count, key, totalT);
    }

    @OnEvent(value="reset")
    public static void onReset() {
    println ("Data reset");
    clearAggregation(count);    
    clearAggregation(min);    
    clearAggregation(max);    
    clearAggregation(average);    
    clearAggregation(histogram);    
    }

    @OnTimer(3000)
    public static void onEvent() {
        println("Results. All times are in microseconds");
        println("---------------------------------------------");
        printAggregation("Count", count);
        printAggregation("Average", average);
        if (full) {
          printAggregation("Min", min);
          printAggregation("Max", max);
          printAggregation("Histogram", histogram);
       }
        println("---------------------------------------------");
    }
}

To run the script, execute the following -
# btrace <pid> GFV2HttpListenerServiceTime.java

Example:

# /home/binu/Utils/btrace/bin/btrace `jps | grep PEL | awk '{print $1}'` /home/binu/Utils/btrace/samples/GFV2HttpListenerServiceTime.java 

Results. All times are in microseconds
---------------------------------------------
Count
  Service time                                                  10811
Average
  Service time                                                    136
---------------------------------------------

Count is the number of invocations and Average is the average service time. Note that the service times are in micro-seconds.

 The script also supports a full option, which can be run using the --full argument as shown below.

# btrace <pid> GFV2HttpListenerServiceTime.java --full

Example:

# /home/binu/Utils/btrace/bin/btrace `jps | grep PEL | awk '{print $1}'` /home/binu/Utils/btrace/samples/GFV2HttpListenerServiceTime.java --full

Results. All times are in microseconds
---------------------------------------------
Count
  Service time                                                  22456
Average
  Service time                                                    120
Min
  Service time                                                     69
Max
  Service time                                                   3160
Histogram
  Service time
                  value  ------------- Distribution ------------- count
                     32 |                                         0
                     64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@             16229
                    128 |@@@@@@@@@@@                              6176
                    256 |                                         47
                    512 |                                         1
                   1024 |                                         1
                   2048 |                                         2
                   4096 |                                         0

---------------------------------------------





Comments:

Post a Comment:
Comments are closed for this entry.
About

binu

Search

Archives
« April 2014
SunMonTueWedThuFriSat
  
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
   
       
Today