95

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);
Willi Mentzel
  • 27,862
  • 20
  • 113
  • 121
George Mic
  • 985
  • 2
  • 8
  • 6

14 Answers14

155
final long startTime = System.currentTimeMillis();
for (int i = 0; i < length; i++) {
  // Do something
}
final long endTime = System.currentTimeMillis();

System.out.println("Total execution time: " + (endTime - startTime));
Willi Mentzel
  • 27,862
  • 20
  • 113
  • 121
bua
  • 4,761
  • 1
  • 26
  • 32
  • 2
    it should really be nanoTime actually – Eugene Nov 07 '12 at 15:35
  • 6
    Should not be nanoTime. See rhu's answer. – fabspro Feb 12 '13 at 13:56
  • 4
    Is there some particular reason you used "final" here? What would be different if you dropped that keyword? – dijxtra Aug 06 '13 at 08:03
  • 10
    @dijxtra using `final` has the advantage that you can't accidentally assign to it (as well as other advantages, such as anonymous class access, etc.). In this code it wouldn't make a difference. It's a fairly common practice to make everything `final` and only un-`final`ize it if you need to. – wchargin Aug 28 '13 at 17:12
  • 1
    The code to be tested, along with the time measurements, should be run multiple times and the first result should be discarded. The first will likely include class loading times etc. By running it multiples times also of course you get an average which is more helpful and reliable. – Arun Ramakrishnan Feb 19 '16 at 06:38
  • What guarantees that the compiler will not reorder the endTime sampling and the for-loop? – bobah Jun 21 '21 at 09:36
36

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

Community
  • 1
  • 1
rhu
  • 963
  • 5
  • 9
9

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.

BalusC
  • 1,082,665
  • 372
  • 3,610
  • 3,555
  • The timer on Windows doesn't have a particularly good resolution by default. There *is* a high-performance timer too, but it's much harder to use even from C and Java doesn't (AFAIK) provide access to that low a level of hackery without a JNI thunk. – Donal Fellows Apr 03 '10 at 22:47
  • 1
    `nanoTime()` has one problem (at least on Windows); the timestamp is specific to the processor core. I had a program that got a negative execution time because it got the "start" timestamp on one core, and the "stop" timestamp on another core. – gustafc Apr 03 '10 at 23:33
9

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;
Jonathan Feinberg
  • 44,698
  • 7
  • 80
  • 103
4

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);
DaveyDaveDave
  • 9,821
  • 11
  • 64
  • 77
SumiSujith
  • 475
  • 5
  • 9
3

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

SyntaxT3rr0r
  • 27,745
  • 21
  • 87
  • 120
  • +1 for pointing out auto-generator code. I use a similar statement all the time, and didn't know about inserting code templates. Just found out how to do that with eclipse, and it will definitely help! – Jason Apr 04 '10 at 03:01
  • All Codehaus services have been terminated. Your link is now broken. – naXa stands with Ukraine Jan 06 '16 at 08:21
2

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.

yegor256
  • 102,010
  • 123
  • 446
  • 597
1

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()

mprabhat
  • 20,107
  • 7
  • 46
  • 63
Jason
  • 11,263
  • 21
  • 87
  • 181
1

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.

Willi Mentzel
  • 27,862
  • 20
  • 113
  • 121
1

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());
San4musa
  • 277
  • 2
  • 12
0

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]
dotrc
  • 171
  • 2
  • 5
0

Have a look at System.currentTimeMillis().

Thomas
  • 174,939
  • 50
  • 355
  • 478
0
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");
   }
}
luis.espinal
  • 10,331
  • 6
  • 39
  • 55
0

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.

MarAja
  • 1,547
  • 4
  • 20
  • 36
  • This depends on how you run the code. If it's a piece of code running a server, then you're going to include startup time which is incorrect. – Arun Ramakrishnan Feb 19 '16 at 06:36