Stopwatch class for Java

Question

Which Java class should you use for time performance measurements?

(One could use any date/time class, but the reason I'm asking is in .Net there's a designated Stopwatch class for this purpose)

Answer 1

The Spring Framework has an excellent StopWatch class:

StopWatch stopWatch = new StopWatch("My Stop Watch");  stopWatch.start("initializing"); Thread.sleep(2000); // simulated work stopWatch.stop();  stopWatch.start("processing"); Thread.sleep(5000); // simulated work stopWatch.stop();  stopWatch.start("finalizing"); Thread.sleep(3000); // simulated work stopWatch.stop();  System.out.println(stopWatch.prettyPrint()); 

This produces:

     StopWatch 'My Stop Watch': running time (millis) = 10000     -----------------------------------------     ms     %     Task name     -----------------------------------------     02000  020%  initializing     05000  050%  processing     03000  030%  finalizing 

Answer 2

This is an example how to use StopWatch to set multiple measurements by annotating dedicated methods. Very useful and very simple to use to measure e.g. Service call over multiple embedded call / operation and so on.

StopWatchHierarchy

package ch.vii.spring.aop;  import java.util.Arrays;  import org.aopalliance.intercept.MethodInterceptor; import org.aopalliance.intercept.MethodInvocation; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.springframework.stereotype.Component; import org.springframework.util.StopWatch;  @Component public class ProfilingMethodInterceptor implements MethodInterceptor {      private static final Logger log = LoggerFactory.getLogger(ProfilingMethodInterceptor.class);      public Object invoke(MethodInvocation invocation) throws Throwable {          if (log.isInfoEnabled()) {             String stopWatchName = invocation.getMethod().toGenericString();             StopWatchHierarchy stopWatch = StopWatchHierarchy.getStopWatchHierarchy(stopWatchName);              String taskName = invocation.getMethod().getName();             stopWatch.start(taskName);              try {                 return invocation.proceed();             } finally {                 stopWatch.stop();             }         } else {             return invocation.proceed();         }     }      static class StopWatchHierarchy {         private static final ThreadLocal<StopWatchHierarchy> stopwatchLocal = new ThreadLocal<StopWatchHierarchy>();         private static final IndentStack indentStack = new IndentStack();          static StopWatchHierarchy getStopWatchHierarchy(String id) {              StopWatchHierarchy stopWatch = stopwatchLocal.get();             if (stopWatch == null) {                 stopWatch = new StopWatchHierarchy(id);                 stopwatchLocal.set(stopWatch);             }             return stopWatch;         }          static void reset() {             stopwatchLocal.set(null);         }          final StopWatch stopWatch;         final Stack stack;          StopWatchHierarchy(String id) {             stopWatch = new StopWatch(id);             stack = new Stack();         }          void start(String taskName) {             if (stopWatch.isRunning()) {                 stopWatch.stop();             }             taskName = indentStack.get(stack.size) + taskName;             stack.push(taskName);             stopWatch.start(taskName);         }          void stop() {             stopWatch.stop();             stack.pop();             if (stack.isEmpty()) {                 log.info(stopWatch.prettyPrint());                 StopWatchHierarchy.reset();             } else {                 stopWatch.start(stack.get());             }         }      }      static class Stack {         private int size = 0;         String elements[];          public Stack() {             elements = new String[10];         }          public void push(String e) {             if (size == elements.length) {                 ensureCapa();             }             elements[size++] = e;         }          public String pop() {             String e = elements[--size];             elements[size] = null;             return e;         }          public String get() {             return elements[size - 1];         }          public boolean isEmpty() {             return size == 0;         }          private void ensureCapa() {             int newSize = elements.length * 2;             elements = Arrays.copyOf(elements, newSize);         }     }      static class IndentStack {         String elements[] = new String[0];          public String get(int index) {             if (index >= elements.length) {                 ensureCapa(index + 10);             }             return elements[index];         }          private void ensureCapa(int newSize) {             int oldSize = elements.length;             elements = Arrays.copyOf(elements, newSize);             for (int i = oldSize; i < elements.length; i++) {                 elements[i] = new String(new char[i]).replace("\0", "|   ");             }         }     } } 

Advisor

package ch.vii.spring.aop;  import java.lang.reflect.Method;  import org.aopalliance.aop.Advice; import org.springframework.aop.Pointcut; import org.springframework.aop.support.AbstractPointcutAdvisor; import org.springframework.aop.support.StaticMethodMatcherPointcut; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.stereotype.Component;  @Component public class ProfilingAdvisor extends AbstractPointcutAdvisor {      private static final long serialVersionUID = 1L;      private final StaticMethodMatcherPointcut pointcut = new StaticMethodMatcherPointcut() {         public boolean matches(Method method, Class<?> targetClass) {             return method.isAnnotationPresent(ProfileExecution.class);         }     };      @Autowired     private ProfilingMethodInterceptor interceptor;      public Pointcut getPointcut() {         return this.pointcut;     }      public Advice getAdvice() {         return this.interceptor;     } } 

ProfileExecution Annotation

package ch.vii.spring.aop;  import java.lang.annotation.ElementType; import java.lang.annotation.Inherited; import java.lang.annotation.Retention; import java.lang.annotation.RetentionPolicy; import java.lang.annotation.Target;  @Retention(RetentionPolicy.RUNTIME) @Target(ElementType.METHOD) @Inherited public @interface ProfileExecution {  } 

Annotate your code

package ch.vii.spring;                                                                                                                                                                  import org.springframework.beans.factory.annotation.Autowired;                                       import org.springframework.stereotype.Component;                                                      import ch.vii.spring.aop.ProfileExecution;                                                            @Component                                                                                           public class Bean {                                                                                      @Autowired                                                                                           InnerBean innerBean;        @ProfileExecution                                                                                    public void foo() {                                                                                      innerBean.innerFoo();                                                                               innerBean.innerFoo2();                                                                               innerBean.innerFoo();                                                                            }                                                                                                                                                                                          }    public class InnerBean {     @Autowired     InnerInnerBean innerInnerBean;      @ProfileExecution     public void innerFoo() {     }      @ProfileExecution     public void innerFoo2() {         innerInnerBean.innerInnerFoo();         innerInnerBean.innerInnerFoo();         innerInnerBean.innerInnerFoo();     } }                                                                                                     

Output

09:58:39.627 [main] INFO  c.v.s.aop.ProfilingMethodInterceptor - StopWatch 'public void ch.vii.spring.Bean.foo()': running time (millis) = 215 ----------------------------------------- ms     %     Task name ----------------------------------------- 00018  008 %  foo 00026  012 %  |   innerFoo 00001  000 %  foo 00016  007 %  |   innerFoo2 00038  018 %  |   |   innerInnerFoo 00000  000 %  |   innerFoo2 00024  011 %  |   |   innerInnerFoo 00028  013 %  |   innerFoo2 00024  011 %  |   |   innerInnerFoo 00029  013 %  |   innerFoo2 00000  000 %  foo 00011  005 %  |   innerFoo 00000  000 %  foo