If you want to dig into why certain method runs slow than you expected, then you can do performance profiling by Btrace, Here is some simple example i used before, hope this helps, BTW, I used JVisualVM Btrace plugin, it is really easy of use, but Be caution with bugs :)
Calculate method execution time:
/* BTrace Script Template */
package com.sun.btrace.samples;
import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;
import com.sun.btrace.aggregation.*;
@BTrace
public class MethodResponseTime {
/* put your code here */
@TLS
private static long starttime;
private static Aggregation average = newAggregation(AggregationFunction.AVERAGE);
private static Aggregation globalcount = newAggregation(AggregationFunction.COUNT);
@OnMethod(
clazz = "com.myapp.service.pipeline.PipelineServlet",
method = "execute"
)
public static void onCall(){
println("enter this method!");
starttime = timeNanos();
}
@OnMethod(
clazz = "com.myapp.operations.PrePopulateResponse",
method = "execute",
location = @Location(Kind.RETURN)
)
public static void onReturn(){
println("Method End!");
int duration = (int)(timeNanos()- starttime)/1000000;
println(duration);
addToAggregation(average,duration);
addToAggregation(globalcount,duration);
}
@OnTimer(20000)
public static void onEvent(){
println("----------------");
printAggregation("Average", average);
printAggregation("Global Count", globalcount);
println("----------------");
}
}
------------------------------------------------------------
Execution time between code lines:
/* BTrace Script Template */
package com.sun.btrace.samples;
import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;
import com.sun.btrace.aggregation.*;
@BTrace
public class CodeLines {
@TLS private static long startTime;
@OnMethod(
clazz="com.myapp.impl.CommonResourceChangePollingImpl",
location=@Location(value=Kind.LINE, line=97)
)
public static void onEnter(){
//println("enter this method");
startTime= timeNanos();
}
@OnMethod(
clazz="com.myapp.impl.CommonResourceChangePollingImpl",
location=@Location(value=Kind.LINE, line=100)
)
public static void onReturn(){
//println("method end!");
int duration = (int)(timeNanos()-startTime)/1000000;
println(duration);
addToAggregation(average,duration);
addToAggregation(globalCount, duration);
}
@OnTimer(30000)
public static void onEvent() {
println("---------------------------------------------");
printAggregation("Average", average);
printAggregation("Global Count", globalCount);
println("---------------------------------------------");
}
}
PS: it calculates from code line 97 to 100 , but not including 100 execution time itself
--------------------------------------------------------------
Call dump trace:
/* BTrace Script Template */
package com.sun.btrace.samples;
import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;
import com.sun.btrace.aggregation.*;
@BTrace
public class CallTree {
@OnMethod(
clazz="com.myapp.impl.CommonResourceChangePollingImpl",
method="getResourceChanges",
location=@Location(value=Kind.LINE, line=-1)
)
public static void online(@ProbeClassName String pcn, @ProbeMethodName String pmn, int line) {
print(strcat(pcn, "."));
print(strcat(pmn, ":"));
println(line);
}
}
-----------------------------------------------------------
Regular expression match on Clazz:
/* BTrace Script Template */
package com.sun.btrace.samples;
import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;
import com.sun.btrace.aggregation.*;
@BTrace
public class RegexMatch {
@OnMethod(
clazz="/com\\.mycompany\\.service\\..*/",
location=@Location(value=Kind.LINE, line=-1)
)
public static void online(@ProbeClassName String pcn, @ProbeMethodName String pmn, int line) {
print(strcat(pcn, "."));
print(strcat(pmn, ":"));
println(line);
}
}
