Binu John's Weblog
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
---------------------------------------------
Posted at 06:31PM Apr 16, 2009 by binu in GlassFish |