[java] How to time Java program execution speed

How do you time the execution of a java program? I'm not sure what class I should use to do this.

I'm kinda looking for something like:

// Some timer starts here
for (int i = 0; i < length; i++) {
  // Do something
}
// End timer here

System.out.println("Total execution time: " + totalExecutionTime);

Here are a few ways to find the execution time in Java:

1) System.nanoTime()

long startTime = System.nanoTime();
.....your code....
long endTime   = System.nanoTime();
long totalTime = endTime - startTime;
System.out.println("Execution time in nanoseconds  : " + totalTime);
System.out.println("Execution time in milliseconds : " + totalTime / 1000000);

2) System.currentTimeMillis()

long startTime = System.currentTimeMillis();
.....your code....
long endTime = System.currentTimeMillis();
long totalTime = endTime - startTime;
System.out.println("Execution time in milliseconds  : " + totalTime);

3) Instant.now()

long startTime = Instant.now().toEpochMilli();
.....your code....
long endTime = Instant.now().toEpochMilli();
long totalTime = endTime - startTime;
System.out.println("Execution time in milliseconds: " + totalTime);

or

Instant start = Instant.now();
.....your code....
Instant end = Instant.now();
Duration interval = Duration.between(start, end);
System.out.println("Execution time in seconds: " +interval.getSeconds());

4) Date.getTime()

long startTime = new Date().getTime();
.....your code....
long endTime = new Date().getTime();
long totalTime = endTime - startTime;
System.out.println("Execution time in milliseconds: " + totalTime);

Using System.currentTimeMillis() is the proper way of doing this. But, if you use command line, and you want to time the whole program approximately and quickly, think about:

time java App

which allows you not to modify the code and time your App.

public class someClass
{
   public static void main(String[] args) // your app start point
   {
       long start = java.util.Calendar.getInstance().getTimeInMillis();

       ... your stuff ...

       long end = java.util.Calendar.getInstance().getTimeInMillis();
       System.out.println("it took this long to complete this stuff: " + (end - start) + "ms");
   }
}

For simple stuff, System.currentTimeMillis() can work.

It's actually so common that my IDE is setup so that upon entering "t0" it generates me the following line:

final long t0 = System.currentTimeMillis()

But for more complicated things, you'll probably want to use statistical time measurements, like here (scroll down a bit and look at the time measurements expressed including standard deviations etc.):

http://perf4j.codehaus.org/devguide.html

I created a higher order function which takes the code you want to measure in/as a lambda:

class Utils {

    public static <T> T timeIt(String msg, Supplier<T> s) {
        long startTime = System.nanoTime();
        T t = s.get();
        long endTime = System.nanoTime();
        System.out.println(msg + ": " + (endTime - startTime) + " ns");
        return t;
    }

    public static void timeIt(String msg, Runnable r) {
       timeIt(msg, () -> {r.run(); return null; });
    }
}

Call it like that:

Utils.timeIt("code 0", () ->
        System.out.println("Hallo")
);

// in case you need the result of the lambda
int i = Utils.timeIt("code 1", () ->
        5 * 5
);

Output:

code 0: 180528 ns
code 1: 12003 ns

_{Special thanks to Andy Turner who helped me cut down the redundancy. See here.}

You may also try Perf4J. Its a neat way of doing what you are looking for, and helps in aggregated performance statistics like mean, minimum, maximum, standard deviation and transactions per second over a set time span. An extract from http://perf4j.codehaus.org/devguide.html:

StopWatch stopWatch = new LoggingStopWatch();

try {
    // the code block being timed - this is just a dummy example
    long sleepTime = (long)(Math.random() * 1000L);
    Thread.sleep(sleepTime);
    if (sleepTime > 500L) {
        throw new Exception("Throwing exception");
    }

    stopWatch.stop("codeBlock2.success", "Sleep time was < 500 ms");
} catch (Exception e) {
    stopWatch.stop("codeBlock2.failure", "Exception was: " + e);
}

Output:

INFO: start[1230493236109] time[447] tag[codeBlock2.success] message[Sleep time was < 500 ms]
INFO: start[1230493236719] time[567] tag[codeBlock2.failure] message[Exception was: java.lang.Exception: Throwing exception]
INFO: start[1230493237286] time[986] tag[codeBlock2.failure] message[Exception was: java.lang.Exception: Throwing exception]
INFO: start[1230493238273] time[194] tag[codeBlock2.success] message[Sleep time was < 500 ms]
INFO: start[1230493238467] time[463] tag[codeBlock2.success] message[Sleep time was < 500 ms]
INFO: start[1230493238930] time[310] tag[codeBlock2.success] message[Sleep time was < 500 ms]
INFO: start[1230493239241] time[610] tag[codeBlock2.failure] message[Exception was: java.lang.Exception: Throwing exception]
INFO: start[1230493239852] time[84] tag[codeBlock2.success] message[Sleep time was < 500 ms]
INFO: start[1230493239937] time[30] tag[codeBlock2.success] message[Sleep time was < 500 ms]
INFO: start[1230493239968] time[852] tag[codeBlock2.failure] message[Exception was: java.lang.Exception: Throwing exception]

Have a look at System.currentTimeMillis().

use long startTime=System.currentTimeMillis() for start time, at the top of the loop

put long endTime= System.currentTimeMillis(); outside the end of the loop. You'll have to subtract the values to get the runtime in milliseconds.

If you want time in nanoseconds, check out System.nanoTime()

You can make use of System#nanoTime(). Get it before and after the execution and just do the math. It's preferred above System#currentTimeMillis() because it has a better precision. Depending on the hardware and the platform used, you may otherwise get an incorrect gap in elapsed time. Here with Core2Duo on Windows, between about 0 and ~15ms actually nothing can be calculated.

A more advanced tool is a profiler.

You can use Stopwatch

import com.google.common.base.Stopwatch;

Stopwatch timer = Stopwatch.createStarted();
//lines to be executed
System.out.println("Execution time= " + timer.stop());

You get the current system time, in milliseconds:

final long startTime = System.currentTimeMillis();

Then you do what you're going to do:

for (int i = 0; i < length; i++) {
  // Do something
}

Then you see how long it took:

final long elapsedTimeMillis = System.currentTimeMillis() - startTime;

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.

Be aware that there are some issues where System#nanoTime() cannot be reliably used on multi-core CPU's to record elapsed time ... each core has maintains its own TSC (Time Stamp Counter): this counter is used to obtain the nano time (really it is the number of ticks since the CPU booted).

Hence, unless the OS does some TSC time warping to keep the cores in sync, then if a thread gets scheduled on one core when the initial time reading is taken, then switched to a different core, the relative time can sporadically appear to jump backwards and forwards.

I observed this some time ago on AMD/Solaris where elapsed times between two timing points were sometimes coming back as either negative values or unexpectedly large positive numbers. There was a Solaris kernel patch and a BIOS setting required to force the AMD PowerNow! off, which appeared to solved it.

Also, there is (AFAIK) a so-far unfixed bug when using java System#nanoTime() in a VirtualBox environment; causing all sorts of bizarre intermittent threading problems for us as much of the java.util.concurrency package relies on nano time.

See also:

Is System.nanoTime() completely useless? http://vbox.innotek.de/pipermail/vbox-trac/2010-January/135631.html