Better logging

README.md

@@ -16,13 +16,13 @@ The following options are supported for JUnit tests:
 
  Option                                       | Description
 :---------------------------------------------|:----------------------
- `-v`                                         | Log "test run started" / "test started" / "test run finished" events on log level "info" instead of "debug".
+ `-v`                                         | Same as `--verbosity=2`
  `-q`                                         | Suppress stdout for successful tests. Stderr is printed to the console normally. Stdout is written to a buffer and discarded when a test succeeds. If it fails, the buffer is dumped to the console. Since stdio redirection in Java is a bad kludge (`System.setOut()` changes the static final field System.out through native code) this may not work for all scenarios. Scala has its own console with a sane redirection feature. If Scala is detected on the class path, junit-interface tries to reroute scala.Console's stdout, too.
  `-n`                                         | Do not use ANSI colors in the output even if sbt reports that they are supported.
  `-s`                                         | Try to decode Scala names in stack traces and test names. Fall back silently to non-decoded names if no matching Scala library is on the class path.
  `-a`                                         | Show stack traces and exception class name for AssertionErrors (thrown by all assert* methods in JUnit).`
  `-c`                                         | Do not print the exception class name prefix for any messages. With this option, only the result of getMessage() plus a stack trace is shown.
- `+v`                                         | Turn off `-v`. Takes precedence over `-v`.
+ `+v`                                         | Same as `--verbosity=0`
  `+q`                                         | Turn off `-q`. Takes precedence over `-q`.
  `+n`                                         | Turn off `-n`. Takes precedence over `-n`.
  `+s`                                         | Turn off `-s`. Takes precedence over `-s`.
@@ -34,6 +34,8 @@ The following options are supported for JUnit tests:
  `--run-listener=<CLASS_NAME>`                | A (user defined) class which extends `org.junit.runner.notification.RunListener`. An instance of this class is created and added to the JUnit Runner, so that it will receive the run events. For more information, see [RunListener](http://junit.org/javadoc/latest/org/junit/runner/notification/RunListener.html). *Note: this uses the test-classloader, so the class needs to be defined in `src/test` or `src/main` or included as a test or compile dependency*
  `--include-categories=<CLASSES>`             | A comma separated list of category class names that should be included. Only tests with one or more of these categories will be run.
  `--exclude-categories=<CLASSES>`             | A comma separated list of category class names that should be excluded. No tests that match one or more of these categories will be run.
+ `--verbosity=<INT>`                          | Higher verbosity logs more events at level "info" instead of "debug". 0: Default; 1: "Test run finished" at info; 2: Also "test run started" and "test started" at info; 3: Also "test finished" at info.
+ `--summary=<INT>`                            | The type of summary to show for a test task execution. 0: Leave to sbt (default); 1: One line; 2: Include list of failed tests
 
 Any parameter not starting with `-` or `+` is treated as a glob pattern for matching tests. Unlike the patterns given directly to sbt's `test-only` command, the patterns given to junit-interface will match against the full test names (as displayed by junit-interface) of all atomic test cases, so you can match on test methods and parts of suites with custom runners.
 

build.sbt

@@ -12,7 +12,7 @@ libraryDependencies ++= Seq(
   "org.scala-sbt" % "test-interface" % "1.0"
 )
 
-javacOptions in compile ++= List("-target", "1.5", "-source", "1.5")
+javacOptions in compile ++= List("-target", "1.8", "-source", "1.8")
 
 publishTo := Some(
   if(version.value.trim.endsWith("SNAPSHOT")) "snapshots" at "https://oss.sonatype.org/content/repositories/snapshots"

src/main/java/com/novocode/junit/EventDispatcher.java

@@ -1,5 +1,6 @@
 package com.novocode.junit;
 
+import java.util.ArrayList;
 import java.util.Collections;
 import java.util.Set;
 import java.util.concurrent.ConcurrentHashMap;
@@ -23,15 +24,20 @@ final class EventDispatcher extends RunListener
   private final ConcurrentHashMap<String, Long> startTimes = new ConcurrentHashMap<String, Long>();
   private final EventHandler handler;
   private final RunSettings settings;
-  private OutputCapture capture;
   private final Fingerprint fingerprint;
+  private final String taskInfo;
+  private final RunStatistics runStatistics;
+  private OutputCapture capture;
 
-  EventDispatcher(RichLogger logger, EventHandler handler, RunSettings settings, Fingerprint fingerprint)
+  EventDispatcher(RichLogger logger, EventHandler handler, RunSettings settings, Fingerprint fingerprint,
+                  Description taskDescription, RunStatistics runStatistics)
   {
     this.logger = logger;
     this.handler = handler;
     this.settings = settings;
     this.fingerprint = fingerprint;
+    this.taskInfo = settings.buildInfoName(taskDescription);
+    this.runStatistics = runStatistics;
   }
 
   private abstract class Event extends AbstractEvent {
@@ -85,7 +91,7 @@ public void testFinished(Description desc)
     uncapture(false);
     postIfFirst(new InfoEvent(desc, Status.Success) {
       void logTo(RichLogger logger) {
-        logger.debug("Test "+ansiName+" finished" + durationSuffix());
+        debugOrInfo("Test "+ansiName+" finished" + durationSuffix(), RunSettings.Verbosity.TEST_FINISHED);
       }
     });
     logger.popCurrentTestClassName();
@@ -106,7 +112,7 @@ public void testStarted(Description description)
   {
     recordStartTime(description);
     logger.pushCurrentTestClassName(description.getClassName());
-    debugOrInfo("Test " + settings.buildInfoName(description) + " started");
+    debugOrInfo("Test " + settings.buildInfoName(description) + " started", RunSettings.Verbosity.STARTED);
     capture();
   }
 
@@ -126,17 +132,18 @@ private Long elapsedTime(Description description) {
   @Override
   public void testRunFinished(Result result)
   {
-    debugOrInfo(c("Test run finished: ", INFO)+
+    debugOrInfo(c("Test run ", INFO)+taskInfo+c(" finished: ", INFO)+
       c(result.getFailureCount()+" failed", result.getFailureCount() > 0 ? ERRCOUNT : INFO)+
       c(", ", INFO)+
       c(result.getIgnoreCount()+" ignored", result.getIgnoreCount() > 0 ? IGNCOUNT : INFO)+
-      c(", "+result.getRunCount()+" total, "+(result.getRunTime()/1000.0)+"s", INFO));
+      c(", "+result.getRunCount()+" total, "+(result.getRunTime()/1000.0)+"s", INFO), RunSettings.Verbosity.RUN_FINISHED);
+    runStatistics.addTime(result.getRunTime());
   }
 
   @Override
   public void testRunStarted(Description description)
   {
-    debugOrInfo(c("Test run started", INFO));
+    debugOrInfo(c("Test run ", INFO)+taskInfo+c(" started", INFO), RunSettings.Verbosity.STARTED);
   }
 
   void testExecutionFailed(String testName, Throwable err)
@@ -151,12 +158,16 @@ void logTo(RichLogger logger) {
   private void postIfFirst(AbstractEvent e)
   {
     e.logTo(logger);
-    if(reported.add(e.fullyQualifiedName())) handler.handle(e);
+    if(reported.add(e.fullyQualifiedName())) {
+      runStatistics.captureStats(e);
+      handler.handle(e);
+    }
   }
 
   void post(AbstractEvent e)
   {
     e.logTo(logger);
+    runStatistics.captureStats(e);
     handler.handle(e);
   }
 
@@ -180,9 +191,9 @@ void uncapture(boolean replay)
     }
   }
 
-  private void debugOrInfo(String msg)
+  private void debugOrInfo(String msg, RunSettings.Verbosity atVerbosity)
   {
-    if(settings.verbose) logger.info(msg);
+    if(atVerbosity.ordinal() <= settings.verbosity.ordinal()) logger.info(msg);
     else logger.debug(msg);
   }
 }