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 its 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 long fStartNanos;
+    private long fEndNanos;
+
+    /**
+     * 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 fEndNanos - fStartNanos;
+    }
+
+    private void starting() {
+        fStartNanos= System.nanoTime();
+    }
+
+    private void stopping() {
+        fEndNanos= 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,132 @@
+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 {
+    private static enum TestStatus { SUCCEEDED, FAILED, SKIPPED }
+    private static Record fRecord;
+    private static Record fFinishedRecord;
+
+    private static class Record {
+        final long fDuration;
+        final String fName;
+        final TestStatus fStatus;
+
+        Record() {
+            this(0, null, null);
+        }
+
+        Record(long duration, String name) {
+            this(duration, null, name);
+        }
+
+        Record(long duration, TestStatus status, String name) {
+            fDuration= duration;
+            fStatus= status;
+            fName= name;
+        }
+    }
+
+    public static abstract class AbstractStopwatchTest {
+
+        @Rule
+        public final Stopwatch fStopwatch= new Stopwatch() {
+            @Override
+            protected void succeeded(long nanos, Description description) {
+                StopwatchTest.fRecord= new Record(nanos, TestStatus.SUCCEEDED, description.getMethodName());
+            }
+
+            @Override
+            protected void failed(long nanos, Throwable e, Description description) {
+                StopwatchTest.fRecord= new Record(nanos, TestStatus.FAILED, description.getMethodName());
+            }
+
+            @Override
+            protected void skipped(long nanos, AssumptionViolatedException e, Description description) {
+                StopwatchTest.fRecord= new Record(nanos, TestStatus.SKIPPED, description.getMethodName());
+            }
+
+            @Override
+            protected void finished(long nanos, Description description) {
+                StopwatchTest.fFinishedRecord= new Record(nanos, 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() {
+        fRecord= new Record();
+        fFinishedRecord= new Record();
+    }
+
+    @Test
+    public void succeeded() {
+        Result result= JUnitCore.runClasses(SuccessfulTest.class);
+        assertEquals(0, result.getFailureCount());
+        assertThat(fRecord.fName, is("successfulTest"));
+        assertThat(fRecord.fName, is(fFinishedRecord.fName));
+        assertThat(fRecord.fStatus, is(TestStatus.SUCCEEDED));
+        assertTrue("timeSpent > 0", fRecord.fDuration > 0);
+        assertThat(fRecord.fDuration, is(fFinishedRecord.fDuration));
+    }
+
+    @Test
+    public void failed() {
+        Result result= JUnitCore.runClasses(FailedTest.class);
+        assertEquals(1, result.getFailureCount());
+        assertThat(fRecord.fName, is("failedTest"));
+        assertThat(fRecord.fName, is(fFinishedRecord.fName));
+        assertThat(fRecord.fStatus, is(TestStatus.FAILED));
+        assertTrue("timeSpent > 0", fRecord.fDuration > 0);
+        assertThat(fRecord.fDuration, is(fFinishedRecord.fDuration));
+    }
+
+    @Test
+    public void skipped() {
+        Result result= JUnitCore.runClasses(SkippedTest.class);
+        assertEquals(0, result.getFailureCount());
+        assertThat(fRecord.fName, is("skippedTest"));
+        assertThat(fRecord.fName, is(fFinishedRecord.fName));
+        assertThat(fRecord.fStatus, is(TestStatus.SKIPPED));
+        assertTrue("timeSpent > 0", fRecord.fDuration > 0);
+        assertThat(fRecord.fDuration, is(fFinishedRecord.fDuration));
+    }
+}