Controlling Time: How to deal with periodic gaps

Patrick

16 years ago

Some application logging is important enough to put regressions tests in place. For instance, when you shell out to other programs and you want to monitor the amount of time it takes. In this entry I’m going to demonstrate how you might test that you are correctly logging out the time taken to do some long running work. I’m going to assume that you already have a Clock concept in the system.

Let’s assume we’re trying to test the following block of code:

public void doSomeWork(Clock clock) {
  DateTime startTime = clock.now();
  executeSomeLongRunningWork();
  DateTime endTime = clock.now();
  long timeTaken = endTime.minus(startTime.getMillis()).getMillis();
  LOG.log(Level.INFO, "Time taken was %sms", timeTaken);
}

One approach would be refactor the above code, replacing the Clock with a StopWatch but I’m going to show a technique for testing this code without changing it. Instead, we are going to inject an AutomaticallyForwardingClock. Here’s the implementation:

public class AutomaticallyMovingForwardClock implements Clock {
  private final int periodToMoveForwardsInMs;
  private DateTime now;

  public AutomaticallyMovingForwardClock(DateTime initialStartTime,
      int periodToMoveForwardsInMs) {
    this.now = initialStartTime;
    this.periodToMoveForwardsInMs = periodToMoveForwardsInMs;
  }

  public DateTime now() {
    DateTime result = now;
    now = now.plusMillis(periodToMoveForwardsInMs);
    return result;
  }
}

So whenever anyone asks the current time from the Clock, it automatically shifts time forward by the specified amount. Now we can write a test that looks like this:

@Test
public void shouldLogTimeTakenForProgramToExecute() throws Exception {
  int periodToMoveForwards = 5;
  Clock clock = new AutomaticallyMovingForwardClock(new DateTime(), periodToMoveForwards);
  doSomeWork(clock);
        
  long expectedDuration = periodToMoveForwards;       
  assertThat(fetchLogEntry(), containsString("Time taken " + expectedDuration + "ms"));   
}

A few notes from above: