Port WithLogCapturing + Silence TLSSpec (#24476)

* =tkt port WithLogCapturing from akka-http

* =str use WithLogCapturing for very noisy TLSSpec

* =sha use WithLogCapturing to silence noisy CoordinatedShutdownShardingSpec

akka-cluster-sharding/src/test/scala/akka/cluster/sharding/CoordinatedShutdownShardingSpec.scala

@@ -4,7 +4,6 @@
 package akka.cluster.sharding
 
 import scala.concurrent.Future
-
 import scala.concurrent.duration._
 import akka.Done
 import akka.actor.ActorSystem
@@ -15,11 +14,13 @@ import akka.cluster.MemberStatus
 import akka.testkit.AkkaSpec
 import akka.testkit.TestActors.EchoActor
 import akka.testkit.TestProbe
+import akka.testkit.WithLogCapturing
 
 object CoordinatedShutdownShardingSpec {
   val config =
     """
     akka.loglevel = DEBUG
+    akka.loggers = ["akka.testkit.SilenceAllTestEventListener"]
     akka.actor.provider = "cluster"
     akka.remote.netty.tcp.port = 0
     akka.remote.artery.canonical.port = 0
@@ -34,7 +35,7 @@ object CoordinatedShutdownShardingSpec {
   }
 }
 
-class CoordinatedShutdownShardingSpec extends AkkaSpec(CoordinatedShutdownShardingSpec.config) {
+class CoordinatedShutdownShardingSpec extends AkkaSpec(CoordinatedShutdownShardingSpec.config) with WithLogCapturing {
   import CoordinatedShutdownShardingSpec._
 
   val sys1 = ActorSystem(system.name, system.settings.config)

akka-stream-tests/src/test/scala/akka/stream/io/TlsSpec.scala

@@ -20,11 +20,11 @@ import akka.stream.scaladsl._
 import akka.stream.stage._
 import akka.stream.testkit._
 import akka.stream.testkit.Utils._
-import akka.testkit.EventFilter
 import akka.util.ByteString
 import javax.net.ssl._
 
 import akka.stream.impl.fusing.GraphStages.SimpleLinearGraphStage
+import akka.testkit.WithLogCapturing
 
 object TlsSpec {
 
@@ -82,9 +82,15 @@ object TlsSpec {
     }
   }
 
+  val configOverrides =
+    """
+      akka.loglevel = DEBUG
+      akka.loggers = ["akka.testkit.SilenceAllTestEventListener"]
+      akka.actor.debug.receive=off
+    """
 }
 
-class TlsSpec extends StreamSpec("akka.loglevel=DEBUG\nakka.actor.debug.receive=off") {
+class TlsSpec extends StreamSpec(TlsSpec.configOverrides) with WithLogCapturing {
   import TlsSpec._
 
   import system.dispatcher
@@ -375,12 +381,6 @@ class TlsSpec extends StreamSpec("akka.loglevel=DEBUG\nakka.actor.debug.receive=
         Await.result(f, 8.seconds).utf8String should be(scenario.output.utf8String)
 
         commPattern.cleanup()
-
-        // flush log so as to not mix up logs of different test cases
-        if (log.isDebugEnabled)
-          EventFilter.debug("stopgap", occurrences = 1) intercept {
-            log.debug("stopgap")
-          }
       }
     }
 

akka-testkit/src/test/scala/akka/testkit/WithLogCapturing.scala

@@ -0,0 +1,87 @@
+/*
+ * Copyright (C) 2009-2018 Lightbend Inc. <https://www.lightbend.com>
+ */
+
+package akka.testkit
+
+import java.io.{ OutputStream, PrintStream }
+
+import akka.actor.ActorSystem
+import akka.event.Logging
+import akka.event.Logging._
+import akka.testkit.{ EventFilter, TestEventListener }
+import org.scalatest.{ Outcome, SuiteMixin, TestSuite }
+
+/**
+ * Mixin this trait to a test to make log lines appear only when the test failed.
+ */
+trait WithLogCapturing extends SuiteMixin { this: TestSuite ⇒
+  implicit def system: ActorSystem
+
+  abstract override def withFixture(test: NoArgTest): Outcome = {
+    // When filtering just collects events into this var (yeah, it's a hack to do that in a filter).
+    // We assume that the filter will always ever be used from a single actor, so a regular var should be fine.
+    var events: List[LogEvent] = Nil
+
+    object LogEventCollector extends EventFilter(Int.MaxValue) {
+      override protected def matches(event: Logging.LogEvent): Boolean = {
+        events ::= event
+        true
+      }
+    }
+
+    val myLogger = Logging(system, classOf[WithLogCapturing])
+    val res = LogEventCollector.intercept {
+      myLogger.debug(s"Logging started for test [${test.name}]")
+      val r = test()
+      myLogger.debug(s"Logging finished for test [${test.name}]")
+      r
+    }
+
+    if (!(res.isSucceeded || res.isPending)) {
+      println(s"--> [${Console.BLUE}${test.name}${Console.RESET}] Start of log messages of test that [$res]")
+      val logger = new StdOutLogger {}
+      withPrefixedOut("| ") { events.reverse.foreach(logger.print) }
+      println(s"<-- [${Console.BLUE}${test.name}${Console.RESET}] End of log messages of test that [$res]")
+    }
+
+    res
+  }
+
+  /** Adds a prefix to every line printed out during execution of the thunk. */
+  private def withPrefixedOut[T](prefix: String)(thunk: ⇒ T): T = {
+    val oldOut = Console.out
+    val prefixingOut =
+      new PrintStream(new OutputStream {
+        override def write(b: Int): Unit = oldOut.write(b)
+      }) {
+        override def println(x: Any): Unit =
+          oldOut.println(prefix + String.valueOf(x).replaceAllLiterally("\n", s"\n$prefix"))
+      }
+
+    Console.withOut(prefixingOut) {
+      thunk
+    }
+  }
+}
+
+/**
+ * An adaption of TestEventListener that never prints debug logs itself. Use together with [[akka.http.impl.util.WithLogCapturing]].
+ * It allows to enable noisy DEBUG logging for tests and silence pre/post test DEBUG output completely while still showing
+ * test-specific DEBUG output selectively
+ */
+class DebugLogSilencingTestEventListener extends TestEventListener {
+  override def print(event: Any): Unit = event match {
+    case d: Debug ⇒ // ignore
+    case _        ⇒ super.print(event)
+  }
+}
+
+/**
+ * An adaption of TestEventListener that does not print out any logs. Use together with [[akka.http.impl.util.WithLogCapturing]].
+ * It allows to enable noisy logging for tests and silence pre/post test log output completely while still showing
+ * test-specific log output selectively on failures.
+ */
+class SilenceAllTestEventListener extends TestEventListener {
+  override def print(event: Any): Unit = ()
+}