How to measure the time spent on methods execution in Java

In this tutorial we will show how to measure the time spent on the execution of a Java method by using Byteman tool.

There are several tools or product which can trace the execution of Java methods and calculate how much time you are spending in the single methods of your application. This is a key aspect to identify bottlenecks in your code. The great advantage of Byteman is that you won’t need to change a single line of code in your application but you will rely completely on simple Byteman script that will be injected in your JVM.

So, supposing you want to trace how much time you are spending in the method “doSend” of the class “org.springframework.jms.core.JmsTemplate” then you will have to add two Rules:

1) A Rule for capturing the start time, when the method has been fired.

2) A Rule to measure the time spent when the method has terminated the execution. A Linked map is used to store the Start Time and the Thread used to run the method.

Here is our Byteman Rule file:

RULE doSend start time
CLASS org.springframework.jms.core.JmsTemplate
METHOD doSend
AT ENTRY
BIND thread = Thread.currentThread();
startTime = System.currentTimeMillis()
IF true
DO link("doSend.org.springframework.jms.core.JmsTemplate", thread, startTime)
ENDRULE

RULE doSend end time
CLASS org.springframework.jms.core.JmsTemplate
METHOD doSend
AT EXIT
BIND thread = Thread.currentThread();
startTime:int = unlink("doSend.org.springframework.jms.core.JmsTemplate", thread);
endTime = System.currentTimeMillis()
IF true
DO traceln("[BYTEMAN] org.springframework.jms.core.JmsTemplate.doSend elapsedTime = " + (endTime - startTime))
ENDRULE

To install the Rule on WildFly:

1) Download and unzip the file byteman.zip (Available at: https://byteman.jboss.org/downloads.html)

2) It is recommended to set this location in the environment variable BYTEMAN_HOME:

Ex.

$ export BYTEMAN_HOME=/home/jboss/byteman

3) Copy the above file rule.btm in all the $JBOSS_HOME/bin folders (It can be placed also in another folder, but if so you need to specify the full path of the Rule in the JVM settings)

4) Add the following JVM settings to WildFly/EAP:

-Dorg.jboss.byteman.transform.all -javaagent:${BYTEMAN_HOME}/lib/byteman.jar=script:rule.btm,boot:${BYTEMAN_HOME}/lib/byteman.jar -Dorg.jboss.byteman.debug=true

That’s all you need to instrument the Rule file.

If all the above steps have been executed correctly, you will see in your server log this information, which shows the time spent on the methods specified in the Rule file:

09:52:24,001 INFO  [stdout] (ServerService Thread Pool -- 92) [BYTEMAN] org.springframework.jms.core.JmsTemplate.doSend elapsedTime = 34

Measuring time spent on method execution using Spring

For the sake of completeness, you are using entirely Spring Beans in your applications, you can use AspectJ as wrapper around your method execution. The advantage of this approach is that you can use wildcards to capture a set of packages. See the following example:

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;

@Aspect
public class MyProfiler {

    @Pointcut("execution(* com.sample.*.*(..))")
    public void businessMethods() { }

    @Around("businessMethods()")
    public Object profile(ProceedingJoinPoint pjp) throws Throwable {

        long start = System.currentTimeMillis();
        System.out.println("Going to call the method."+pjp.getTarget());
        Object output = pjp.proceed();
        System.out.println("Method execution completed."+pjp.getTarget());
        long elapsedTime = System.currentTimeMillis() - start;
        System.out.println("Method execution time: " + elapsedTime + " milliseconds.");
        return output;
    }

}

In this code, we are capturing the execution of all methods in the com.sample packages.

@PointCut − Marks a function as a PointCut

@Around is an advice type, which ensures that an advice can run before and after the method execution.