Merge pull request #328 from scalacenter/fix/remove-l4j

Remove log4j
scalacenter · Mar 12, 2018 · bee471d · bee471d
2 parents 62f408d + 703f85c
commit bee471d
Show file tree

Hide file tree

Showing 6 changed files with 116 additions and 147 deletions.
diff --git a/backend/src/main/scala/bloop/logging/BloopLogger.scala b/backend/src/main/scala/bloop/logging/BloopLogger.scala
@@ -1,89 +1,73 @@
 package bloop.logging
 
 import java.io.{FileOutputStream, OutputStream, PrintStream}
+import java.util.concurrent.atomic.AtomicInteger
+
+import scala.Console.{CYAN, GREEN, RED, RESET, YELLOW}
 
 import bloop.io.AbsolutePath
-import org.apache.logging.log4j
-import org.apache.logging.log4j.{Level, LogManager}
-import org.apache.logging.log4j.core.{Filter, LoggerContext}
-import org.apache.logging.log4j.core.appender.{ConsoleAppender, OutputStreamAppender}
-import org.apache.logging.log4j.core.filter.{CompositeFilter, Filterable, ThresholdFilter}
-import org.apache.logging.log4j.core.layout.PatternLayout
-import org.apache.logging.log4j.core.config.{AppenderRef, Configurator, LoggerConfig}
 
 /**
- * Creates a logger that is backed up by a Log4j logger.
+ * Creates a logger that writes to the given streams.
  *
  * @param name The name of this logger.
  * @param out  The stream to use to write `INFO` and `WARN` level messages.
  * @param err  The stream to use to write `FATAL`, `ERROR`, `DEBUG` and `TRACE` level messages.
  */
 class BloopLogger(override val name: String, out: PrintStream, err: PrintStream)
     extends AbstractLogger {
-  private val logger: log4j.Logger = LogManager.getLogger(name)
-
-  private val outAppender = createAppender(out, "out", BloopLogger.outFilter)
-  private val errAppender = createAppender(err, "err", BloopLogger.normalErrFilter)
 
-  initialize()
+  private val verboseCount: AtomicInteger = new AtomicInteger(0)
 
   override def ansiCodesSupported() = true
-  override def debug(msg: String): Unit = msg.lines.foreach(logger.debug)
-  override def error(msg: String): Unit = msg.lines.foreach(logger.error)
-  override def warn(msg: String): Unit = msg.lines.foreach(logger.warn)
-  override def trace(exception: Throwable): Unit = logger.trace(exception)
-  override def info(msg: String): Unit = msg.lines.foreach(logger.info)
+  override def debug(msg: String): Unit = if (isVerbose) print(msg, printDebug)
+  override def error(msg: String): Unit = print(msg, printError)
+  override def warn(msg: String): Unit = print(msg, printWarning)
+  override def trace(exception: Throwable): Unit = trace("", exception)
+  override def info(msg: String): Unit = print(msg, printInfo)
 
   override def verbose[T](op: => T): T = {
-    val previousFilter = errAppender.getFilter()
-    val newFilter = BloopLogger.verboseErrFilter
-    BloopLogger.switchFilters(errAppender, previousFilter, newFilter)
+    val _ = verboseCount.incrementAndGet()
     try op
-    finally BloopLogger.switchFilters(errAppender, newFilter, previousFilter)
+    finally { verboseCount.decrementAndGet(); () }
   }
 
-  override def isVerbose: Boolean = errAppender.getFilter eq BloopLogger.verboseErrFilter
+  override def isVerbose: Boolean = verboseCount.get > 0
 
-  private[this] def initialize(): Unit = BloopLogger.synchronized {
-    removeAllAppenders()
+  @scala.annotation.tailrec
+  private def trace(prefix: String, exception: Throwable): Unit = {
+    if (isVerbose) {
+      print(prefix + exception.toString(), printTrace)
+      exception.getStackTrace.foreach(ste => print("\t" + ste.toString, printTrace))
 
-    outAppender.start()
-    errAppender.start()
+      val cause = exception.getCause
+      if (cause != null) trace("Caused by: ", cause)
+    }
+  }
 
-    val coreLogger = logger.asInstanceOf[log4j.core.Logger]
-    coreLogger.addAppender(outAppender)
-    coreLogger.addAppender(errAppender)
+  private def print(msg: String, fn: String => Unit): Unit = {
+    val lines = msg.split("\\r?\\n", -1)
+    lines.foreach(fn)
   }
 
-  private[this] def removeAllAppenders(): Unit = BloopLogger.synchronized {
-    val coreLogger = logger.asInstanceOf[log4j.core.Logger]
-    val appenders = coreLogger.getAppenders()
-    appenders.forEach {
-      case (_, appender) => coreLogger.removeAppender(appender)
-    }
+  private def printInfo(line: String): Unit = {
+    out.println(line)
   }
 
-  /**
-   * Instantiate an `Appender` for writing to `stream`, using filter `filter`.
-   *
-   * @param stream     The stream to which this `Appender` should write.
-   * @param nameSuffix A suffix to add to this `Appender`'s name, unique per instance.
-   * @param filter     The filter to use to determine whether to accept a log event.
-   * @return An `Appender` writing to `stream` the log events that `filter` accepts.
-   */
-  private[this] def createAppender(stream: PrintStream,
-                                   nameSuffix: String,
-                                   filter: Filter): OutputStreamAppender = {
-    val layout = PatternLayout.newBuilder().withPattern(BloopLogger.DefaultLayout).build()
-    val appender = OutputStreamAppender
-      .newBuilder()
-      .setName(s"$name-$nameSuffix")
-      .setFilter(filter)
-      .setLayout(layout)
-      .setTarget(stream)
-      .build()
-
-    appender
+  private def printWarning(line: String): Unit = {
+    out.println(s"${RESET}${YELLOW}[W]${RESET} $line")
+  }
+
+  private def printError(line: String): Unit = {
+    err.println(s"${RESET}${RED}[E]${RESET} $line")
+  }
+
+  private def printTrace(line: String): Unit = {
+    err.println(s"${RESET}${CYAN}[T]${RESET} $line")
+  }
+
+  private def printDebug(line: String): Unit = {
+    err.println(s"${RESET}${GREEN}[D]${RESET} $line")
   }
 
 }
@@ -110,79 +94,4 @@ object BloopLogger {
    */
   def default(name: String): BloopLogger = at(name, System.out, System.err)
 
-  private val DefaultLayout: String =
-    "%highlight{%equals{[%-0.-1level] }{[I] }{}}{FATAL=white, ERROR=bright red, WARN=yellow, INFO=dim blue, DEBUG=green, TRACE=blue}%msg%n"
-  private final val AppenderName = "BloopCommonOptionsAppender"
-
-  /**
-   * A filter that accepts events whose `level` is `level` or more specific. For less
-   * specific events, this filter returns `NEUTRAL`.
-   *
-   * @param level The least specific `Level` that this filter should accept.
-   * @return A filter that accepts events at level `Level` or more specific.
-   */
-  private[this] def accept(level: Level) = {
-    ThresholdFilter.createFilter(level, Filter.Result.ACCEPT, Filter.Result.NEUTRAL)
-  }
-
-  /**
-   * A filter that rejects events whose `level` is `level` or more specific. For less
-   * specific events, this filter returns `NEUTRAL`.
-   *
-   * @param level The least specific `Level` that this filter should reject.
-   * @return A filter that rejects events at level `Level` or more specific.
-   */
-  private[this] def deny(level: Level) = {
-    ThresholdFilter.createFilter(level, Filter.Result.DENY, Filter.Result.NEUTRAL)
-  }
-
-  /** A filter that rejects all messages. */
-  private[this] val denyAll = {
-    deny(Level.ALL)
-  }
-
-  /**
-   * The filter for writing to the `out` stream. Accepts messages between levels
-   * `WARN` and `INFO`. All other messages are rejected.
-   */
-  private val outFilter = {
-    val rejectErrorAndUp = deny(Level.ERROR)
-    val acceptInfoAndUp = accept(Level.INFO)
-    CompositeFilter.createFilters(Array(rejectErrorAndUp, acceptInfoAndUp, denyAll))
-  }
-
-  /**
-   * The filter for writing to the `err` stream. Accepts messages at level `ERROR` and
-   * up. All other messages are rejected.
-   */
-  private val normalErrFilter = {
-    val acceptErrorAndUp = accept(Level.ERROR)
-    CompositeFilter.createFilters(Array(acceptErrorAndUp, denyAll))
-  }
-
-  /**
-   * The filter for writing to the `err` stream when the logger is in `verbose` mode.
-   * Accepts messages at levels `ERROR` and up, and below `INFO`. Messages between levels
-   * `WARN` and `INFO` are rejected.
-   */
-  private val verboseErrFilter = {
-    val acceptErrorAndUp = accept(Level.ERROR)
-    val rejectInfoAndUp = deny(Level.INFO)
-    val acceptAll = accept(Level.ALL)
-    CompositeFilter.createFilters(Array(acceptErrorAndUp, rejectInfoAndUp, acceptAll))
-  }
-
-  /**
-   * Replaces the filter `previousFilter` with `newFilter` in `filterable`.
-   *
-   * @param filterable     The `Filterable` for which filters should be replaced.
-   * @param previousFilter The current filter.
-   * @param newFilter      The new filter to install in place of `previousFilter`.
-   */
-  private def switchFilters(filterable: Filterable,
-                            previousFilter: Filter,
-                            newFilter: Filter): Unit = {
-    filterable.removeFilter(previousFilter)
-    filterable.addFilter(newFilter)
-  }
 }
diff --git a/build.sbt b/build.sbt
@@ -3,12 +3,11 @@ import build.BuildImplementation.BuildDefaults
 /***************************************************************************************************/
 /*                      This is the build definition of the source deps                            */
 /***************************************************************************************************/
-
 val benchmarkBridge = project
   .in(file(".benchmark-bridge-compilation"))
   .aggregate(BenchmarkBridgeCompilation)
   .settings(
-    releaseEarly := {()},
+    releaseEarly := { () },
     skip in publish := true
   )
 
@@ -30,8 +29,6 @@ val backend = project
       Dependencies.configDirectories,
       Dependencies.caseApp,
       Dependencies.sourcecode,
-      Dependencies.log4jApi,
-      Dependencies.log4jCore,
       Dependencies.sbtTestInterface,
       Dependencies.sbtTestAgent,
       Dependencies.monix,
@@ -114,7 +111,7 @@ val bloop = project
   .in(file("."))
   .aggregate(allProjectReferences: _*)
   .settings(
-    releaseEarly := {()},
+    releaseEarly := { () },
     skip in publish := true,
     crossSbtVersions := Seq("1.1.0", "0.13.16")
   )

diff --git a/frontend/src/test/scala/bloop/logging/BloopLoggerSpec.scala b/frontend/src/test/scala/bloop/logging/BloopLoggerSpec.scala
@@ -54,29 +54,44 @@ class BloopLoggerSpec {
   @Test
   def debugAndTraceMessagesGoToErrInVerboseMode =
     runAndCheck { logger =>
+      val ex0 = {
+        val ex = new Exception("trace0")
+        ex.setStackTrace(ex.getStackTrace.take(3))
+        ex
+      }
       logger.error("error0")
       logger.warn("warn0")
       logger.info("info0")
       logger.debug("debug0")
-      logger.trace(new Exception("trace0"))
+      logger.trace(ex0)
 
       logger.verbose {
+        val ex1 = {
+          val ex = new Exception("trace1")
+          ex.setStackTrace(ex.getStackTrace.take(3))
+          ex
+        }
         logger.error("error1")
         logger.warn("warn1")
         logger.info("info1")
         logger.debug("debug1")
-        logger.trace(new Exception("trace1"))
+        logger.trace(ex1)
       }
 
+      val ex2 = {
+        val ex = new Exception("trace2")
+        ex.setStackTrace(ex.getStackTrace.take(3))
+        ex
+      }
       logger.error("error2")
       logger.warn("warn2")
       logger.info("info2")
       logger.debug("debug2")
-      logger.trace(new Exception("trace2"))
+      logger.trace(ex2)
 
     } { (outMsgs, errMsgs) =>
       assertEquals(6, outMsgs.length.toLong)
-      assertEquals(5, errMsgs.length.toLong)
+      assertEquals(8, errMsgs.length.toLong)
 
       assert(isWarn(outMsgs(0)) && outMsgs(0).endsWith("warn0"))
       assert(isInfo(outMsgs(1)) && outMsgs(1).endsWith("info0"))
@@ -89,7 +104,7 @@ class BloopLoggerSpec {
       assert(isError(errMsgs(1)) && errMsgs(1).endsWith("error1"))
       assert(isDebug(errMsgs(2)) && errMsgs(2).endsWith("debug1"))
       assert(isTrace(errMsgs(3)) && errMsgs(3).endsWith("java.lang.Exception: trace1"))
-      assert(isError(errMsgs(4)) && errMsgs(4).endsWith("error2"))
+      assert(isError(errMsgs(7)) && errMsgs(7).endsWith("error2"))
     }
 
   @Test

diff --git a/frontend/src/test/scala/bloop/nailgun/BasicNailgunSpec.scala b/frontend/src/test/scala/bloop/nailgun/BasicNailgunSpec.scala
@@ -1,8 +1,12 @@
 package bloop.nailgun
 
+import scala.Console.{GREEN, RESET}
+
 import org.junit.{Ignore, Test}
 import org.junit.Assert.{assertEquals, assertTrue}
 
+import bloop.logging.RecordingLogger
+
 class BasicNailgunSpec extends NailgunTest {
 
   @Test
@@ -119,7 +123,54 @@ class BasicNailgunSpec extends NailgunTest {
         case ("info", msg) => msg.contains(needle)
         case _ => false
       }
-      assertEquals(s"${messages.mkString("\n")} should contain four times '$needle'", 4, matches.toLong)
+      assertEquals(s"${messages.mkString("\n")} should contain four times '$needle'",
+                   4,
+                   matches.toLong)
+    }
+  }
+
+  @Test
+  def testSeveralConcurrentClients(): Unit = {
+    withServerInProject("with-resources") { (logger1, client1) =>
+      val debugPrefix = s"${RESET}${GREEN}[D]${RESET} "
+      val logger2 = new RecordingLogger
+      val client2 = client1.copy(log = logger2)
+
+      val thread1 = new Thread {
+        override def run() = {
+          (1 to 3).foreach { _ =>
+            client1.success("clean", "with-resources-test")
+            client1.success("compile", "with-resources-test", "--verbose")
+          }
+        }
+      }
+
+      val thread2 = new Thread {
+        override def run() = {
+          try while (true) client2.success("projects")
+          catch { case _: InterruptedException => () }
+        }
+      }
+
+      thread1.start()
+      Thread.sleep(1000)
+      thread2.start()
+
+      thread1.join()
+      thread2.interrupt()
+
+      val msgs1 = logger1.getMessages.map(_._2)
+      val msgs2 = logger2.getMessages.map(_._2)
+
+      assertTrue("`logger1` received messages of `logger2`",
+                 !msgs1.exists(_.startsWith("Projects loaded from")))
+      assertEquals("`logger` didn't receive verbose messages",
+                   3,
+                   msgs1.count(_.startsWith(s"${debugPrefix}Elapsed:")).toLong)
+      assertTrue("`logger2` received messages of `logger1`",
+                 !msgs2.exists(_.startsWith("Compiling")))
+      assertTrue("`logger2` received verbose messages of `logger1`",
+                 !msgs2.exists(_.startsWith(debugPrefix)))
     }
   }
 

diff --git a/frontend/src/test/scala/bloop/nailgun/NailgunTest.scala b/frontend/src/test/scala/bloop/nailgun/NailgunTest.scala
@@ -77,7 +77,7 @@ abstract class NailgunTest {
    * @param port The port on which the client should communicate with the server.
    * @param base The base directory from which the client is running.
    */
-  class Client(port: Int, log: RecordingLogger, base: Path) {
+  case class Client(port: Int, log: RecordingLogger, base: Path) {
 
     private val clientPath = bloop.internal.build.BuildInfo.nailgunClientLocation.getAbsolutePath
 

diff --git a/project/Dependencies.scala b/project/Dependencies.scala
@@ -9,7 +9,6 @@ object Dependencies {
   val configDirsVersion = "5"
   val caseAppVersion = "1.2.0"
   val sourcecodeVersion = "0.1.4"
-  val log4jVersion = "2.8.1"
   val sbtTestInterfaceVersion = "1.0"
   val sbtTestAgentVersion = "1.0.4"
   val junitVersion = "0.11"
@@ -32,8 +31,6 @@ object Dependencies {
   val coursierCache = "io.get-coursier" %% "coursier-cache" % coursierVersion
   val caseApp = "com.github.alexarchambault" %% "case-app" % caseAppVersion
   val sourcecode = "com.lihaoyi" %% "sourcecode" % sourcecodeVersion
-  val log4jApi = "org.apache.logging.log4j" % "log4j-api" % log4jVersion
-  val log4jCore = "org.apache.logging.log4j" % "log4j-core" % log4jVersion
   val sbtTestInterface = "org.scala-sbt" % "test-interface" % sbtTestInterfaceVersion
   val sbtTestAgent = "org.scala-sbt" % "test-agent" % sbtTestAgentVersion