97

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);
Improve this question

14 Answers 14

Reset to default
159 
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));
Improve this answer
Sign up to request clarification or add additional context in comments.

6 Comments

it should really be nanoTime actually
Should not be nanoTime. See rhu's answer.
Is there some particular reason you used "final" here? What would be different if you dropped that keyword?
@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-finalize it if you need to.
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.
|
35

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

Improve this answer

Comments

8

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;
Improve this answer

1 Comment

BalusC's answer is also correct; it depends on the needed timer resolution, and why you need the timing.
8

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.

Improve this answer

2 Comments

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.
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.
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);
Improve this answer

Comments

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

Improve this answer

2 Comments

+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!
All Codehaus services have been terminated. Your link is now broken.
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.

Improve this answer

Comments

1

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.

Improve this answer

1 Comment

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

Improve this answer

Comments

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.

Improve this answer

Comments

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());
Improve this answer

Comments

0

Have a look at System.currentTimeMillis().

Improve this answer

Comments

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]
Improve this answer

Comments

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");
   }
}
Improve this answer

Comments

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.