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

Viewed 870824
  1. How do I get a method's execution time?
  2. 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.

42 Answers

There is always the old-fashioned way:

long startTime = System.nanoTime();
methodToTime();
long endTime = System.nanoTime();

long duration = (endTime - startTime);  //divide by 1000000 to get milliseconds.

I go with the simple answer. Works for me.

long startTime = System.currentTimeMillis();

doReallyLongThing();

long endTime = System.currentTimeMillis();

System.out.println("That took " + (endTime - startTime) + " milliseconds");

It works quite well. The resolution is obviously only to the millisecond, you can do better with System.nanoTime(). There are some limitations to both (operating system schedule slices, etc.) but this works pretty well.

Average across a couple of runs (the more the better) and you'll get a decent idea.

Use a profiler (JProfiler, Netbeans Profiler, Visual VM, Eclipse Profiler, etc). You'll get the most accurate results and is the least intrusive. They use the built-in JVM mechanism for profiling which can also give you extra information like stack traces, execution paths, and more comprehensive results if necessary.

When using a fully integrated profiler, it's faily trivial to profile a method. Right click, Profiler -> Add to Root Methods. Then run the profiler just like you were doing a test run or debugger.

This probably isn't what you wanted me to say, but this is a good use of AOP. Whip an proxy interceptor around your method, and do the timing in there.

The what, why and how of AOP is rather beyond the scope of this answer, sadly, but that's how I'd likely do it.

Edit: Here's a link to Spring AOP to get you started, if you're keen. This is the most accessible implementation of AOP that Iive come across for java.

Also, given everyone else's very simple suggestions, I should add that AOP is for when you don't want stuff like timing to invade your code. But in many cases, that sort of simple and easy approach is fine.

Just a small twist, if you don't use tooling and want to time methods with low execution time: execute it many times, each time doubling the number of times it is executed until you reach a second, or so. Thus, the time of the Call to System.nanoTime and so forth, nor the accuracy of System.nanoTime does affect the result much.

    int runs = 0, runsPerRound = 10;
    long begin = System.nanoTime(), end;
    do {
        for (int i=0; i<runsPerRound; ++i) timedMethod();
        end = System.nanoTime();
        runs += runsPerRound;
        runsPerRound *= 2;
    } while (runs < Integer.MAX_VALUE / 2 && 1000000000L > end - begin);
    System.out.println("Time for timedMethod() is " + 
        0.000000001 * (end-begin) / runs + " seconds");

Of course, the caveats about using the wall clock apply: influences of JIT-compilation, multiple threads / processes etc. Thus, you need to first execute the method a lot of times first, such that the JIT compiler does its work, and then repeat this test multiple times and take the lowest execution time.

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;
  }
  [...]
}

I have written a method to print the method execution time in a much readable form. For example, to calculate the factorial of 1 Million, it takes approximately 9 minutes. So the execution time get printed as:

Execution Time: 9 Minutes, 36 Seconds, 237 MicroSeconds, 806193 NanoSeconds

The code is here:

public class series
{
    public static void main(String[] args)
    {
        long startTime = System.nanoTime();

        long n = 10_00_000;
        printFactorial(n);

        long endTime = System.nanoTime();
        printExecutionTime(startTime, endTime);

    }

    public static void printExecutionTime(long startTime, long endTime)
    {
        long time_ns = endTime - startTime;
        long time_ms = TimeUnit.NANOSECONDS.toMillis(time_ns);
        long time_sec = TimeUnit.NANOSECONDS.toSeconds(time_ns);
        long time_min = TimeUnit.NANOSECONDS.toMinutes(time_ns);
        long time_hour = TimeUnit.NANOSECONDS.toHours(time_ns);

        System.out.print("\nExecution Time: ");
        if(time_hour > 0)
            System.out.print(time_hour + " Hours, ");
        if(time_min > 0)
            System.out.print(time_min % 60 + " Minutes, ");
        if(time_sec > 0)
            System.out.print(time_sec % 60 + " Seconds, ");
        if(time_ms > 0)
            System.out.print(time_ms % 1E+3 + " MicroSeconds, ");
        if(time_ns > 0)
            System.out.print(time_ns % 1E+6 + " NanoSeconds");
    }
}

In Spring framework we have a call called StopWatch (org.springframework.util.StopWatch)

//measuring elapsed time using Spring StopWatch
        StopWatch watch = new StopWatch();
        watch.start();
        for(int i=0; i< 1000; i++){
            Object obj = new Object();
        }
        watch.stop();
        System.out.println("Total execution time to create 1000 objects in Java using StopWatch in millis: "
                + watch.getTotalTimeMillis());

I basically do variations of this, but considering how hotspot compilation works, if you want to get accurate results you need to throw out the first few measurements and make sure you are using the method in a real world (read application specific) application.

If the JIT decides to compile it your numbers will vary heavily. so just be aware

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.

If you want wall-clock time

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

As "skaffman" said, use AOP OR you can use run time bytecode weaving, just like unit test method coverage tools use to transparently add timing info to methods invoked.

You can look at code used by open source tools tools like Emma (http://downloads.sourceforge.net/emma/emma-2.0.5312-src.zip?modtime=1118607545&big_mirror=0). The other opensource coverage tool is http://prdownloads.sourceforge.net/cobertura/cobertura-1.9-src.zip?download.

If you eventually manage to do what you set out for, pls. share it back with the community here with your ant task/jars.

You can try this way if just want know the time.

long startTime = System.currentTimeMillis();
//@ Method call
System.out.println("Total time [ms]: " + (System.currentTimeMillis() - startTime));    

For java 8+, another possible solution (more general, func-style and without aspects) could be to create some utility method accepting code as a parameter

public static <T> T timed (String description, Consumer<String> out, Supplier<T> code) {
    final LocalDateTime start = LocalDateTime.now ();
    T res = code.get ();
    final long execTime = Duration.between (start, LocalDateTime.now ()).toMillis ();
    out.accept (String.format ("%s: %d ms", description, execTime));
    return res;
}

And the calling code could be smth like that:

public static void main (String[] args) throws InterruptedException {
    timed ("Simple example", System.out::println, Timing::myCode);
}

public static Object myCode () {
    try {
        Thread.sleep (1500);
    } catch (InterruptedException e) {
        e.printStackTrace ();
    }
    return null;
}

Also could be implemented Timer interface and executed on any method of your class

import java.util.function.*;

public interface Timer {

    default void timeIt(Runnable r) {
        timeIt(() -> { r.run(); return 0;});
    }

    default <S,T> T timeIt(Function<S,T> fun, S arg) {
        long start = System.nanoTime();
        T result = fun.apply(arg);
        long stop = System.nanoTime();
        System.out.println("Time: " + (stop-start)/1000000.0 + " msec");
        return result;
    }

    default <T> T timeIt(Supplier<T> s) {
        return timeIt(obj -> s.get(), null);
    }
}

Usage:

class MyClass implements Timer ..

timeIt(this::myFunction); 

There's a lot of valid answers here, all of which are implemented within the method. To make a general purpose method for timing I generally have a Timing class consisting of the following.

public record TimedResult<T>(T result, Duration duration) {}

public static Duration time(Runnable r) {
    var s = Instant.now();
    r.run();
    var dur = Duration.between(s, Instant.now());
    return dur;
}

public static <T> TimedResult<T> time(Callable<T> r) throws Exception {
    var s = Instant.now();
    T res = r.call();
    var dur = Duration.between(s, Instant.now());
    return new TimedResult<>(res, dur);
}

This is general enough to pass a Runnable or Callable.

Duration result = Timing.time(() -> {
    // do some work.
});

TimedResult<String> result = Timing.time(() -> {
    // do some work.
    return "answer";
});

Duration timeTaken = result.duration();
String answer = result.result();

Pure Java SE code, no need for adding dependency, using TimeTracedExecuter :

public static void main(String[] args) {

    Integer square = new TimeTracedExecutor<>(Main::calculateSquare)
                .executeWithInput("calculate square of num",5,logger);

}
public static int calculateSquare(int num){
    return num*num;
}

Will produce result like this:

INFO: It took 3 milliseconds to calculate square of num

Custom reusable class: TimeTracedExecutor

import java.text.NumberFormat;
import java.time.Duration;
import java.time.Instant;
import java.util.function.Function;
import java.util.logging.Logger;

public class TimeTracedExecutor<T,R> {
    Function<T,R> methodToExecute;

    public TimeTracedExecutor(Function<T, R> methodToExecute) {
        this.methodToExecute = methodToExecute;
    }

    public R executeWithInput(String taskDescription, T t, Logger logger){
        Instant start = Instant.now();
        R r= methodToExecute.apply(t);
        Instant finish = Instant.now();
        String format = "It took %s milliseconds to "+taskDescription;
        String elapsedTime = NumberFormat.getNumberInstance().format(Duration.between(start, finish).toMillis());
        logger.info(String.format(format, elapsedTime));
        return r;
    }
}
Related