How do I time a method's execution in Java?

Question

How do I get a method's execution time? Is there a Timer utility class for things like timing how long a task takes, etc?

Most of the searches on Google return results for timers that schedule threads and tasks, which is not what I want.

Answer 1

Ok, this is a simple class to be used for simple simple timing of your functions. There is an example below it.

public class Stopwatch {
    static long startTime;
    static long splitTime;
    static long endTime;

    public Stopwatch() {
        start();
    }

    public void start() {
        startTime = System.currentTimeMillis();
        splitTime = System.currentTimeMillis();
        endTime = System.currentTimeMillis();
    }

    public void split() {
        split("");
    }

    public void split(String tag) {
        endTime = System.currentTimeMillis();
        System.out.println("Split time for [" + tag + "]: " + (endTime - splitTime) + " ms");
        splitTime = endTime;
    }

    public void end() {
        end("");
    }
    public void end(String tag) {
        endTime = System.currentTimeMillis();
        System.out.println("Final time for [" + tag + "]: " + (endTime - startTime) + " ms");
    }
}

Sample of use:

public static Schedule getSchedule(Activity activity_context) {
        String scheduleJson = null;
        Schedule schedule = null;
/*->*/  Stopwatch stopwatch = new Stopwatch();

        InputStream scheduleJsonInputStream = activity_context.getResources().openRawResource(R.raw.skating_times);
/*->*/  stopwatch.split("open raw resource");

        scheduleJson = FileToString.convertStreamToString(scheduleJsonInputStream);
/*->*/  stopwatch.split("file to string");

        schedule = new Gson().fromJson(scheduleJson, Schedule.class);
/*->*/  stopwatch.split("parse Json");
/*->*/  stopwatch.end("Method getSchedule"); 
    return schedule;
}

Sample of console output:

Split time for [file to string]: 672 ms
Split time for [parse Json]: 893 ms
Final time for [get Schedule]: 1565 ms

Answer 2

There are a couple of ways to do that. I normally fall back to just using something like this:

long start = System.currentTimeMillis();
// ... do something ...
long end = System.currentTimeMillis();

or the same thing with System.nanoTime();

For something more on the benchmarking side of things there seems also to be this one: http://jetm.void.fm/ Never tried it though.

Answer 3

Spring provides a utility class org.springframework.util.StopWatch, as per JavaDoc:

Simple stop watch, allowing for timing of a number of tasks, exposing total running time and running time for each named task.

Usage:

StopWatch stopWatch = new StopWatch("Performance Test Result");

stopWatch.start("Method 1");
doSomething1();//method to test
stopWatch.stop();

stopWatch.start("Method 2");
doSomething2();//method to test
stopWatch.stop();

System.out.println(stopWatch.prettyPrint());

Output:

StopWatch 'Performance Test Result': running time (millis) = 12829
-----------------------------------------
ms     %     Task name
-----------------------------------------
11907  036%  Method 1
00922  064%  Method 2

With Aspects:

@Around("execution(* my.package..*.*(..))")
public Object logTime(ProceedingJoinPoint joinPoint) throws Throwable {
    StopWatch stopWatch = new StopWatch();
    stopWatch.start();
    Object retVal = joinPoint.proceed();
    stopWatch.stop();
    log.info(" execution time: " + stopWatch.getTotalTimeMillis() + " ms");
    return retVal;
}

Answer 4

long startTime = System.currentTimeMillis();
// code goes here
long finishTime = System.currentTimeMillis();
long elapsedTime = finishTime - startTime; // elapsed time in milliseconds

Answer 5

We are using AspectJ and Java annotations for this purpose. If we need to know to execution time for a method, we simple annotate it. A more advanced version could use an own log level that can enabled and disabled at runtime.

public @interface Trace {
  boolean showParameters();
}

@Aspect
public class TraceAspect {
  [...]
  @Around("tracePointcut() && @annotation(trace) && !within(TraceAspect)")
  public Object traceAdvice ( ProceedingJintPoint jP, Trace trace ) {

    Object result;
    // initilize timer

    try { 
      result = jp.procced();
    } finally { 
      // calculate execution time 
    }

    return result;
  }
  [...]
}

Answer 6

Using AOP/AspectJ and @Loggable annotation from jcabi-aspects you can do it easy and compact:

@Loggable(Loggable.DEBUG)
public String getSomeResult() {
  // return some value
}

Every call to this method will be sent to SLF4J logging facility with DEBUG logging level. And every log message will include execution time.