Time Watcher

src/main/java/org/junit/rules/Stopwatch.java

@@ -0,0 +1,150 @@
+package org.junit.rules;
+
+import org.junit.internal.AssumptionViolatedException;
+import org.junit.runner.Description;
+
+import java.util.concurrent.TimeUnit;
+
+/**
+ * The Stopwatch Rule notifies one of own protected methods of the time spent by a test.<p/>
+ * Override them to get the time in nanoseconds. For example, this class will keep logging the
+ * time spent by each passing, failing and skipped test:
+ *
+ * <pre>
+ * public static class StopwatchTest {
+ *     private static final Logger logger = Logger.getLogger(&quot;&quot;);
+ *
+ *     private static void logInfo(String testName, String status, long nanos) {
+ *         logger.info(String.format(&quot;Test %s %s, spent %d microseconds&quot;,
+ *                                     testName, status, Stopwatch.toMicros(nanos)));
+ *     }
+ *
+ *     &#064;Rule
+ *     public Stopwatch stopwatch= new Stopwatch() {
+ *         &#064;Override
+ *         protected void succeeded(long nanos, Description description) {
+ *             logInfo(description.getMethodName(), &quot;succeeded&quot;, nanos);
+ *         }
+ *
+ *         &#064;Override
+ *         protected void failed(long nanos, Throwable e, Description description) {
+ *             logInfo(description.getMethodName(), &quot;failed&quot;, nanos);
+ *         }
+ *
+ *         &#064;Override
+ *         protected void skipped(long nanos, AssumptionViolatedException e, Description description) {
+ *             logInfo(description.getMethodName(), &quot;skipped&quot;, nanos);
+ *         }
+ *
+ *         &#064;Override
+ *         protected void finished(long nanos, Description description) {
+ *             logInfo(description.getMethodName(), &quot;finished&quot;, nanos);
+ *         }
+ *     };
+ *
+ *     &#064;Test
+ *     public void succeeds() {
+ *     }
+ *
+ *     &#064;Test
+ *     public void fails() {
+ *         fail();
+ *     }
+ *
+ *     &#064;Test
+ *     public void skips() {
+ *         assumeTrue(false);
+ *     }
+ * }
+ * </pre>
+ *
+ * @author tibor17
+ * @since 4.12
+ */
+public class Stopwatch extends TestWatcher {
+    private volatile long startNanos = 0L;
+    private volatile long endNanos = 0L;
+
+    /**
+     * Invoked when a test succeeds
+     */
+    protected void succeeded(long nanos, Description description) {
+    }
+
+    /**
+     * Invoked when a test fails
+     */
+    protected void failed(long nanos, Throwable e, Description description) {
+    }
+
+    /**
+     * Invoked when a test is skipped due to a failed assumption.
+     */
+    protected void skipped(long nanos, AssumptionViolatedException e, Description description) {
+    }
+
+    /**
+     * Invoked when a test method finishes (whether passing or failing)
+     */
+    protected void finished(long nanos, Description description) {
+    }
+
+    /**
+     * @param nanos time in nanoseconds
+     * @return time converted to microseconds
+     */
+    public static long toMicros(long nanos) {
+        return TimeUnit.NANOSECONDS.toMicros(nanos);
+    }
+
+    /**
+     * @param nanos time in nanoseconds
+     * @return time converted to milliseconds
+     */
+    public static long toMillis(long nanos) {
+        return TimeUnit.NANOSECONDS.toMillis(nanos);
+    }
+
+    /**
+     * @param nanos time in nanoseconds
+     * @return time converted to seconds
+     */
+    public static long toSeconds(long nanos) {
+        return TimeUnit.NANOSECONDS.toSeconds(nanos);
+    }
+
+    private long getNanos() {
+        return endNanos - startNanos;
+    }
+
+    private void starting() {
+        startNanos = System.nanoTime();
+    }
+
+    private void stopping() {
+        endNanos = System.nanoTime();
+    }
+
+    @Override final protected void succeeded(Description description) {
+        stopping();
+        succeeded(getNanos(), description);
+    }
+
+    @Override final protected void failed(Throwable e, Description description) {
+        stopping();
+        failed(getNanos(), e, description);
+    }
+
+    @Override final protected void skipped(AssumptionViolatedException e, Description description) {
+        stopping();
+        skipped(getNanos(), e, description);
+    }
+
+    @Override final protected void starting(Description description) {
+        starting();
+    }
+
+    @Override final protected void finished(Description description) {
+        finished(getNanos(), description);
+    }
+}

src/test/java/org/junit/tests/AllTests.java

@@ -31,6 +31,7 @@
 import org.junit.tests.experimental.rules.NameRulesTest;
 import org.junit.tests.experimental.rules.RuleChainTest;
 import org.junit.tests.experimental.rules.RuleFieldValidatorTest;
+import org.junit.tests.experimental.rules.StopwatchTest;
 import org.junit.tests.experimental.rules.TempFolderRuleTest;
 import org.junit.tests.experimental.rules.TemporaryFolderUsageTest;
 import org.junit.tests.experimental.rules.TestRuleTest;
@@ -160,7 +161,8 @@
         BlockJUnit4ClassRunnerTest.class,
         MethodSorterTest.class,
         TestedOnSupplierTest.class,
-        StacktracePrintingMatcherTest.class
+        StacktracePrintingMatcherTest.class,
+        StopwatchTest.class
 })
 public class AllTests {
     public static Test suite() {

src/test/java/org/junit/tests/experimental/rules/StopwatchTest.java

@@ -0,0 +1,125 @@
+package org.junit.tests.experimental.rules;
+
+import org.junit.Before;
+import org.junit.Rule;
+import org.junit.Test;
+import org.junit.internal.AssumptionViolatedException;
+import org.junit.rules.Stopwatch;
+import org.junit.runner.Description;
+import org.junit.runner.JUnitCore;
+import org.junit.runner.Result;
+
+import static org.hamcrest.core.Is.is;
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertThat;
+import static org.junit.Assume.assumeTrue;
+import static org.junit.Assert.assertTrue;
+import static org.junit.Assert.fail;
+
+/**
+ * @author tibor17
+ * @since 4.12
+ */
+public class StopwatchTest {
+    public static enum TestStatus {SUCCEEDED, FAILED, SKIPPED }
+
+    public static abstract class AbstractStopwatchTest {
+        public static long timeSpent;
+        public static long timeSpentIfFinished;
+        public static String testName;
+        public static String testNameIfFinished;
+        public static TestStatus status;
+
+        @Rule
+        public final Stopwatch stopwatch = new Stopwatch() {
+            @Override
+            protected void succeeded(long nanos, Description description) {
+                timeSpent = nanos;
+                status = TestStatus.SUCCEEDED;
+                testName = description.getMethodName();
+            }
+
+            @Override
+            protected void failed(long nanos, Throwable e, Description description) {
+                timeSpent = nanos;
+                status = TestStatus.FAILED;
+                testName = description.getMethodName();
+            }
+
+            @Override
+            protected void skipped(long nanos, AssumptionViolatedException e, Description description) {
+                timeSpent = nanos;
+                status = TestStatus.SKIPPED;
+                testName = description.getMethodName();
+            }
+
+            @Override
+            protected void finished(long nanos, Description description) {
+                timeSpentIfFinished = nanos;
+                testNameIfFinished = description.getMethodName();
+            }
+        };
+    }
+
+    public static class SuccessfulTest extends AbstractStopwatchTest {
+        @Test
+        public void successfulTest() {
+        }
+    }
+
+    public static class FailedTest extends AbstractStopwatchTest {
+        @Test
+        public void failedTest() {
+            fail();
+        }
+    }
+
+    public static class SkippedTest extends AbstractStopwatchTest {
+        @Test
+        public void skippedTest() {
+            assumeTrue(false);
+        }
+    }
+
+    @Before
+    public void init() {
+        AbstractStopwatchTest.testName = null;
+        AbstractStopwatchTest.testNameIfFinished = null;
+        AbstractStopwatchTest.status = null;
+        AbstractStopwatchTest.timeSpent = 0;
+        AbstractStopwatchTest.timeSpentIfFinished = 0;
+    }
+
+    @Test
+    public void succeeded() {
+        Result result = JUnitCore.runClasses(SuccessfulTest.class);
+        assertEquals(0, result.getFailureCount());
+        assertThat(AbstractStopwatchTest.testName, is("successfulTest"));
+        assertThat(AbstractStopwatchTest.testName, is(AbstractStopwatchTest.testNameIfFinished));
+        assertThat(AbstractStopwatchTest.status, is(TestStatus.SUCCEEDED));
+        assertTrue("timeSpent > 0", AbstractStopwatchTest.timeSpent > 0);
+        assertThat(AbstractStopwatchTest.timeSpent, is(AbstractStopwatchTest.timeSpentIfFinished));
+    }
+
+    @Test
+    public void failed() {
+        Result result = JUnitCore.runClasses(FailedTest.class);
+        assertEquals(1, result.getFailureCount());
+        assertThat(AbstractStopwatchTest.testName, is("failedTest"));
+        assertThat(AbstractStopwatchTest.testName, is(AbstractStopwatchTest.testNameIfFinished));
+        assertThat(AbstractStopwatchTest.status, is(TestStatus.FAILED));
+        assertTrue("timeSpent > 0", AbstractStopwatchTest.timeSpent > 0);
+        assertThat(AbstractStopwatchTest.timeSpent, is(AbstractStopwatchTest.timeSpentIfFinished));
+    }
+
+    @Test
+    public void skipped() {
+        Result result = JUnitCore.runClasses(SkippedTest.class);
+        assertEquals(0, result.getFailureCount());
+        assertThat(AbstractStopwatchTest.testName, is("skippedTest"));
+        assertThat(AbstractStopwatchTest.testName, is(AbstractStopwatchTest.testNameIfFinished));
+        assertThat(AbstractStopwatchTest.status, is(TestStatus.SKIPPED));
+        assertTrue("timeSpent > 0", AbstractStopwatchTest.timeSpent > 0);
+        assertThat(AbstractStopwatchTest.timeSpent, is(AbstractStopwatchTest.timeSpentIfFinished));
+    }
+}