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(&quot;&quot;);
018     *
019     *     private static void logInfo(Description description, String status, long nanos) {
020     *         String testName = description.getMethodName();
021     *         logger.info(String.format(&quot;Test %s %s, spent %d microseconds&quot;,
022     *                                   testName, status, TimeUnit.NANOSECONDS.toMicros(nanos)));
023     *     }
024     *
025     *     &#064;Rule
026     *     public Stopwatch stopwatch = new Stopwatch() {
027     *         &#064;Override
028     *         protected void succeeded(long nanos, Description description) {
029     *             logInfo(description, &quot;succeeded&quot;, nanos);
030     *         }
031     *
032     *         &#064;Override
033     *         protected void failed(long nanos, Throwable e, Description description) {
034     *             logInfo(description, &quot;failed&quot;, nanos);
035     *         }
036     *
037     *         &#064;Override
038     *         protected void skipped(long nanos, AssumptionViolatedException e, Description description) {
039     *             logInfo(description, &quot;skipped&quot;, nanos);
040     *         }
041     *
042     *         &#064;Override
043     *         protected void finished(long nanos, Description description) {
044     *             logInfo(description, &quot;finished&quot;, nanos);
045     *         }
046     *     };
047     *
048     *     &#064;Test
049     *     public void succeeds() {
050     *     }
051     *
052     *     &#064;Test
053     *     public void fails() {
054     *         fail();
055     *     }
056     *
057     *     &#064;Test
058     *     public void skips() {
059     *         assumeTrue(false);
060     *     }
061     * }
062     * </pre>
063     *
064     * An example to assert runtime:
065     * <pre>
066     * &#064;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 abstract 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    }