2

I'm trying to come-up with a utility method to log the time duration taken by code blocks in my java code. Please find below the utility code to log duration and the main code using the utility method,

Utility code:

public static void logDuration(Runnable blockToExec
            , String blockCode) {
    Instant start = Instant.now();
    blockToExec.run();
    Duration duration = Duration.between(start, Instant.now());

    /*
        SAMPLE OUPUT of below print stmt (from JAVA API doc)
        "20.345 seconds"                 -- "PT20.345S
        "15 minutes" (15 * 60 seconds)   -- "PT15M"
        "10 hours" (10 * 3600 seconds)   -- "PT10H"
        "2 days" (2 * 86400 seconds)     -- "PT48H"
     */        
    System.out.println("Time taken to complete <" + blockCode + "> - " + duration.toString());
}

Main code:

Utils.logDuration(() -> {

    List<PersonInfo> personInfos = persons.stream()
            .flatMap(person -> person.getCurrAndPrevAddrs().stream()
                    .map(addr -> {
                        PersonInfo personInfo = new PersonInfo();
                        personInfo.setName(person.getName());
                        personInfo.setAge(person.getAge());
                        personInfo.setAddrs(addr);              
                        return personInfo;
                    }
            )).collect(Collectors.toList());

}, "Parsing and Splitting Persons list");

Sample Output: Time taken to complete Parsing and Splitting Persons list - PT0.012S

This seems to be working fine but i want to make sure this implementation does not have any adverse unwanted hidden impacts to my code execution. Could you please let me know the design flaws in this implementation? Or please let me know if there are any alternate implementation.

Pons
  • 1,101
  • 1
  • 11
  • 20
  • [CodeReview](http://codereview.stackexchange.com/) would be the best StackExchange for this kind of question :) – Aaron Feb 28 '17 at 20:05
  • 1
    You should use System.nanoTime. And of course, creating the Runnable instance, and above all, printing to the console, will make your code slower. It could be significant if you time hot spots in your code. Another problem in your design is that you can't time anything that needs to retur something or throw a checked exception. – JB Nizet Feb 28 '17 at 20:10

3 Answers3

2

It sounds like you want a Stopwatch utility, which guava has:

Stopwatch watch = Stopwatch.createStarted();
// your code
long elapsed = watch.elapsed(TimeUnit.MILLISECONDS);

Unless you want to benchmark your code. Micro-benchmark that is. In which case JMH is the de-facto tool for that. Read more here

Community
  • 1
  • 1
Eugene
  • 117,005
  • 15
  • 201
  • 306
0

Why would you want to log code execution time? I would rather use a profiler like JProfiler to find out bottlenecks instead. Anyway, if you need to measure time, you can use DropWizard Metrics and expose those metrics through JMX for example.

It's way more convenient as reading a log file which outputs execution times.

Jerome L
  • 607
  • 5
  • 11
0

Have a look at microbenchmarking framework such as JMH : JMH is a Java harness for building, running, and analyzing nano/micro/milli/macro benchmarks written in Java and other languages targeting the JVM.

Thomas Lehoux
  • 1,158
  • 9
  • 13