diff --git a/spring-core/src/main/java/org/springframework/util/StopWatch.java b/spring-core/src/main/java/org/springframework/util/StopWatch.java index 50a3cb179a3..e88d359339e 100644 --- a/spring-core/src/main/java/org/springframework/util/StopWatch.java +++ b/spring-core/src/main/java/org/springframework/util/StopWatch.java @@ -75,6 +75,12 @@ public class StopWatch { /** Total running time. */ private long totalTimeNanos; + /** + * The {@link NanoClock} used to compute execution times of tasks. + *
+ * Defaults to {@link System#nanoTime()}, other implementations can be injected for unit testing. + */ + private final NanoClock nanoClock; /** * Construct a new {@code StopWatch}. @@ -92,9 +98,21 @@ public StopWatch() { * @param id identifier for this stop watch */ public StopWatch(String id) { - this.id = id; + this(id, System::nanoTime); } + /** + * Construct a new {@code StopWatch} with the given id. + *

The id is handy when we have output from multiple stop watches and need + * to distinguish between them. + *

Does not start any task. + * @param id identifier for this stop watch + * @param nanoClock the {@link NanoClock} used to compute execution times of tasks + */ + public StopWatch(String id, NanoClock nanoClock) { + this.id = id; + this.nanoClock = nanoClock; + } /** * Get the id of this {@code StopWatch}, as specified on construction. @@ -141,7 +159,7 @@ public void start(String taskName) throws IllegalStateException { throw new IllegalStateException("Can't start StopWatch: it's already running"); } this.currentTaskName = taskName; - this.startTimeNanos = System.nanoTime(); + this.startTimeNanos = nanoClock.nanoTime(); } /** @@ -155,7 +173,7 @@ public void stop() throws IllegalStateException { if (this.currentTaskName == null) { throw new IllegalStateException("Can't stop StopWatch: it's not running"); } - long lastTime = System.nanoTime() - this.startTimeNanos; + long lastTime = nanoClock.nanoTime() - this.startTimeNanos; this.totalTimeNanos += lastTime; this.lastTaskInfo = new TaskInfo(this.currentTaskName, lastTime); if (this.taskList != null) { @@ -389,6 +407,14 @@ public String toString() { return sb.toString(); } + /** + * An abstraction of a clock that provides nanosecond precision and that can be used to compute relative times. + */ + public interface NanoClock { + + long nanoTime(); + + } /** * Nested class to hold data about one task executed within the {@code StopWatch}. diff --git a/spring-core/src/test/java/org/springframework/util/StopWatchTests.java b/spring-core/src/test/java/org/springframework/util/StopWatchTests.java index 5637bf250de..8057ece54f9 100644 --- a/spring-core/src/test/java/org/springframework/util/StopWatchTests.java +++ b/spring-core/src/test/java/org/springframework/util/StopWatchTests.java @@ -16,13 +16,17 @@ package org.springframework.util; +import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; - +import org.junit.jupiter.api.extension.ExtendWith; +import org.mockito.Mock; +import org.mockito.junit.jupiter.MockitoExtension; import org.springframework.util.StopWatch.TaskInfo; import static org.assertj.core.api.Assertions.assertThat; import static org.assertj.core.api.Assertions.assertThatExceptionOfType; import static org.assertj.core.api.Assertions.assertThatIllegalStateException; +import static org.mockito.Mockito.when; /** * Tests for {@link StopWatch}. @@ -31,6 +35,7 @@ * @author Juergen Hoeller * @author Sam Brannen */ +@ExtendWith(MockitoExtension.class) class StopWatchTests { private static final String ID = "myId"; @@ -38,12 +43,15 @@ class StopWatchTests { private static final String name1 = "Task 1"; private static final String name2 = "Task 2"; - private static final long duration1 = 200; - private static final long duration2 = 100; - // private static final long fudgeFactor = 100; + private StopWatch stopWatch; - private final StopWatch stopWatch = new StopWatch(ID); + @Mock + private StopWatch.NanoClock nanoClock; + @BeforeEach + void setUp() { + stopWatch = new StopWatch(ID, nanoClock); + } @Test void failureToStartBeforeGettingTimings() { @@ -57,6 +65,8 @@ void failureToStartBeforeStop() { @Test void rejectsStartTwice() { + when(nanoClock.nanoTime()).thenAnswer(invocation -> System.nanoTime()); + stopWatch.start(); assertThat(stopWatch.isRunning()).isTrue(); stopWatch.stop(); @@ -68,52 +78,46 @@ void rejectsStartTwice() { } @Test - void validUsage() throws Exception { + void validUsage() { + when(nanoClock.nanoTime()) + .thenReturn(1_000_000_000L) // start task 1 + .thenReturn(2_000_000_000L) // stop task 1 (duration = 1 second) + .thenReturn(3_000_000_000L) // start task 2 + .thenReturn(5_123_456_789L); // stop task 2 (duration = 2.123456789 seconds) + assertThat(stopWatch.isRunning()).isFalse(); stopWatch.start(name1); - Thread.sleep(duration1); assertThat(stopWatch.isRunning()).isTrue(); assertThat(stopWatch.currentTaskName()).isEqualTo(name1); stopWatch.stop(); assertThat(stopWatch.isRunning()).isFalse(); - /* Flaky StopWatch time assertions... - assertThat(stopWatch.getLastTaskTimeNanos()) + assertThat(stopWatch.lastTaskInfo().getTimeNanos()) .as("last task time in nanoseconds for task #1") - .isGreaterThanOrEqualTo(TimeUnit.MILLISECONDS.toNanos(duration1 - fudgeFactor)) - .isLessThanOrEqualTo(TimeUnit.MILLISECONDS.toNanos(duration1 + fudgeFactor)); + .isEqualTo(1_000_000_000L); assertThat(stopWatch.getTotalTimeMillis()) - .as("total time in milliseconds for task #1") - .isGreaterThanOrEqualTo(duration1 - fudgeFactor) - .isLessThanOrEqualTo(duration1 + fudgeFactor); + .as("total time in milliseconds") + .isEqualTo(1_000L); assertThat(stopWatch.getTotalTimeSeconds()) - .as("total time in seconds for task #1") - .isGreaterThanOrEqualTo((duration1 - fudgeFactor) / 1000.0) - .isLessThanOrEqualTo((duration1 + fudgeFactor) / 1000.0); - */ + .as("total time in seconds") + .isEqualTo(1.0); stopWatch.start(name2); - Thread.sleep(duration2); assertThat(stopWatch.isRunning()).isTrue(); assertThat(stopWatch.currentTaskName()).isEqualTo(name2); stopWatch.stop(); assertThat(stopWatch.isRunning()).isFalse(); - /* Flaky StopWatch time assertions... - assertThat(stopWatch.getLastTaskTimeNanos()) + assertThat(stopWatch.lastTaskInfo().getTimeNanos()) .as("last task time in nanoseconds for task #2") - .isGreaterThanOrEqualTo(TimeUnit.MILLISECONDS.toNanos(duration2)) - .isLessThanOrEqualTo(TimeUnit.MILLISECONDS.toNanos(duration2 + fudgeFactor)); + .isEqualTo(2_123_456_789L); assertThat(stopWatch.getTotalTimeMillis()) - .as("total time in milliseconds for tasks #1 and #2") - .isGreaterThanOrEqualTo(duration1 + duration2 - fudgeFactor) - .isLessThanOrEqualTo(duration1 + duration2 + fudgeFactor); + .as("total time in milliseconds") + .isEqualTo(3_123L); assertThat(stopWatch.getTotalTimeSeconds()) - .as("total time in seconds for task #2") - .isGreaterThanOrEqualTo((duration1 + duration2 - fudgeFactor) / 1000.0) - .isLessThanOrEqualTo((duration1 + duration2 + fudgeFactor) / 1000.0); - */ + .as("total time in seconds") + .isEqualTo(3.123456789); assertThat(stopWatch.getTaskCount()).isEqualTo(2); assertThat(stopWatch.prettyPrint()).contains(name1, name2); @@ -123,16 +127,15 @@ void validUsage() throws Exception { } @Test - void validUsageDoesNotKeepTaskList() throws Exception { + void validUsageDoesNotKeepTaskList() { + when(nanoClock.nanoTime()).thenAnswer(invocation -> System.nanoTime()); stopWatch.setKeepTaskList(false); stopWatch.start(name1); - Thread.sleep(duration1); assertThat(stopWatch.currentTaskName()).isEqualTo(name1); stopWatch.stop(); stopWatch.start(name2); - Thread.sleep(duration2); assertThat(stopWatch.currentTaskName()).isEqualTo(name2); stopWatch.stop();