1012
  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.

nabster
  • 1,561
  • 2
  • 20
  • 32
Ogre Psalm33
  • 21,366
  • 16
  • 74
  • 92
  • Later similar Question: [How do I write a correct micro-benchmark in Java?](http://stackoverflow.com/q/504103/642706) – Basil Bourque Jul 01 '16 at 22:48
  • JAMon API is a free, simple, high performance, thread safe, Java API that allows developers to easily monitor the performance and scalability of production applications. JAMon tracks hits, execution times (total, avg, min, max, std dev), and more. [http://jamonapi.sourceforge.net/](http://jamonapi.sourceforge.net/) download : [http://sourceforge.net/project/showfiles.php?group_id=96550](http://sourceforge.net/project/showfiles.php?group_id=96550) – Mike Pone Oct 07 '08 at 21:47
  • 2
    You might also want to look at the [Apache Commons Lang StopWatch](http://commons.apache.org/proper/commons-lang/javadocs/api-release/org/apache/commons/lang3/time/StopWatch.html) class. A simple but useful utility class. –  May 05 '09 at 13:10
  • Yes, StopWatch is great for this. – Shubham Pandey Aug 01 '19 at 06:08
  • Java 8 using `Instant` class: https://stackoverflow.com/a/30975902/1216775 – akhil_mittal Aug 01 '19 at 11:36

42 Answers42

1445

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.
michaelsnowden
  • 6,031
  • 2
  • 38
  • 83
Diastrophism
  • 15,139
  • 1
  • 16
  • 7
  • 272
    actually, its "new-fashioned" because you used nanoTime, which wasn't added until java5 – John Gardner Oct 07 '08 at 22:26
  • 11
    This (or using System.currentTimeMillis()) seems to be the way it's usually done in Java...that I've seen anyway. It still mildly suprises me that there's no spiffy built-in class, like Timer t = new Timer(); String s = t.getElapsed(format); etc... – Ogre Psalm33 Oct 08 '08 at 12:48
  • 18
    nanoTime does not guarantee accuracy better than currentTimeMillis(), though it usually does. http://forums.sun.com/thread.jspa?messageID=9460663 and http://www.simongbrown.com/blog/2007/08/20/millisecond_accuracy_in_java.html – James Schek Oct 08 '08 at 17:20
  • 11
    Of course, it's always important to remember the pitfalls of micro-benchmarking, such as compiler/JVM optimizations that may distort the result =8-) – Yuval Jan 07 '09 at 15:26
  • 18
    There is no need for a finally block as endTime won't be used if an exception is thrown. – Peter Lawrey May 05 '09 at 19:42
  • From the javadoc for System.currentTimeMillis() "...many operating systems measure time in units of tens of milliseconds". And this is true, on my windows box it seems to be about 16 ms. Remember, there are two clocks in there. So never use currentTimeMillis to measure elapsed time. If you need millis, just divide the result by 1 million – James Scriven May 25 '11 at 14:22
  • 1
    if between start and end time the Thread got suspended then end time will actually reflect the suspend time as well. so the end-start will not be the actual time Thread spent in execution. – Java Spring Coder Mar 25 '13 at 23:32
  • OK, This is nice. But, how to UNIT TEST this behavior ? i.e I want to assert the the method returns the execution time which is the difference between endTime and startTime. – Adelin May 10 '13 at 11:08
  • 8
    @JamesSchek Be careful with your wording there, `nanoTime` is guaranteed to be _at least as resolute_ as `currentTimeMillis`. http://docs.oracle.com/javase/7/docs/api/java/lang/System.html#nanoTime%28%29 – arkon May 18 '13 at 15:33
  • @OgrePsalm33 Java 7 has a Timer class, but it's used for scheduling tasks. – Chthonic Project Jul 24 '13 at 18:25
  • @ChthonicProject But of course. My example class name was just a fictitious representation. – Ogre Psalm33 Jul 25 '13 at 12:47
  • This answer is not really correct, check my answer if you are looking for time consumed only by your application. – TondaCZE Apr 06 '14 at 13:49
  • 2
    Please refer this answer http://stackoverflow.com/a/3383047/870547 to do it in Java 8 way – Kay Gee Dec 05 '14 at 18:56
  • This is a Stopwatch I made, it lets you add named timers statically. It's very simple to use, see Class' DocBlock. https://gist.github.com/juanmf/4147a9b7010c7b04c003 you want to put it in your util package – juanmf Nov 08 '15 at 22:40
  • 2
    It should be noted that `System.currentTimeMillis()` returns what the OS thinks is the time since the Unix epoch. If your user (or the OS itself) changes the OS time in between calls to `System.currentTimeMillis()`, then you could get strange results. `nanoTime` is unaffected by changes to the OS clock time, so is more reliable. – daiscog Jun 02 '16 at 18:56
  • I had to cast `endTime` to `double` when dividing by 1000000000 (a billion) to get seconds: `double duration = ((double)endTime - startTime) / 1000000000;` – Sam Malayek Jul 23 '18 at 04:12
  • take care about async methods with this, since you will need an interface to know when those methods finish – Gastón Saillén Sep 25 '18 at 13:48
  • 1
    also keep in mind that the number you end up with is slightly influenced by the time needed to execute the calls to get the timestamps. – jwenting Oct 01 '18 at 07:58
  • 2
    As an improvement, a better way to extract the number of millis passed would be the following: `double time = (endTime - startTime) * 1e-6;` It's concise, faster than division, unambiguous as to the number of decimal places, and cast implicitly to a double with the `1e-6` literal ( see https://stackoverflow.com/questions/15527198/is-scientific-notation-interpreted-as-int-or-float ) – JJ Brown Dec 10 '18 at 17:38
  • 3
    @JohnGardner Now it's old fashioned. :) – Kröw May 18 '19 at 01:29
  • @Kröw indeeded it is. old-old-new by now? – John Gardner May 23 '19 at 18:59
255

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.

MBCook
  • 14,424
  • 7
  • 37
  • 41
  • 63
    Actually, System.currentTimeMillis() is only accurate above 15ms. For really low values it can't be trusted. The solution for this (as mentioned) is System.nanoTime(); – Steve g Oct 07 '08 at 21:38
  • Ok, I was about to accept this as the official answer until I read Steve g's comment. Great tidbit, Steve! – Ogre Psalm33 Oct 08 '08 at 12:15
  • 6
    nanoTime() does not guarantee accuracy better than currentTimeMillis, but many JVM implementations do have better accuracy with nanoTime. – James Schek Oct 08 '08 at 17:22
  • 8
    @JamesSchek You really need to watch your wording, as I already mentioned to this identical comment elsewhere; `nanoTime` is guaranteed to be _at least as resolute_ as `currentTimeMillis`. http://docs.oracle.com/javase/7/docs/api/java/lang/System.html#nanoTime%28%29 – arkon May 18 '13 at 15:37
  • 1
    The one slight advantage of `currentTimeMillis` is that it's an actual timestamp, and could be used to log start/end times as well, while `nanoTime` "can only be used to measure elapsed time and is not related to any other notion of system or wall-clock time." – Brad Parks Nov 28 '16 at 14:17
  • System.currentTimeMillis() is actually deprecated for measuring elapsed time. It is designed to return accurate wall clock time, which occasionally jumps around, e.g. jump forward/backward an hour for daily savings time transitions, or jumps forwards as second for occasional "leap seconds". These are bad things for measuring elapsed time. Otoh, `System.nanotime()` is expressly designed for measuring elapsed time and is guaranteed to never jump forward or backwards. That said, it is often negative. So you always have to take the difference between two times to arrive at a valid duration. – Charlie Reitzel Jul 26 '23 at 18:26
202

Come on guys! Nobody mentioned the Guava way to do that (which is arguably awesome):

import com.google.common.base.Stopwatch;

Stopwatch timer = Stopwatch.createStarted();
//method invocation
LOG.info("Method took: " + timer.stop());

The nice thing is that Stopwatch.toString() does a good job of selecting time units for the measurement. I.e. if the value is small, it'll output 38 ns, if it's long, it'll show 5m 3s

Even nicer:

Stopwatch timer = Stopwatch.createUnstarted();
for (...) {
   timer.start();
   methodToTrackTimeFor();
   timer.stop();
   methodNotToTrackTimeFor();
}
LOG.info("Method took: " + timer);

Note: Google Guava requires Java 1.6+

bramp
  • 9,581
  • 5
  • 40
  • 46
Dmitry Kalashnikov
  • 2,021
  • 1
  • 12
  • 3
171

Using Instant and Duration from Java 8's new API,

Instant start = Instant.now();
Thread.sleep(5000);
Instant end = Instant.now();
System.out.println(Duration.between(start, end));

outputs,

PT5S
beldaz
  • 4,299
  • 3
  • 43
  • 63
Sufiyan Ghori
  • 18,164
  • 14
  • 82
  • 110
  • 2
    Thanks, How can I output the result without having the PT in front? – java123999 Mar 16 '16 at 15:31
  • 1
    The problem with method is that Instant does not problem milli and nano second precision. Ref: http://stackoverflow.com/questions/20689055/java-8-instant-now-with-nanosecond-resolution – prashantsunkari Apr 12 '17 at 22:56
  • 10
    @java123999: You can call `Duration.between(start, end).getSeconds()`. `Duration` also has methods to convert to other time units, e.g. `toMillis()` which converts to milliseconds. – Emil Lunde May 29 '18 at 13:29
160

Gathered all possible ways together into one place.

Date

Date startDate = Calendar.getInstance().getTime();
long d_StartTime = new Date().getTime();
Thread.sleep(1000 * 4);
Date endDate = Calendar.getInstance().getTime();
long d_endTime = new Date().getTime();
System.out.format("StartDate : %s, EndDate : %s \n", startDate, endDate);
System.out.format("Milli = %s, ( D_Start : %s, D_End : %s ) \n", (d_endTime - d_StartTime),d_StartTime, d_endTime);

System.currentTimeMillis()

long startTime = System.currentTimeMillis();
Thread.sleep(1000 * 4);
long endTime = System.currentTimeMillis();
long duration = (endTime - startTime);  
System.out.format("Milli = %s, ( S_Start : %s, S_End : %s ) \n", duration, startTime, endTime );
System.out.println("Human-Readable format : "+millisToShortDHMS( duration ) );

Human Readable Format

public static String millisToShortDHMS(long duration) {
    String res = "";    // java.util.concurrent.TimeUnit;
    long days       = TimeUnit.MILLISECONDS.toDays(duration);
    long hours      = TimeUnit.MILLISECONDS.toHours(duration) -
                      TimeUnit.DAYS.toHours(TimeUnit.MILLISECONDS.toDays(duration));
    long minutes    = TimeUnit.MILLISECONDS.toMinutes(duration) -
                      TimeUnit.HOURS.toMinutes(TimeUnit.MILLISECONDS.toHours(duration));
    long seconds    = TimeUnit.MILLISECONDS.toSeconds(duration) -
                      TimeUnit.MINUTES.toSeconds(TimeUnit.MILLISECONDS.toMinutes(duration));
    long millis     = TimeUnit.MILLISECONDS.toMillis(duration) - 
                      TimeUnit.SECONDS.toMillis(TimeUnit.MILLISECONDS.toSeconds(duration));

    if (days == 0)      res = String.format("%02d:%02d:%02d.%04d", hours, minutes, seconds, millis);
    else                res = String.format("%dd %02d:%02d:%02d.%04d", days, hours, minutes, seconds, millis);
    return res;
}

Guava: Google StopwatchJAR « An object of Stopwatch is to measures elapsed time in nanoseconds.

com.google.common.base.Stopwatch g_SW = Stopwatch.createUnstarted();
g_SW.start();
Thread.sleep(1000 * 4);
g_SW.stop();
System.out.println("Google StopWatch  : "+g_SW);

Apache Commons LangJAR « StopWatch provides a convenient API for timings.

org.apache.commons.lang3.time.StopWatch sw = new StopWatch();
sw.start();     
Thread.sleep(1000 * 4);     
sw.stop();
System.out.println("Apache StopWatch  : "+ millisToShortDHMS(sw.getTime()) );

JODA-TIME

public static void jodaTime() throws InterruptedException, ParseException{
    java.text.SimpleDateFormat ms_SDF = new SimpleDateFormat("yyyy/MM/dd HH:mm:ss.SSS");
    String start = ms_SDF.format( new Date() ); // java.util.Date

    Thread.sleep(10000);

    String end = ms_SDF.format( new Date() );       
    System.out.println("Start:"+start+"\t Stop:"+end);

    Date date_1 = ms_SDF.parse(start);
    Date date_2 = ms_SDF.parse(end);        
    Interval interval = new org.joda.time.Interval( date_1.getTime(), date_2.getTime() );
    Period period = interval.toPeriod(); //org.joda.time.Period

    System.out.format("%dY/%dM/%dD, %02d:%02d:%02d.%04d \n", 
        period.getYears(), period.getMonths(), period.getDays(),
        period.getHours(), period.getMinutes(), period.getSeconds(), period.getMillis());
}

Java date time API from Java 8 « A Duration object represents a period of time between two Instant objects.

Instant start = java.time.Instant.now();
    Thread.sleep(1000);
Instant end = java.time.Instant.now();
Duration between = java.time.Duration.between(start, end);
System.out.println( between ); // PT1.001S
System.out.format("%dD, %02d:%02d:%02d.%04d \n", between.toDays(),
        between.toHours(), between.toMinutes(), between.getSeconds(), between.toMillis()); // 0D, 00:00:01.1001 

Spring Framework provides StopWatch utility class to measure elapsed time in Java.

StopWatch sw = new org.springframework.util.StopWatch();
sw.start("Method-1"); // Start a named task
    Thread.sleep(500);
sw.stop();

sw.start("Method-2");
    Thread.sleep(300);
sw.stop();

sw.start("Method-3");
    Thread.sleep(200);
sw.stop();

System.out.println("Total time in milliseconds for all tasks :\n"+sw.getTotalTimeMillis());
System.out.println("Table describing all tasks performed :\n"+sw.prettyPrint());

System.out.format("Time taken by the last task : [%s]:[%d]", 
        sw.getLastTaskName(),sw.getLastTaskTimeMillis());

System.out.println("\n Array of the data for tasks performed « Task Name: Time Taken");
TaskInfo[] listofTasks = sw.getTaskInfo();
for (TaskInfo task : listofTasks) {
    System.out.format("[%s]:[%d]\n", 
            task.getTaskName(), task.getTimeMillis());
}

OutPut:

Total time in milliseconds for all tasks :
999
Table describing all tasks performed :
StopWatch '': running time (millis) = 999
-----------------------------------------
ms     %     Task name
-----------------------------------------
00500  050%  Method-1
00299  030%  Method-2
00200  020%  Method-3

Time taken by the last task : [Method-3]:[200]
 Array of the data for tasks performed « Task Name: Time Taken
[Method-1]:[500]
[Method-2]:[299]
[Method-3]:[200]
Yash
  • 9,250
  • 2
  • 69
  • 74
  • Stopwatch of Guava, Apache Commons and Spring Framework are not thread safe. Not safe for production usage. – Deepak Puthraya Jun 12 '18 at 19:25
  • @DeepakPuthraya then which library to use which is safe for production usage? – Gaurav Sep 24 '19 at 07:24
  • 1
    @DeepakPuthraya you can use java 8 provided Java date time API. Which is simple. – Yash Sep 24 '19 at 07:48
  • 2
    IMO this post would benefit if every solution would also show the output of the system outs. – BAERUS Apr 28 '20 at 15:23
  • 1
    `new Date().getTime()` is just a `System.currentTimeMillis()` in disguise. `new Date()` does the same as `new Date(System.currentTimeMillis())` and `getTime()` will just return that `long` value (and that’s the only feature of this class that has not been marked as deprecated). Likewise, `Calendar.getInstance().getTime()` produces exactly the same as `new Date()`, but with significantly more overhead, as it will prepare things that this code snippet doesn’t use. – Holger Nov 03 '22 at 16:46
  • `System.currentTimeMillis()` is to be avoided for elapsed time measurements. See comments above. – Charlie Reitzel Jul 26 '23 at 18:35
91

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.

James Schek
  • 17,844
  • 7
  • 51
  • 64
  • This was also a great suggestion, and one of those "duh" light-bulb moments for me when I read this answer. Our project uses JDeveloper, but I checked, and sure enough, it's got a built-in profiler! – Ogre Psalm33 Oct 08 '08 at 12:14
  • 2
    From java 7 build 40 (i think) they included the former JRockits Flight Recorder to java (search for Java Mission Control) – Niels Bech Nielsen Mar 17 '14 at 13:30
  • Sure enough @NielsBechNielsen! http://www.oracle.com/technetwork/java/javaseproducts/mission-control/java-mission-control-1998576.html – Ogre Psalm33 Jul 07 '14 at 14:43
  • How to get method's execution in Java by Visual VM, for example? – petertc Nov 13 '14 at 08:06
51

System.currentTimeMillis(); IS NOT a good approach for measuring the performance of your algorithms. It measures the total time you experience as a user watching the computer screen. It includes also time consumed by everything else running on your computer in the background. This could make a huge difference in case you have a lot of programs running on your workstation.

Proper approach is using java.lang.management package.

From http://nadeausoftware.com/articles/2008/03/java_tip_how_get_cpu_and_user_time_benchmarking website (archive link):

  • "User time" is the time spent running your application's own code.
  • "System time" is the time spent running OS code on behalf of your application (such as for I/O).

getCpuTime() method gives you sum of those:

import java.lang.management.ManagementFactory;
import java.lang.management.ThreadMXBean;

public class CPUUtils {

    /** Get CPU time in nanoseconds. */
    public static long getCpuTime( ) {
        ThreadMXBean bean = ManagementFactory.getThreadMXBean( );
        return bean.isCurrentThreadCpuTimeSupported( ) ?
            bean.getCurrentThreadCpuTime( ) : 0L;
    }

    /** Get user time in nanoseconds. */
    public static long getUserTime( ) {
        ThreadMXBean bean = ManagementFactory.getThreadMXBean( );
        return bean.isCurrentThreadCpuTimeSupported( ) ?
            bean.getCurrentThreadUserTime( ) : 0L;
    }

    /** Get system time in nanoseconds. */
    public static long getSystemTime( ) {
        ThreadMXBean bean = ManagementFactory.getThreadMXBean( );
        return bean.isCurrentThreadCpuTimeSupported( ) ?
            (bean.getCurrentThreadCpuTime( ) - bean.getCurrentThreadUserTime( )) : 0L;
    }

}
Joshua Goldberg
  • 5,059
  • 2
  • 34
  • 39
TondaCZE
  • 2,590
  • 1
  • 19
  • 20
  • 5
    This is definitely a good point, that "user time" (wall-clock time) is not always a great measure of performance, especially in a multi-threaded program. – Ogre Psalm33 Apr 07 '14 at 12:52
  • This is the answer I am looking for. – ZhaoGang Jan 06 '20 at 02:14
  • Agree and disagree on "user time" – sometimes it's correct to measure how long the code itself takes, and exclude wall-clock time; but other times the total elapsed time is what should be measured. – Kaan Jun 18 '22 at 17:20
  • Elapsed time using `System.nanoTime()` is the best approach, imo, for measuring single thread performance. Almost always, you can tune the code used by each thread individually and measure the impact on overall throughput using coarser methods, e.g. you can index 50 GB/hour using 10 threads vs. 10 GB/hour with 1 thread or whatever. – Charlie Reitzel Jul 26 '23 at 18:43
43

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.

Buhake Sindi
  • 87,898
  • 29
  • 167
  • 228
skaffman
  • 398,947
  • 96
  • 818
  • 769
  • 4
    Here is a tutorial on how to do this with Spring: http://veerasundar.com/blog/2010/01/spring-aop-example-profiling-method-execution-time-tutorial/ – David Tinker Jan 04 '11 at 11:05
34

With Java 8 you can do also something like this with every normal methods:

Object returnValue = TimeIt.printTime(() -> methodeWithReturnValue());
//do stuff with your returnValue

with TimeIt like:

public class TimeIt {

public static <T> T printTime(Callable<T> task) {
    T call = null;
    try {
        long startTime = System.currentTimeMillis();
        call = task.call();
        System.out.print((System.currentTimeMillis() - startTime) / 1000d + "s");
    } catch (Exception e) {
        //...
    }
    return call;
}
}

With this methode you can make easy time measurement anywhere in your code without breaking it. In this simple example i just print the time. May you add a Switch for TimeIt, e.g. to only print the time in DebugMode or something.

If you are working with Function you can do somthing like this:

Function<Integer, Integer> yourFunction= (n) -> {
        return IntStream.range(0, n).reduce(0, (a, b) -> a + b);
    };

Integer returnValue = TimeIt.printTime2(yourFunction).apply(10000);
//do stuff with your returnValue

public static <T, R> Function<T, R> printTime2(Function<T, R> task) {
    return (t) -> {
        long startTime = System.currentTimeMillis();
        R apply = task.apply(t);
        System.out.print((System.currentTimeMillis() - startTime) / 1000d
                + "s");
        return apply;
    };
}
Stefan
  • 438
  • 4
  • 9
  • This looks much better than other solutions. Its closer to Spring AOP yet lighter than that. True java 8 way! +1 Thanks! – Amit Kumar Dec 05 '17 at 14:09
  • Maybe this looks good to you, because Stefan is using fancy new java functions. But I think this is needlesly difficult to read and understand. – Stimpson Cat Jul 05 '19 at 09:25
21

Also We can use StopWatch class of Apache commons for measuring the time.

Sample code

org.apache.commons.lang.time.StopWatch sw = new org.apache.commons.lang.time.StopWatch();

System.out.println("getEventFilterTreeData :: Start Time : " + sw.getTime());
sw.start();

// Method execution code

sw.stop();
System.out.println("getEventFilterTreeData :: End Time : " + sw.getTime());
animuson
  • 53,861
  • 28
  • 137
  • 147
Narayan
  • 211
  • 2
  • 2
19

JEP 230: Microbenchmark Suite

FYI, JEP 230: Microbenchmark Suite is an OpenJDK project to:

Add a basic suite of microbenchmarks to the JDK source code, and make it easy for developers to run existing microbenchmarks and create new ones.

This feature arrived in Java 12.

Java Microbenchmark Harness (JMH)

For earlier versions of Java, take a look at the Java Microbenchmark Harness (JMH) project on which JEP 230 is based.

Basil Bourque
  • 303,325
  • 100
  • 852
  • 1,154
15

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

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.

Dr. Hans-Peter Störr
  • 25,298
  • 30
  • 102
  • 139
12

Really good code.

http://www.rgagnon.com/javadetails/java-0585.html

import java.util.concurrent.TimeUnit;

long startTime = System.currentTimeMillis();
........
........
........
long finishTime = System.currentTimeMillis();

String diff = millisToShortDHMS(finishTime - startTime);


  /**
   * converts time (in milliseconds) to human-readable format
   *  "<dd:>hh:mm:ss"
   */
  public static String millisToShortDHMS(long duration) {
    String res = "";
    long days  = TimeUnit.MILLISECONDS.toDays(duration);
    long hours = TimeUnit.MILLISECONDS.toHours(duration)
                   - TimeUnit.DAYS.toHours(TimeUnit.MILLISECONDS.toDays(duration));
    long minutes = TimeUnit.MILLISECONDS.toMinutes(duration)
                     - TimeUnit.HOURS.toMinutes(TimeUnit.MILLISECONDS.toHours(duration));
    long seconds = TimeUnit.MILLISECONDS.toSeconds(duration)
                   - TimeUnit.MINUTES.toSeconds(TimeUnit.MILLISECONDS.toMinutes(duration));
    if (days == 0) {
      res = String.format("%02d:%02d:%02d", hours, minutes, seconds);
    }
    else {
      res = String.format("%dd%02d:%02d:%02d", days, hours, minutes, seconds);
    }
    return res;
  }
iceberg
  • 1,951
  • 1
  • 22
  • 26
  • 3
    Actually the question was how to calculate the amount of time a method takes, not how to format it. However this question is quite old (almost four years!). Try to avoid resurrecting old threads unless the response will add something new and significant over existing responses. – Leigh Jun 15 '12 at 08:58
  • 1
    And to add remaining millis to the end, make the following changes: `long millis = TimeUnit.MILLISECONDS.toMillis(duration) - TimeUnit.SECONDS.toMillis(TimeUnit.MILLISECONDS.toSeconds(duration)); if (days == 0) { res = String.format("%02d:%02d:%02d.%02d", hours, minutes, seconds, millis); } else { res = String.format("%dd%02d:%02d:%02d.%02d", days, hours, minutes, seconds, millis); }` – Rick Barkhouse Jan 23 '13 at 22:19
12

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;
}
Sunil Manheri
  • 2,313
  • 2
  • 18
  • 19
10

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");
    }
}
Pratik Patil
  • 3,662
  • 3
  • 31
  • 31
10

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());
Bhaskara Arani
  • 1,556
  • 1
  • 26
  • 44
  • From the docs: `This class is normally used to verify performance during proof-of-concept work and in development, rather than as part of production applications.` – q99 Jun 17 '20 at 15:59
  • @q99 True, this kind of logic we dont put in production envrionments, before moving it to production we need to test – Bhaskara Arani Jun 19 '20 at 09:05
  • it uses `System.nanoTime()` under the hood which is not good(applies to `System.currentTimeMillis()` too), see @TondaCZE answer – Eboubaker Nov 21 '21 at 08:52
10

You can use Perf4j. Very cool utility. Usage is simple

String watchTag = "target.SomeMethod";
StopWatch stopWatch = new LoggingStopWatch(watchTag);
Result result = null; // Result is a type of a return value of a method
try {
    result = target.SomeMethod();
    stopWatch.stop(watchTag + ".success");
} catch (Exception e) {
    stopWatch.stop(watchTag + ".fail", "Exception was " + e);
    throw e; 
}

More information can be found in Developer Guide

Edit: Project seems dead

Graham Russell
  • 997
  • 13
  • 24
mergenchik
  • 1,129
  • 16
  • 27
  • 1
    Perf4j can also generate nice [statistics](http://perf4j.codehaus.org/devguide.html#Parsing_Log_Files_to_Generate_Performance_Statistics). – Paaske Mar 28 '12 at 12:00
8

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
8
new Timer(""){{
    // code to time 
}}.timeMe();



public class Timer {

    private final String timerName;
    private long started;

    public Timer(String timerName) {
        this.timerName = timerName;
        this.started = System.currentTimeMillis();
    }

    public void timeMe() {
        System.out.println(
        String.format("Execution of '%s' takes %dms.", 
                timerName, 
                started-System.currentTimeMillis()));
    }

}
Maciek Kreft
  • 882
  • 9
  • 14
  • 1
    Roll your own simple class is a good choice when you already have the build system and dependent OTS set up, and don't want to bother pulling in another OTS package that includes a utility timer class. – Ogre Psalm33 Apr 03 '13 at 21:06
8

You can use Metrics library which provides various measuring instruments. Add dependency:

<dependencies>
    <dependency>
        <groupId>io.dropwizard.metrics</groupId>
        <artifactId>metrics-core</artifactId>
        <version>${metrics.version}</version>
    </dependency>
</dependencies>

And configure it for your environment.

Methods can be annotated with @Timed:

@Timed
public void exampleMethod(){
    // some code
}

or piece of code wrapped with Timer:

final Timer timer = metricsRegistry.timer("some_name");
final Timer.Context context = timer.time();
// timed code
context.stop();

Aggregated metrics can exported to console, JMX, CSV or other.

@Timed metrics output example:

com.example.ExampleService.exampleMethod
             count = 2
         mean rate = 3.11 calls/minute
     1-minute rate = 0.96 calls/minute
     5-minute rate = 0.20 calls/minute
    15-minute rate = 0.07 calls/minute
               min = 17.01 milliseconds
               max = 1006.68 milliseconds
              mean = 511.84 milliseconds
            stddev = 699.80 milliseconds
            median = 511.84 milliseconds
              75% <= 1006.68 milliseconds
              95% <= 1006.68 milliseconds
              98% <= 1006.68 milliseconds
              99% <= 1006.68 milliseconds
            99.9% <= 1006.68 milliseconds
Justinas Jakavonis
  • 8,220
  • 10
  • 69
  • 114
7

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

luke
  • 14,518
  • 4
  • 46
  • 57
7

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.

Horst Gutmann
  • 10,910
  • 2
  • 28
  • 31
6

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;
David Nehme
  • 21,379
  • 8
  • 78
  • 117
5
long startTime = System.currentTimeMillis();
// code goes here
long finishTime = System.currentTimeMillis();
long elapsedTime = finishTime - startTime; // elapsed time in milliseconds
Ryan Rodemoyer
  • 5,548
  • 12
  • 44
  • 54
5

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.

anjanb
  • 12,999
  • 18
  • 77
  • 106
4

I modified the code from correct answer to get result in seconds:

long startTime = System.nanoTime();

methodCode ...

long endTime = System.nanoTime();
double duration = (double)(endTime - startTime) / (Math.pow(10, 9));
Log.v(TAG, "MethodName time (s) = " + duration);
Denis Kutlubaev
  • 15,320
  • 6
  • 84
  • 70
4

Performance measurements on my machine

  • System.nanoTime() : 750ns
  • System.currentTimeMillis() : 18ns

As mentioned, System.nanoTime() is thought to measure elapsed time. Just be aware of the cost if used inside a loop or the like.

dave
  • 62,300
  • 5
  • 72
  • 93
leo
  • 3,528
  • 3
  • 20
  • 19
4

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
msysmilu
  • 2,015
  • 23
  • 24
4

In Java 8 a new class named Instant is introduced. As per doc:

Instant represents the start of a nanosecond on the time line. This class is useful for generating a time stamp to represent machine time. The range of an instant requires the storage of a number larger than a long. To achieve this, the class stores a long representing epoch-seconds and an int representing nanosecond-of-second, which will always be between 0 and 999,999,999. The epoch-seconds are measured from the standard Java epoch of 1970-01-01T00:00:00Z where instants after the epoch have positive values, and earlier instants have negative values. For both the epoch-second and nanosecond parts, a larger value is always later on the time-line than a smaller value.

This can be used as:

Instant start = Instant.now();
try {
    Thread.sleep(7000);
} catch (InterruptedException e) {
    e.printStackTrace();
}
Instant end = Instant.now();
System.out.println(Duration.between(start, end));

It prints PT7.001S.

akhil_mittal
  • 23,309
  • 7
  • 96
  • 95
4

You can use stopwatch class from spring core project:

Code:

StopWatch stopWatch = new StopWatch()
stopWatch.start();  //start stopwatch
// write your function or line of code.
stopWatch.stop();  //stop stopwatch
stopWatch.getTotalTimeMillis() ; ///get total time

Documentation for Stopwatch: Simple stop watch, allowing for timing of a number of tasks, exposing total running time and running time for each named task. Conceals use of System.currentTimeMillis(), improving the readability of application code and reducing the likelihood of calculation errors. Note that this object is not designed to be thread-safe and does not use synchronization. This class is normally used to verify performance during proof-of-concepts and in development, rather than as part of production applications.

praveen jain
  • 778
  • 2
  • 8
  • 23
3

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));    
msysmilu
  • 2,015
  • 23
  • 24
gifpif
  • 4,507
  • 4
  • 31
  • 45
2

It would be nice if java had a better functional support, so that the action, that needs to be measured, could be wrapped into a block:

measure {
   // your operation here
}

In java this could be done by anonymous functions, that look too verbose

public interface Timer {
    void wrap();
}


public class Logger {

    public static void logTime(Timer timer) {
        long start = System.currentTimeMillis();
        timer.wrap();
        System.out.println("" + (System.currentTimeMillis() - start) + "ms");
    }

    public static void main(String a[]) {
        Logger.logTime(new Timer() {
            public void wrap() {
                // Your method here
                timeConsumingOperation();
            }
        });

    }

    public static void timeConsumingOperation() {
        for (int i = 0; i<=10000; i++) {
           System.out.println("i=" +i);
        }
    }
}
  • 1
    Could probably be cleaned up by using Java 8's lambda expressions. http://www.drdobbs.com/jvm/lambda-expressions-in-java-8/240166764?pgno=2 – Ogre Psalm33 Jan 19 '15 at 13:55
  • Indeed, since Java 8, `java.lang.Runnable` is a `@FunctionalInterface`, which means you can pass a lambda expression to any method that takes a `Runnable` as parameter. Your `timeThisCode(Runnable r)` could simply return the millis/nanos or a more elaborate representation of the elapsed time. – Cornel Masson Apr 24 '15 at 12:28
2

You can use javaagent to modify the java class bytes ,add the monitor codes dynamically.there is some open source tools on the github that can do this for you.
If you want to do it by yourself, just implements the javaagent,use javassist to modify the methods you want to monitor,and the monitor code before your method return.it's clean and you can monitor systems that you even don't have source code.

dingjsh
  • 367
  • 1
  • 2
  • 15
2

Here is pretty printed string ready formated seconds elapsed similar to google search time took to search:

        long startTime = System.nanoTime();
        //  ... methodToTime();
        long endTime = System.nanoTime();
        long duration = (endTime - startTime);
        long seconds = (duration / 1000) % 60;
        // formatedSeconds = (0.xy seconds)
        String formatedSeconds = String.format("(0.%d seconds)", seconds);
        System.out.println("formatedSeconds = "+ formatedSeconds);
        // i.e actual formatedSeconds = (0.52 seconds)
Tim Siwula
  • 966
  • 11
  • 15
  • nonoTime is not /1000 of a second. your math is assuming getTime which is millisecond. better to do /1e6 to get milliseconds. – simbo1905 Feb 14 '18 at 07:38
2

I implemented a simple timer, And I think it's really useful:

public class Timer{
    private static long start_time;

    public static double tic(){
        return start_time = System.nanoTime();
    }

    public static double toc(){
        return (System.nanoTime()-start_time)/1000000000.0;
    }

}

That way you can time one or more actions:

Timer.tic();
// Code 1
System.out.println("Code 1 runtime: "+Timer.toc()+" seconds.");
// Code 2
System.out.println("(Code 1 + Code 2) runtime: "+Timer.toc()+"seconds");
Timer.tic();
// Code 3
System.out.println("Code 3 runtime: "+Timer.toc()+" seconds.");
StationaryTraveller
  • 1,449
  • 2
  • 19
  • 31
1

System.nanoTime() is a pretty precise system utility to measure execution time. But be careful, if you're running on pre-emptive scheduler mode (default), this utility actually measures wall-clock time and not CPU time. Therefore, you may notice different execution time values from run to run, depending on system loads. If you look for CPU time, I think that running your program in real-time mode will do the trick. You have to use RT linux. link: Real-time programming with Linux

Community
  • 1
  • 1
hmitcs
  • 343
  • 4
  • 11
1

A strategy that works to me in java ee was:

  1. Create a class with a method annotated with @AroundInvoke;

    @Singleton
    public class TimedInterceptor implements Serializable {
    
        @AroundInvoke
        public Object logMethod(InvocationContext ic) throws Exception {
            Date start = new Date();
            Object result = ic.proceed();
            Date end = new Date();
            System.out.println("time: " + (end.getTime - start.getTime()));
            return result;
        }
    }
    
  2. Annotate the method that you want to monitoring:

    @Interceptors(TimedInterceptor.class)
    public void onMessage(final Message message) { ... 
    

I hope this can help.

1

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;
}
Aska Fed
  • 311
  • 3
  • 6
0

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); 
Kaan
  • 5,434
  • 3
  • 19
  • 41
jhenya-d
  • 399
  • 7
  • 19
0

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();
Brett Ryan
  • 26,937
  • 30
  • 128
  • 163
-1

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;
    }
}