What's a clean way to time code execution in Java?

user_4417306 0
Viewed 3410

It can be handy to time code execution so you know how long things take. However, I find the common way this is done sloppy since it's supposed to have the same indentation, which makes it harder to read what's actually being timed.

long start = System.nanoTime();

// The code you want to time

long end = System.nanoTime();
System.out.printf("That took: %d ms.%n", TimeUnit.NANOSECONDS.toMillis(end - start));

An attempt

I came up with the following, it looks way better, there are a few advantages & disadvantages:

Advantages:

  • It's clear what's being timed because of the indentation
  • It will automatically print how long something took after code finishes

Disadvantages:

  • This is not the way AutoClosable is supposed to be used (pretty sure)
  • It creates a new instance of TimeCode which isn't good
  • Variables declared within the try block are not accessible outside of it

It can be used like this:

 try (TimeCode t = new TimeCode()) {
     // The stuff you want to time
 }

The code which makes this possible is:

class TimeCode implements AutoCloseable {

    private long startTime;

    public TimeCode() {
        this.startTime = System.nanoTime();
    }

    @Override
    public void close() throws Exception {
        long endTime = System.nanoTime();
        System.out.printf("That took: %d ms%n",
                TimeUnit.NANOSECONDS.toMillis(endTime - this.startTime));
    }

}

The question

My question is:

  • Is my method actually as bad as I think it is
  • Is there a better way to time code execution in Java where you can clearly see what's being timed, or will I just have to settle for something like my first code block.
autocloseable timing java
3 Answers

You solution is just fine.

A less expressive way would be to wrap your code to be timed in a lambda.

public void timeCode(Runnable code) {
    ...
    try {
        code.run();
    } catch ...
    }
    ...
}

timeCode(() -> { ...code to time... });

You would probably like to catch the checked exceptions and pass them to some runtime exception or whatever.

user_9848230

You method is great as-is. We use something similar professionally but written in C#.

One thing that I would potentially add, is proper logging support, so that you can toggle those performance numbers, or have them at a debug or info level.

Additional improvements that I would be considering, is creating some static application state, (abusing thread locals) so that you can nest these sections, and have summary breakdowns.

See https://github.com/aikar/minecraft-timings for a library that does this for minecraft modding (written in java).

user_3060360

I think the solution that is suggested in the question text is too indirect and non-idiomatic to be suitable for production code. (But it looks like a neat tool to get quick timings of stuff during development.)

Both the Guava project and the Apache Commons include stop-watch classes. If you use any of them the code will be easier to read and understand, and these classes have more built-in functionality too.

Even without using a try-with-resource statement the section that is being measured can be enclosed in a block to improve clarity:

// Do things that shouldn't be measured

{
    Stopwatch watch = Stopwatch.createStarted();

    // Do things that should be measured

    System.out.println("Duration: " + watch.elapsed(TimeUnit.SECONDS) + " s");
}
user_4527750
Related