Report stats after each test suite execution (zio#1435)

* Report stats after each test suite execution

* Fix zio-test-sbt test

test-sbt/jvm/src/test/scala/zio/test/sbt/ZTestFrameworkSpec.scala

@@ -68,7 +68,8 @@ object ZTestFrameworkSpec {
             s"info: ${red("- some suite")}",
             s"info:   ${red("- failing test")}",
             s"info:     ${blue("1")} did not satisfy ${cyan("equals(2)")}",
-            s"info:   ${green("+")} passing test"
+            s"info:   ${green("+")} passing test",
+            s"info: ${cyan("Ran 3 tests in 0 seconds: 1 succeeded, 1 ignored, 1 failed")}"
           )
         )
       )

test-sbt/shared/src/main/scala/zio/test/sbt/BaseTestTask.scala

@@ -1,6 +1,7 @@
 package zio.test.sbt
 
 import sbt.testing.{ EventHandler, Logger, Task, TaskDef }
+import zio.clock.Clock
 import zio.test.{ AbstractRunnableSpec, TestLogger }
 import zio.{ Runtime, ZIO }
 
@@ -17,7 +18,7 @@ abstract class BaseTestTask(val taskDef: TaskDef, testClassLoader: ClassLoader)
 
   protected def run(eventHandler: EventHandler, loggers: Array[Logger]) =
     for {
-      res    <- spec.run.provide(new SbtTestLogger(loggers))
+      res    <- spec.run.provide(new SbtTestLogger(loggers) with Clock.Live)
       events = ZTestEvent.from(res, taskDef.fullyQualifiedName, taskDef.fingerprint)
       _      <- ZIO.foreach[Any, Throwable, ZTestEvent, Unit](events)(e => ZIO.effect(eventHandler.handle(e)))
     } yield ()

test/shared/src/main/scala/zio/test/DefaultTestReporter.scala

@@ -20,8 +20,8 @@ import zio.test.RenderedResult.CaseType._
 import zio.test.RenderedResult.Status._
 import zio.test.RenderedResult.{ CaseType, Status }
 import zio.{ Cause, ZIO }
-
 import scala.{ Console => SConsole }
+import zio.duration.Duration
 
 object DefaultTestReporter {
 
@@ -47,12 +47,35 @@ object DefaultTestReporter {
     loop(executedSpec, 0)
   }
 
-  def apply[L](): TestReporter[L] = { executedSpec: ExecutedSpec[L] =>
+  def apply[L](): TestReporter[L] = { (duration: Duration, executedSpec: ExecutedSpec[L]) =>
     ZIO
       .foreach(render(executedSpec.mapLabel(_.toString))) { res =>
         ZIO.foreach(res.rendered)(TestLogger.logLine)
+      } *> logStats(duration, executedSpec)
+  }
+
+  private def logStats[L](duration: Duration, executedSpec: ExecutedSpec[L]) = {
+    def loop(executedSpec: ExecutedSpec[String]): (Int, Int, Int) =
+      executedSpec.caseValue match {
+        case Spec.SuiteCase(_, executedSpecs, _) =>
+          executedSpecs.map(loop).foldLeft((0, 0, 0)) {
+            case ((x1, x2, x3), (y1, y2, y3)) => (x1 + y1, x2 + y2, x3 + y3)
+          }
+        case Spec.TestCase(_, result) =>
+          result match {
+            case Assertion.Success    => (1, 0, 0)
+            case Assertion.Ignore     => (0, 1, 0)
+            case Assertion.Failure(_) => (0, 0, 1)
+          }
       }
-      .unit
+    val (success, ignore, failure) = loop(executedSpec.mapLabel(_.toString))
+    val total                      = success + ignore + failure
+    val seconds                    = duration.toMillis / 1000
+    TestLogger.logLine(
+      cyan(
+        s"Ran $total test${if (total == 1) "" else "s"} in $seconds second${if (seconds == 1) "" else "s"}: $success succeeded, $ignore ignored, $failure failed"
+      )
+    )
   }
 
   private def renderSuccessLabel(label: String, offset: Int) =

test/shared/src/main/scala/zio/test/RunnableSpec.scala

@@ -17,6 +17,7 @@
 package zio.test
 
 import zio.URIO
+import zio.clock.Clock
 import zio.test.reflect.Reflect.EnableReflectiveInstantiation
 
 /**
@@ -41,7 +42,7 @@ abstract class AbstractRunnableSpec {
   /**
    * Returns an effect that executes the spec, producing the results of the execution.
    */
-  final def run: URIO[TestLogger, ExecutedSpec[Label]] = runner.run(spec)
+  final def run: URIO[TestLogger with Clock, ExecutedSpec[Label]] = runner.run(spec)
 
   /**
    * the platform used by the runner

test/shared/src/main/scala/zio/test/TestRunner.scala

@@ -17,6 +17,7 @@
 package zio.test
 
 import zio._
+import zio.clock.Clock
 import zio.console.Console
 import zio.internal.{ Platform, PlatformLive }
 
@@ -36,24 +37,28 @@ case class TestRunner[L, -T](
   /**
    * Runs the spec, producing the execution results.
    */
-  final def run(spec: Spec[L, T]): URIO[TestLogger, ExecutedSpec[L]] =
-    executor(spec, ExecutionStrategy.ParallelN(4)).flatMap { results =>
-      reporter(results) *> ZIO.succeed(results)
+  final def run(spec: Spec[L, T]): URIO[TestLogger with Clock, ExecutedSpec[L]] =
+    executor(spec, ExecutionStrategy.ParallelN(4)).timed.flatMap {
+      case (duration, results) => reporter(duration, results).as(results)
     }
 
   /**
    * An unsafe, synchronous run of the specified spec.
    */
-  final def unsafeRun(spec: Spec[L, T], testLogger: TestLogger = defaultTestLogger): ExecutedSpec[L] =
-    Runtime((), platform).unsafeRun(run(spec).provide(testLogger))
+  final def unsafeRun(
+    spec: Spec[L, T],
+    testLogger: TestLogger = defaultTestLogger,
+    clock: Clock = Clock.Live
+  ): ExecutedSpec[L] =
+    Runtime((), platform).unsafeRun(run(spec).provide(buildEnv(testLogger, clock)))
 
   /**
    * An unsafe, asynchronous run of the specified spec.
    */
-  final def unsafeRunAsync(spec: Spec[L, T], testLogger: TestLogger = defaultTestLogger)(
+  final def unsafeRunAsync(spec: Spec[L, T], testLogger: TestLogger = defaultTestLogger, clock: Clock = Clock.Live)(
     k: ExecutedSpec[L] => Unit
   ): Unit =
-    Runtime((), platform).unsafeRunAsync(run(spec).provide(testLogger)) {
+    Runtime((), platform).unsafeRunAsync(run(spec).provide(buildEnv(testLogger, clock))) {
       case Exit.Success(v) => k(v)
       case Exit.Failure(c) => throw FiberFailure(c)
     }
@@ -63,12 +68,18 @@ case class TestRunner[L, -T](
    */
   final def unsafeRunSync(
     spec: Spec[L, T],
-    testLogger: TestLogger = defaultTestLogger
+    testLogger: TestLogger = defaultTestLogger,
+    clock: Clock = Clock.Live
   ): Exit[Nothing, ExecutedSpec[L]] =
-    Runtime((), platform).unsafeRunSync(run(spec).provide(testLogger))
+    Runtime((), platform).unsafeRunSync(run(spec).provide(buildEnv(testLogger, clock)))
 
   /**
    * Creates a copy of this runner replacing the reporter.
    */
   final def withReporter(reporter: TestReporter[L]) = copy(reporter = reporter)
+
+  private def buildEnv(loggerSvc: TestLogger, clockSvc: Clock): TestLogger with Clock = new TestLogger with Clock {
+    override def testLogger: TestLogger.Service = loggerSvc.testLogger
+    override val clock: Clock.Service[Any]      = clockSvc.clock
+  }
 }

test/shared/src/main/scala/zio/test/package.scala

@@ -16,6 +16,7 @@
 
 package zio
 
+import zio.duration.Duration
 import zio.stream.{ ZSink, ZStream }
 
 /**
@@ -49,14 +50,14 @@ package object test {
    * A `TestReporter[L]` is capable of reporting test results annotated with
    * labels `L`.
    */
-  type TestReporter[-L] = ExecutedSpec[L] => URIO[TestLogger, Unit]
+  type TestReporter[-L] = (Duration, ExecutedSpec[L]) => URIO[TestLogger, Unit]
 
   object TestReporter {
 
     /**
      * TestReporter that does nothing
      */
-    def silent[L]: TestReporter[L] = _ => ZIO.unit
+    def silent[L]: TestReporter[L] = (_, _) => ZIO.unit
   }
 
   /**

test/shared/src/test/scala/zio/test/DefaultTestReporterSpec.scala

@@ -3,6 +3,7 @@ package zio.test
 import scala.concurrent.{ ExecutionContext, Future }
 import zio._
 import scala.{ Console => SConsole }
+import zio.clock.Clock
 import zio.test.mock._
 import zio.test.TestUtils.label
 
@@ -82,31 +83,39 @@ object DefaultTestReporterSpec extends DefaultRuntime {
     withOffset(2)(test2Expected)
   ) ++ test3Expected.map(withOffset(2)(_))
 
+  def reportStats(success: Int, ignore: Int, failure: Int) = {
+    val total = success + ignore + failure
+    cyan(
+      s"Ran $total test${if (total == 1) "" else "s"} in 0 seconds: $success succeeded, $ignore ignored, $failure failed"
+    ) + "\n"
+  }
+
   def reportSuccess =
-    check(test1, Vector(test1Expected))
+    check(test1, Vector(test1Expected, reportStats(1, 0, 0)))
 
   def reportFailure =
-    check(test3, test3Expected)
+    check(test3, test3Expected :+ reportStats(0, 0, 1))
 
   def reportError =
-    check(test4, test4Expected)
+    check(test4, test4Expected :+ reportStats(0, 0, 1))
 
   def reportSuite1 =
-    check(suite1, suite1Expected)
+    check(suite1, suite1Expected :+ reportStats(2, 0, 0))
 
   def reportSuite2 =
-    check(suite2, suite2Expected)
+    check(suite2, suite2Expected :+ reportStats(2, 0, 1))
 
   def reportSuites =
     check(
       suite("Suite3")(suite1, test3),
-      Vector(expectedFailure("Suite3")) ++ suite1Expected.map(withOffset(2)) ++ test3Expected.map(withOffset(2))
+      Vector(expectedFailure("Suite3")) ++ suite1Expected.map(withOffset(2)) ++ test3Expected
+        .map(withOffset(2)) :+ reportStats(2, 0, 1)
     )
 
   def simplePredicate =
     check(
       test5,
-      test5Expected
+      test5Expected :+ reportStats(0, 0, 1)
     )
 
   def expectedSuccess(label: String): String =
@@ -136,7 +145,15 @@ object DefaultTestReporterSpec extends DefaultRuntime {
   def check[E](spec: ZSpec[MockEnvironment, E, String], expected: Vector[String]): Future[Boolean] =
     unsafeRunWith(mockEnvironmentManaged) { r =>
       val zio = for {
-        _      <- MockTestRunner(r).run(spec).provideSomeM(TestLogger.fromConsoleM)
+        _ <- MockTestRunner(r)
+              .run(spec)
+              .provideSomeM(for {
+                logSvc   <- TestLogger.fromConsoleM
+                clockSvc <- MockClock.make(MockClock.DefaultData)
+              } yield new TestLogger with Clock {
+                override def testLogger: TestLogger.Service = logSvc.testLogger
+                override val clock: Clock.Service[Any]      = clockSvc.clock
+              })
         output <- MockConsole.output
       } yield output == expected
       zio.provide(r)