Guava Stopwatch

Guava's Stopwatch is another Guava class new to Guava Release 10 (as is Optional, the subject of another recent post). As its name implies, this simple class provides a method to conveniently measure time elapsed between two code points. It has several advantages over use of System.currentTimeMillis() or System.nanoTime(). I don't focus on these advantages here, but the Javadoc documentation for Stopwatch does cover some of these advantages.

As is true of many of Guava's classes, one of the endearing features of Stopwatch is its simplicity and appropriately named methods. The class features two constructors, one that takes no arguments (likely to be most commonly used) and one that accepts an customized extension of the Ticker class. Once an instance of Stopwatch is obtained, it's a simple matter of using methods with "obvious" names like start(), stop(), and reset() to control the stopwatch.

Any given Stopwatch instance records elapsed time in a cumulative fashion. In other words, you can start and stop the stopwatch multiple times (just don't start an already started stopwatch and don't stop an already stopped stopwatch) and the elapsed time accumulates with each start and stop. If that's not what is wanted and a single instance of the stopwatch is to be used to measure independent events (but not concurrent events), then the reset() method is used between the last run's stop() and the next run's start().

I have already alluded to several caveats to keep in mind when using Guava's Stopwatch. First, two successive start() methods should not be invoked on a given instance of Stopwatch without first stopping it with stop() before making the second call to stop(). Stopwatch has an instance method isRunning() that is useful for detecting a running stopwatch before trying to start it again or even before trying to stop one that has already been stopped or was never started. Most of these issues such as starting the stopwatch twice without stopping it or stopping a stopwatch that is not running or was never started lead to IllegalStateExceptions being thrown. Guava developers make use of their own Preconditions class to ascertain these aberrant conditions and to the throwing of these exceptions. The further implication of this, which is spelled out in the Javadoc documentation, is that Stopwatch is not thread-safe and should be used in a single-thread environment.

The methods covered so far handle constructing instances of Stopwatch and managing the stopwatch. However, a stopwatch is almost always useful only when the timed results are available for viewing. The Stopwatch class provides two main methods for accessing elapsed time recorded by the stopwatch instance. One method, elapsedMillis(), is similar to standard Java methods that return milliseconds since epoch time. The big difference here is that Stopwatch is returning milliseconds elapsed between given points in time (start() and stop() calls) versus since an absolute epoch time.

I prefer elapsedTime(TimeUnit) for acquiring the elapsed time recorded in my stopwatch instance. This method makes use of the TimeUnit enum (see my post on TimeUnit) to specify the units that the elapsed time should be expressed in. Both of these methods for reporting elapsed time can be run while the stopwatch is running or after it has stopped.

The following code listing contains a class that demonstrates the methods on Stopwatch that have been highlighted in this post.

package dustin.examples;

import static java.lang.System.out;

import com.google.common.base.Stopwatch;
import java.util.concurrent.TimeUnit;
import java.util.logging.Level;
import java.util.logging.Logger;

/**
 * Demonstrates Guava's (Release 10) Stopwatch class.
 * 
 * @author Dustin
 */
public class StopWatchDemo
{
   private final static Logger LOGGER = Logger.getLogger(StopWatchDemo.class.getCanonicalName());

   public static void doSomethingJustToBeDoingIt(final int numberOfTimesToDoNothing)
   {
      for (int count=0; count < numberOfTimesToDoNothing; count++)
      {
         try
         {
            Thread.sleep(TimeUnit.SECONDS.toMillis(1));
         }
         catch (InterruptedException interruptEx)
         {
            LOGGER.log(Level.INFO, "Don't interrupt me when I'm trying to sleep!", interruptEx);
         }
      }
   }

   /**
    * Print statistics on Stopwatch-reported times for provided number of loops.
    * 
    * @param numberLoops Number of loops executed.
    * @param stopwatch Stopwatch instance with time used statistics.
    */
   public static void printElapsedTime(final int numberLoops, final Stopwatch stopwatch)
   {
      if (stopwatch.isRunning())
      {
         out.println("WARNING! Your stopwatch is still running!");
      }
      else // stopwatch not running
      {
         out.println(numberLoops + " loops required: ");
         out.println("\t" + stopwatch.toString(6));
         out.println("\t" + stopwatch.elapsedMillis() + " elapsed milliseconds.");
         out.println("\t" + stopwatch.elapsedTime(TimeUnit.MINUTES) + " minutes");
         out.println("\t" + stopwatch.elapsedTime(TimeUnit.SECONDS) + " seconds");
         out.println("\t" + stopwatch.elapsedTime(TimeUnit.MILLISECONDS) + " milliseconds");
         out.println("\t" + stopwatch.elapsedTime(TimeUnit.NANOSECONDS) + " nanoseconds");
      }
   }

   public static void main(final String[] arguments)
   {
      final Stopwatch stopwatch = new Stopwatch();

      int numberTimes = 5;
      stopwatch.start();
      doSomethingJustToBeDoingIt(numberTimes);
      stopwatch.stop();
      printElapsedTime(numberTimes, stopwatch);

      numberTimes = 45;
      stopwatch.reset();
      stopwatch.start();
      doSomethingJustToBeDoingIt(numberTimes);
      stopwatch.stop();
      printElapsedTime(numberTimes, stopwatch);

      numberTimes = 125;
      stopwatch.reset();
      stopwatch.start();
      doSomethingJustToBeDoingIt(numberTimes);
      stopwatch.stop();
      printElapsedTime(numberTimes, stopwatch);
   }
}