001 package org.junit.rules;
002
003 import org.junit.AssumptionViolatedException;
004 import org.junit.runner.Description;
005 import org.junit.runners.model.Statement;
006
007 import java.util.concurrent.TimeUnit;
008
009 /**
010 * The Stopwatch Rule notifies one of its own protected methods of the time spent by a test.
011 *
012 * <p>Override them to get the time in nanoseconds. For example, this class will keep logging the
013 * time spent by each passed, failed, skipped, and finished test:
014 *
015 * <pre>
016 * public static class StopwatchTest {
017 * private static final Logger logger = Logger.getLogger("");
018 *
019 * private static void logInfo(Description description, String status, long nanos) {
020 * String testName = description.getMethodName();
021 * logger.info(String.format("Test %s %s, spent %d microseconds",
022 * testName, status, TimeUnit.NANOSECONDS.toMicros(nanos)));
023 * }
024 *
025 * @Rule
026 * public Stopwatch stopwatch = new Stopwatch() {
027 * @Override
028 * protected void succeeded(long nanos, Description description) {
029 * logInfo(description, "succeeded", nanos);
030 * }
031 *
032 * @Override
033 * protected void failed(long nanos, Throwable e, Description description) {
034 * logInfo(description, "failed", nanos);
035 * }
036 *
037 * @Override
038 * protected void skipped(long nanos, AssumptionViolatedException e, Description description) {
039 * logInfo(description, "skipped", nanos);
040 * }
041 *
042 * @Override
043 * protected void finished(long nanos, Description description) {
044 * logInfo(description, "finished", nanos);
045 * }
046 * };
047 *
048 * @Test
049 * public void succeeds() {
050 * }
051 *
052 * @Test
053 * public void fails() {
054 * fail();
055 * }
056 *
057 * @Test
058 * public void skips() {
059 * assumeTrue(false);
060 * }
061 * }
062 * </pre>
063 *
064 * An example to assert runtime:
065 * <pre>
066 * @Test
067 * public void performanceTest() throws InterruptedException {
068 * long delta = 30;
069 * Thread.sleep(300L);
070 * assertEquals(300d, stopwatch.runtime(MILLISECONDS), delta);
071 * Thread.sleep(500L);
072 * assertEquals(800d, stopwatch.runtime(MILLISECONDS), delta);
073 * }
074 * </pre>
075 *
076 * @author tibor17
077 * @since 4.12
078 */
079 public class Stopwatch implements TestRule {
080 private final Clock clock;
081 private volatile long startNanos;
082 private volatile long endNanos;
083
084 public Stopwatch() {
085 this(new Clock());
086 }
087
088 Stopwatch(Clock clock) {
089 this.clock = clock;
090 }
091
092 /**
093 * Gets the runtime for the test.
094 *
095 * @param unit time unit for returned runtime
096 * @return runtime measured during the test
097 */
098 public long runtime(TimeUnit unit) {
099 return unit.convert(getNanos(), TimeUnit.NANOSECONDS);
100 }
101
102 /**
103 * Invoked when a test succeeds
104 */
105 protected void succeeded(long nanos, Description description) {
106 }
107
108 /**
109 * Invoked when a test fails
110 */
111 protected void failed(long nanos, Throwable e, Description description) {
112 }
113
114 /**
115 * Invoked when a test is skipped due to a failed assumption.
116 */
117 protected void skipped(long nanos, AssumptionViolatedException e, Description description) {
118 }
119
120 /**
121 * Invoked when a test method finishes (whether passing or failing)
122 */
123 protected void finished(long nanos, Description description) {
124 }
125
126 private long getNanos() {
127 if (startNanos == 0) {
128 throw new IllegalStateException("Test has not started");
129 }
130 long currentEndNanos = endNanos; // volatile read happens here
131 if (currentEndNanos == 0) {
132 currentEndNanos = clock.nanoTime();
133 }
134
135 return currentEndNanos - startNanos;
136 }
137
138 private void starting() {
139 startNanos = clock.nanoTime();
140 endNanos = 0;
141 }
142
143 private void stopping() {
144 endNanos = clock.nanoTime();
145 }
146
147 public final Statement apply(Statement base, Description description) {
148 return new InternalWatcher().apply(base, description);
149 }
150
151 private class InternalWatcher extends TestWatcher {
152
153 @Override protected void starting(Description description) {
154 Stopwatch.this.starting();
155 }
156
157 @Override protected void finished(Description description) {
158 Stopwatch.this.finished(getNanos(), description);
159 }
160
161 @Override protected void succeeded(Description description) {
162 Stopwatch.this.stopping();
163 Stopwatch.this.succeeded(getNanos(), description);
164 }
165
166 @Override protected void failed(Throwable e, Description description) {
167 Stopwatch.this.stopping();
168 Stopwatch.this.failed(getNanos(), e, description);
169 }
170
171 @Override protected void skipped(AssumptionViolatedException e, Description description) {
172 Stopwatch.this.stopping();
173 Stopwatch.this.skipped(getNanos(), e, description);
174 }
175 }
176
177 static class Clock {
178
179 public long nanoTime() {
180 return System.nanoTime();
181 }
182 }
183 }