From 36eeb4578d7233d6a0d8873efa0ca42ae7e76307 Mon Sep 17 00:00:00 2001 From: Eugene Yokota Date: Fri, 13 Jan 2017 02:49:12 -0500 Subject: [PATCH] Reimplement multi-logger using log4j2 This introduces ManagedLogger, which is a wrapper around Log4j2's async logging. Log4j2 separates the notion of logger (the code that collects events) and appender (the code that acts on events). The old code is kept around intentionally to minimize breakage during transition. --- build.sbt | 9 +- .../sbt/internal/util/AbstractEntry.scala | 27 +++ .../sbt/internal/util/ChannelLogEntry.scala | 51 ++++++ .../util/codec/AbstractEntryFormats.scala | 10 ++ .../util/codec/ChannelLogEntryFormats.scala | 33 ++++ .../internal/util/codec/JsonProtocol.scala | 10 ++ .../src/main/contraband/logging.contra | 16 ++ ...soleLogger.scala => ConsoleAppender.scala} | 164 +++++++++++++++--- .../scala/sbt/internal/util/ConsoleOut.scala | 2 +- .../sbt/internal/util/GlobalLogging.scala | 30 +++- .../scala/sbt/internal/util/MainLogging.scala | 77 +++++--- .../sbt/internal/util/ManagedLogger.scala | 25 +++ .../scala/sbt/internal/util/MultiLogger.scala | 2 +- .../src/main/scala/sbt/util/LogExchange.scala | 75 ++++++++ .../resources/log4j2.component.properties | 1 + .../util-logging/src/test/scala/Escapes.scala | 2 +- .../src/test/scala/ManagedLoggerSpec.scala | 52 ++++++ project/Dependencies.scala | 7 +- project/contraband.sbt | 1 + 19 files changed, 533 insertions(+), 61 deletions(-) create mode 100644 internal/util-logging/src/main/contraband-scala/sbt/internal/util/AbstractEntry.scala create mode 100644 internal/util-logging/src/main/contraband-scala/sbt/internal/util/ChannelLogEntry.scala create mode 100644 internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/AbstractEntryFormats.scala create mode 100644 internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/ChannelLogEntryFormats.scala create mode 100644 internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/JsonProtocol.scala create mode 100644 internal/util-logging/src/main/contraband/logging.contra rename internal/util-logging/src/main/scala/sbt/internal/util/{ConsoleLogger.scala => ConsoleAppender.scala} (55%) create mode 100644 internal/util-logging/src/main/scala/sbt/internal/util/ManagedLogger.scala create mode 100644 internal/util-logging/src/main/scala/sbt/util/LogExchange.scala create mode 100644 internal/util-logging/src/test/resources/log4j2.component.properties create mode 100644 internal/util-logging/src/test/scala/ManagedLoggerSpec.scala create mode 100644 project/contraband.sbt diff --git a/build.sbt b/build.sbt index bc11d37f1..74535786f 100644 --- a/build.sbt +++ b/build.sbt @@ -2,7 +2,7 @@ import Dependencies._ import Util._ import com.typesafe.tools.mima.core._, ProblemFilters._ -def baseVersion: String = "0.1.0-M16" +def baseVersion: String = "1.0.0-M18" def internalPath = file("internal") def commonSettings: Seq[Setting[_]] = Seq( @@ -98,12 +98,14 @@ lazy val utilComplete = (project in internalPath / "util-complete"). // logging lazy val utilLogging = (project in internalPath / "util-logging"). + enablePlugins(ContrabandPlugin, JsonCodecPlugin). dependsOn(utilInterface, utilTesting % Test). settings( commonSettings, crossScalaVersions := Seq(scala210, scala211, scala212), name := "Util Logging", - libraryDependencies += jline + libraryDependencies ++= Seq(jline, log4jApi, log4jCore, disruptor, sjsonnewScalaJson), + sourceManaged in (Compile, generateContrabands) := baseDirectory.value / "src" / "main" / "contraband-scala" ) // Relation @@ -150,7 +152,8 @@ lazy val utilTesting = (project in internalPath / "util-testing"). crossScalaVersions := Seq(scala210, scala211, scala212), name := "Util Testing", libraryDependencies ++= Seq(scalaCheck, scalatest) - ) + ). + configure(addSbtIO) lazy val utilScripted = (project in internalPath / "util-scripted"). dependsOn(utilLogging). diff --git a/internal/util-logging/src/main/contraband-scala/sbt/internal/util/AbstractEntry.scala b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/AbstractEntry.scala new file mode 100644 index 000000000..1c08e3cad --- /dev/null +++ b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/AbstractEntry.scala @@ -0,0 +1,27 @@ +/** + * This code is generated using sbt-datatype. + */ + +// DO NOT EDIT MANUALLY +package sbt.internal.util +abstract class AbstractEntry( + val channelName: Option[String], + val execId: Option[String]) extends Serializable { + + + + + override def equals(o: Any): Boolean = o match { + case x: AbstractEntry => (this.channelName == x.channelName) && (this.execId == x.execId) + case _ => false + } + override def hashCode: Int = { + 37 * (37 * (17 + channelName.##) + execId.##) + } + override def toString: String = { + "AbstractEntry(" + channelName + ", " + execId + ")" + } +} +object AbstractEntry { + +} diff --git a/internal/util-logging/src/main/contraband-scala/sbt/internal/util/ChannelLogEntry.scala b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/ChannelLogEntry.scala new file mode 100644 index 000000000..b7350efee --- /dev/null +++ b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/ChannelLogEntry.scala @@ -0,0 +1,51 @@ +/** + * This code is generated using sbt-datatype. + */ + +// DO NOT EDIT MANUALLY +package sbt.internal.util +final class ChannelLogEntry private ( + val level: String, + val message: String, + channelName: Option[String], + execId: Option[String]) extends sbt.internal.util.AbstractEntry(channelName, execId) with Serializable { + + + + override def equals(o: Any): Boolean = o match { + case x: ChannelLogEntry => (this.level == x.level) && (this.message == x.message) && (this.channelName == x.channelName) && (this.execId == x.execId) + case _ => false + } + override def hashCode: Int = { + 37 * (37 * (37 * (37 * (17 + level.##) + message.##) + channelName.##) + execId.##) + } + override def toString: String = { + "ChannelLogEntry(" + level + ", " + message + ", " + channelName + ", " + execId + ")" + } + protected[this] def copy(level: String = level, message: String = message, channelName: Option[String] = channelName, execId: Option[String] = execId): ChannelLogEntry = { + new ChannelLogEntry(level, message, channelName, execId) + } + def withLevel(level: String): ChannelLogEntry = { + copy(level = level) + } + def withMessage(message: String): ChannelLogEntry = { + copy(message = message) + } + def withChannelName(channelName: Option[String]): ChannelLogEntry = { + copy(channelName = channelName) + } + def withChannelName(channelName: String): ChannelLogEntry = { + copy(channelName = Option(channelName)) + } + def withExecId(execId: Option[String]): ChannelLogEntry = { + copy(execId = execId) + } + def withExecId(execId: String): ChannelLogEntry = { + copy(execId = Option(execId)) + } +} +object ChannelLogEntry { + + def apply(level: String, message: String, channelName: Option[String], execId: Option[String]): ChannelLogEntry = new ChannelLogEntry(level, message, channelName, execId) + def apply(level: String, message: String, channelName: String, execId: String): ChannelLogEntry = new ChannelLogEntry(level, message, Option(channelName), Option(execId)) +} diff --git a/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/AbstractEntryFormats.scala b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/AbstractEntryFormats.scala new file mode 100644 index 000000000..b797af060 --- /dev/null +++ b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/AbstractEntryFormats.scala @@ -0,0 +1,10 @@ +/** + * This code is generated using sbt-datatype. + */ + +// DO NOT EDIT MANUALLY +package sbt.internal.util.codec +import _root_.sjsonnew.{ deserializationError, serializationError, Builder, JsonFormat, Unbuilder } +trait AbstractEntryFormats { self: sjsonnew.BasicJsonProtocol with sbt.internal.util.codec.ChannelLogEntryFormats => +implicit lazy val AbstractEntryFormat: JsonFormat[sbt.internal.util.AbstractEntry] = flatUnionFormat1[sbt.internal.util.AbstractEntry, sbt.internal.util.ChannelLogEntry]("type") +} diff --git a/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/ChannelLogEntryFormats.scala b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/ChannelLogEntryFormats.scala new file mode 100644 index 000000000..4c8d666d9 --- /dev/null +++ b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/ChannelLogEntryFormats.scala @@ -0,0 +1,33 @@ +/** + * This code is generated using sbt-datatype. + */ + +// DO NOT EDIT MANUALLY +package sbt.internal.util.codec +import _root_.sjsonnew.{ deserializationError, serializationError, Builder, JsonFormat, Unbuilder } +trait ChannelLogEntryFormats { self: sjsonnew.BasicJsonProtocol => +implicit lazy val ChannelLogEntryFormat: JsonFormat[sbt.internal.util.ChannelLogEntry] = new JsonFormat[sbt.internal.util.ChannelLogEntry] { + override def read[J](jsOpt: Option[J], unbuilder: Unbuilder[J]): sbt.internal.util.ChannelLogEntry = { + jsOpt match { + case Some(js) => + unbuilder.beginObject(js) + val level = unbuilder.readField[String]("level") + val message = unbuilder.readField[String]("message") + val channelName = unbuilder.readField[Option[String]]("channelName") + val execId = unbuilder.readField[Option[String]]("execId") + unbuilder.endObject() + sbt.internal.util.ChannelLogEntry(level, message, channelName, execId) + case None => + deserializationError("Expected JsObject but found None") + } + } + override def write[J](obj: sbt.internal.util.ChannelLogEntry, builder: Builder[J]): Unit = { + builder.beginObject() + builder.addField("level", obj.level) + builder.addField("message", obj.message) + builder.addField("channelName", obj.channelName) + builder.addField("execId", obj.execId) + builder.endObject() + } +} +} diff --git a/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/JsonProtocol.scala b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/JsonProtocol.scala new file mode 100644 index 000000000..a2bfe0f25 --- /dev/null +++ b/internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/JsonProtocol.scala @@ -0,0 +1,10 @@ +/** + * This code is generated using sbt-datatype. + */ + +// DO NOT EDIT MANUALLY +package sbt.internal.util.codec +trait JsonProtocol extends sjsonnew.BasicJsonProtocol + with sbt.internal.util.codec.ChannelLogEntryFormats + with sbt.internal.util.codec.AbstractEntryFormats +object JsonProtocol extends JsonProtocol \ No newline at end of file diff --git a/internal/util-logging/src/main/contraband/logging.contra b/internal/util-logging/src/main/contraband/logging.contra new file mode 100644 index 000000000..085044ed8 --- /dev/null +++ b/internal/util-logging/src/main/contraband/logging.contra @@ -0,0 +1,16 @@ +package sbt.internal.util +@target(Scala) +@codecPackage("sbt.internal.util.codec") +@fullCodec("JsonProtocol") + +interface AbstractEntry { + channelName: String + execId: String +} + +type ChannelLogEntry implements sbt.internal.util.AbstractEntry { + level: String! + message: String! + channelName: String + execId: String +} diff --git a/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleLogger.scala b/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala similarity index 55% rename from internal/util-logging/src/main/scala/sbt/internal/util/ConsoleLogger.scala rename to internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala index 9e562a770..e39acb1dc 100644 --- a/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleLogger.scala +++ b/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala @@ -1,13 +1,69 @@ -/* sbt -- Simple Build Tool - * Copyright 2008, 2009, 2010, 2011 Mark Harrah - */ package sbt.internal.util import sbt.util._ import java.io.{ PrintStream, PrintWriter } import java.util.Locale +import java.util.concurrent.atomic.AtomicInteger +import org.apache.logging.log4j.{ Level => XLevel } +import org.apache.logging.log4j.message.{ Message, ParameterizedMessage, ObjectMessage } +import org.apache.logging.log4j.core.{ LogEvent => XLogEvent } +import org.apache.logging.log4j.core.appender.AbstractAppender +import org.apache.logging.log4j.core.layout.PatternLayout +import org.apache.logging.log4j.core.async.RingBufferLogEvent + +import ConsoleAppender._ object ConsoleLogger { + // These are provided so other modules do not break immediately. + @deprecated("Use ConsoleAppender.", "0.13.x") + final val ESC = ConsoleAppender.ESC + @deprecated("Use ConsoleAppender.", "0.13.x") + private[sbt] def isEscapeTerminator(c: Char): Boolean = ConsoleAppender.isEscapeTerminator(c) + @deprecated("Use ConsoleAppender.", "0.13.x") + def hasEscapeSequence(s: String): Boolean = ConsoleAppender.hasEscapeSequence(s) + @deprecated("Use ConsoleAppender.", "0.13.x") + def removeEscapeSequences(s: String): String = ConsoleAppender.removeEscapeSequences(s) + @deprecated("Use ConsoleAppender.", "0.13.x") + val formatEnabled = ConsoleAppender.formatEnabled + @deprecated("Use ConsoleAppender.", "0.13.x") + val noSuppressedMessage = ConsoleAppender.noSuppressedMessage + + def apply(out: PrintStream): ConsoleLogger = apply(ConsoleOut.printStreamOut(out)) + def apply(out: PrintWriter): ConsoleLogger = apply(ConsoleOut.printWriterOut(out)) + def apply(out: ConsoleOut = ConsoleOut.systemOut, ansiCodesSupported: Boolean = ConsoleAppender.formatEnabled, + useColor: Boolean = ConsoleAppender.formatEnabled, suppressedMessage: SuppressedTraceContext => Option[String] = ConsoleAppender.noSuppressedMessage): ConsoleLogger = + new ConsoleLogger(out, ansiCodesSupported, useColor, suppressedMessage) +} + +/** + * A logger that logs to the console. On supported systems, the level labels are + * colored. + */ +class ConsoleLogger private[ConsoleLogger] (val out: ConsoleOut, override val ansiCodesSupported: Boolean, val useColor: Boolean, val suppressedMessage: SuppressedTraceContext => Option[String]) extends BasicLogger { + private[sbt] val appender = ConsoleAppender(generateName, out, ansiCodesSupported, useColor, suppressedMessage) + + override def control(event: ControlEvent.Value, message: => String): Unit = + appender.control(event, message) + override def log(level: Level.Value, message: => String): Unit = + { + if (atLevel(level)) { + appender.appendLog(level, message) + } + } + + override def success(message: => String): Unit = + { + if (successEnabled) { + appender.success(message) + } + } + override def trace(t: => Throwable): Unit = + appender.trace(t, getTrace) + + override def logAll(events: Seq[LogEvent]) = out.lockObject.synchronized { events.foreach(log) } +} + +object ConsoleAppender { /** Escape character, used to introduce an escape sequence. */ final val ESC = '\u001B' @@ -122,25 +178,83 @@ object ConsoleLogger { private[this] def os = System.getProperty("os.name") private[this] def isWindows = os.toLowerCase(Locale.ENGLISH).indexOf("windows") >= 0 - def apply(out: PrintStream): ConsoleLogger = apply(ConsoleOut.printStreamOut(out)) - def apply(out: PrintWriter): ConsoleLogger = apply(ConsoleOut.printWriterOut(out)) - def apply(out: ConsoleOut = ConsoleOut.systemOut, ansiCodesSupported: Boolean = formatEnabled, - useColor: Boolean = formatEnabled, suppressedMessage: SuppressedTraceContext => Option[String] = noSuppressedMessage): ConsoleLogger = - new ConsoleLogger(out, ansiCodesSupported, useColor, suppressedMessage) + def apply(out: PrintStream): ConsoleAppender = apply(generateName, ConsoleOut.printStreamOut(out)) + def apply(out: PrintWriter): ConsoleAppender = apply(generateName, ConsoleOut.printWriterOut(out)) + def apply(name: String = generateName, out: ConsoleOut = ConsoleOut.systemOut, ansiCodesSupported: Boolean = formatEnabled, + useColor: Boolean = formatEnabled, suppressedMessage: SuppressedTraceContext => Option[String] = noSuppressedMessage): ConsoleAppender = + { + val appender = new ConsoleAppender(name, out, ansiCodesSupported, useColor, suppressedMessage) + appender.start + appender + } + def generateName: String = + "out-" + generateId.incrementAndGet + private val generateId: AtomicInteger = new AtomicInteger private[this] val EscapeSequence = (27.toChar + "[^@-~]*[@-~]").r def stripEscapeSequences(s: String): String = EscapeSequence.pattern.matcher(s).replaceAll("") + + def toLevel(level: XLevel): Level.Value = + level match { + case XLevel.OFF => Level.Debug + case XLevel.FATAL => Level.Error + case XLevel.ERROR => Level.Error + case XLevel.WARN => Level.Warn + case XLevel.INFO => Level.Info + case XLevel.DEBUG => Level.Debug + case _ => Level.Debug + } + def toXLevel(level: Level.Value): XLevel = + level match { + case Level.Error => XLevel.ERROR + case Level.Warn => XLevel.WARN + case Level.Info => XLevel.INFO + case Level.Debug => XLevel.DEBUG + } } +// See http://stackoverflow.com/questions/24205093/how-to-create-a-custom-appender-in-log4j2 +// for custom appender using Java. +// http://logging.apache.org/log4j/2.x/manual/customconfig.html +// https://logging.apache.org/log4j/2.x/log4j-core/apidocs/index.html + /** * A logger that logs to the console. On supported systems, the level labels are * colored. * * This logger is not thread-safe. */ -class ConsoleLogger private[ConsoleLogger] (val out: ConsoleOut, override val ansiCodesSupported: Boolean, val useColor: Boolean, val suppressedMessage: SuppressedTraceContext => Option[String]) extends BasicLogger { +class ConsoleAppender private[ConsoleAppender] ( + val name: String, + val out: ConsoleOut, + val ansiCodesSupported: Boolean, + val useColor: Boolean, + val suppressedMessage: SuppressedTraceContext => Option[String] +) extends AbstractAppender(name, null, PatternLayout.createDefaultLayout(), true) { import scala.Console.{ BLUE, GREEN, RED, RESET, YELLOW } + + def append(event: XLogEvent): Unit = + { + val level = ConsoleAppender.toLevel(event.getLevel) + val message = event.getMessage + val str = messageToString(message) + appendLog(level, str) + } + + def messageToString(msg: Message): String = + msg match { + case p: ParameterizedMessage => p.getFormattedMessage + case r: RingBufferLogEvent => r.getFormattedMessage + case o: ObjectMessage => objectToString(o.getParameter) + case _ => msg.toString + } + def objectToString(o: AnyRef): String = + o match { + case x: ChannelLogEntry => x.message + case _ => o.toString + } + def messageColor(level: Level.Value) = RESET def labelColor(level: Level.Value) = level match { @@ -148,24 +262,29 @@ class ConsoleLogger private[ConsoleLogger] (val out: ConsoleOut, override val an case Level.Warn => YELLOW case _ => RESET } - def successLabelColor = GREEN - def successMessageColor = RESET - override def success(message: => String): Unit = { - if (successEnabled) - log(successLabelColor, Level.SuccessLabel, successMessageColor, message) + + // success is called by ConsoleLogger. + // This should turn into an event. + private[sbt] def success(message: => String): Unit = { + appendLog(successLabelColor, Level.SuccessLabel, successMessageColor, message) } - def trace(t: => Throwable): Unit = + private[sbt] def successLabelColor = GREEN + private[sbt] def successMessageColor = RESET + + def trace(t: => Throwable, traceLevel: Int): Unit = out.lockObject.synchronized { - val traceLevel = getTrace if (traceLevel >= 0) out.print(StackTrace.trimmed(t, traceLevel)) if (traceLevel <= 2) for (msg <- suppressedMessage(new SuppressedTraceContext(traceLevel, ansiCodesSupported && useColor))) printLabeledLine(labelColor(Level.Error), "trace", messageColor(Level.Error), msg) } - def log(level: Level.Value, message: => String): Unit = { - if (atLevel(level)) - log(labelColor(level), level.toString, messageColor(level), message) + + def control(event: ControlEvent.Value, message: => String): Unit = + appendLog(labelColor(Level.Info), Level.Info.toString, BLUE, message) + + def appendLog(level: Level.Value, message: => String): Unit = { + appendLog(labelColor(level), level.toString, messageColor(level), message) } private def reset(): Unit = setColor(RESET) @@ -173,7 +292,7 @@ class ConsoleLogger private[ConsoleLogger] (val out: ConsoleOut, override val an if (ansiCodesSupported && useColor) out.lockObject.synchronized { out.print(color) } } - private def log(labelColor: String, label: String, messageColor: String, message: String): Unit = + private def appendLog(labelColor: String, label: String, messageColor: String, message: String): Unit = out.lockObject.synchronized { for (line <- message.split("""\n""")) printLabeledLine(labelColor, label, messageColor, line) @@ -189,10 +308,9 @@ class ConsoleLogger private[ConsoleLogger] (val out: ConsoleOut, override val an setColor(messageColor) out.print(line) reset() + out.print(s" ($name)") out.println() } - - def logAll(events: Seq[LogEvent]) = out.lockObject.synchronized { events.foreach(log) } - def control(event: ControlEvent.Value, message: => String): Unit = log(labelColor(Level.Info), Level.Info.toString, BLUE, message) } + final class SuppressedTraceContext(val traceLevel: Int, val useColor: Boolean) diff --git a/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleOut.scala b/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleOut.scala index 30da238da..72fa01594 100644 --- a/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleOut.scala +++ b/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleOut.scala @@ -33,7 +33,7 @@ object ConsoleOut { def println(s: String): Unit = synchronized { current.append(s); println() } def println(): Unit = synchronized { val s = current.toString - if (ConsoleLogger.formatEnabled && last.exists(lmsg => f(s, lmsg))) + if (ConsoleAppender.formatEnabled && last.exists(lmsg => f(s, lmsg))) lockObject.print(OverwriteLine) lockObject.println(s) last = Some(s) diff --git a/internal/util-logging/src/main/scala/sbt/internal/util/GlobalLogging.scala b/internal/util-logging/src/main/scala/sbt/internal/util/GlobalLogging.scala index 191408393..1dcf9d9f9 100644 --- a/internal/util-logging/src/main/scala/sbt/internal/util/GlobalLogging.scala +++ b/internal/util-logging/src/main/scala/sbt/internal/util/GlobalLogging.scala @@ -5,6 +5,7 @@ package sbt.internal.util import sbt.util._ import java.io.{ File, PrintWriter } +import org.apache.logging.log4j.core.Appender /** * Provides the current global logging configuration. @@ -15,7 +16,10 @@ import java.io.{ File, PrintWriter } * `backing` tracks the files that persist the global logging. * `newLogger` creates a new global logging configuration from a sink and backing configuration. */ -final case class GlobalLogging(full: Logger, console: ConsoleOut, backed: AbstractLogger, backing: GlobalLogBacking, newLogger: (PrintWriter, GlobalLogBacking) => GlobalLogging) +final case class GlobalLogging(full: ManagedLogger, console: ConsoleOut, backed: Appender, + backing: GlobalLogBacking, newAppender: (ManagedLogger, PrintWriter, GlobalLogBacking) => GlobalLogging) + +final case class GlobalLogging1(full: Logger, console: ConsoleOut, backed: AbstractLogger, backing: GlobalLogBacking, newLogger: (PrintWriter, GlobalLogBacking) => GlobalLogging1) /** * Tracks the files that persist the global logging. @@ -38,10 +42,28 @@ final case class GlobalLogBacking(file: File, last: Option[File], newBackingFile object GlobalLogBacking { def apply(newBackingFile: => File): GlobalLogBacking = GlobalLogBacking(newBackingFile, None, newBackingFile _) } + object GlobalLogging { - def initial(newLogger: (PrintWriter, GlobalLogBacking) => GlobalLogging, newBackingFile: => File, console: ConsoleOut): GlobalLogging = + import java.util.concurrent.atomic.AtomicInteger + private def generateName: String = + "GlobalLogging" + generateId.incrementAndGet + private val generateId: AtomicInteger = new AtomicInteger + + def initial1(newLogger: (PrintWriter, GlobalLogBacking) => GlobalLogging1, newBackingFile: => File, console: ConsoleOut): GlobalLogging1 = { val log = ConsoleLogger(console) - GlobalLogging(log, console, log, GlobalLogBacking(newBackingFile), newLogger) + GlobalLogging1(log, console, log, GlobalLogBacking(newBackingFile), newLogger) } -} \ No newline at end of file + + def initial(newAppender: (ManagedLogger, PrintWriter, GlobalLogBacking) => GlobalLogging, newBackingFile: => File, console: ConsoleOut): GlobalLogging = + { + val loggerName = generateName + val log = LogExchange.logger(loggerName) + val appender = ConsoleAppender(ConsoleAppender.generateName, console) + LogExchange.bindLoggerAppenders( + loggerName, List(appender -> Level.Info) + ) + GlobalLogging(log, console, appender, GlobalLogBacking(newBackingFile), newAppender) + } +} + diff --git a/internal/util-logging/src/main/scala/sbt/internal/util/MainLogging.scala b/internal/util-logging/src/main/scala/sbt/internal/util/MainLogging.scala index 6cea97edb..75eb08298 100644 --- a/internal/util-logging/src/main/scala/sbt/internal/util/MainLogging.scala +++ b/internal/util-logging/src/main/scala/sbt/internal/util/MainLogging.scala @@ -2,42 +2,65 @@ package sbt.internal.util import sbt.util._ import java.io.PrintWriter +import org.apache.logging.log4j.core.Appender -object MainLogging { - def multiLogger(config: MultiLoggerConfig): Logger = +object MainAppender { + import java.util.concurrent.atomic.AtomicInteger + private def generateGlobalBackingName: String = + "GlobalBacking" + generateId.incrementAndGet + private val generateId: AtomicInteger = new AtomicInteger + + def multiLogger(log: ManagedLogger, config: MainAppenderConfig): ManagedLogger = { import config._ - val multi = new MultiLogger(console :: backed :: extra) - // sets multi to the most verbose for clients that inspect the current level - multi setLevel Level.unionAll(backingLevel :: screenLevel :: extra.map(_.getLevel)) - // set the specific levels - console setLevel screenLevel - backed setLevel backingLevel - console setTrace screenTrace - backed setTrace backingTrace - multi: Logger + // TODO + // console setTrace screenTrace + // backed setTrace backingTrace + // multi: Logger + + // val log = LogExchange.logger(loggerName) + LogExchange.unbindLoggerAppenders(log.name) + LogExchange.bindLoggerAppenders( + log.name, + (consoleOpt.toList map { _ -> screenLevel }) ::: + List(backed -> backingLevel) ::: + (extra map { x => (x -> Level.Info) }) + ) + log } - def globalDefault(console: ConsoleOut): (PrintWriter, GlobalLogBacking) => GlobalLogging = + def globalDefault(console: ConsoleOut): (ManagedLogger, PrintWriter, GlobalLogBacking) => GlobalLogging = { - lazy val f: (PrintWriter, GlobalLogBacking) => GlobalLogging = (writer, backing) => { - val backed = defaultBacked()(writer) - val full = multiLogger(defaultMultiConfig(console, backed)) - GlobalLogging(full, console, backed, backing, f) + lazy val newAppender: (ManagedLogger, PrintWriter, GlobalLogBacking) => GlobalLogging = (log, writer, backing) => { + val backed: Appender = defaultBacked(generateGlobalBackingName)(writer) + val full = multiLogger(log, defaultMultiConfig(Option(console), backed, Nil)) + GlobalLogging(full, console, backed, backing, newAppender) } - f + newAppender } - def defaultMultiConfig(console: ConsoleOut, backing: AbstractLogger): MultiLoggerConfig = - new MultiLoggerConfig(defaultScreen(console, ConsoleLogger.noSuppressedMessage), backing, Nil, Level.Info, Level.Debug, -1, Int.MaxValue) + def defaultMultiConfig(consoleOpt: Option[ConsoleOut], backing: Appender, extra: List[Appender]): MainAppenderConfig = + MainAppenderConfig(consoleOpt map { defaultScreen(_, ConsoleAppender.noSuppressedMessage) }, backing, extra, + Level.Info, Level.Debug, -1, Int.MaxValue) + def defaultScreen(console: ConsoleOut): Appender = ConsoleAppender(ConsoleAppender.generateName, console) + def defaultScreen(console: ConsoleOut, suppressedMessage: SuppressedTraceContext => Option[String]): Appender = + ConsoleAppender(ConsoleAppender.generateName, console, suppressedMessage = suppressedMessage) + def defaultScreen(name: String, console: ConsoleOut, suppressedMessage: SuppressedTraceContext => Option[String]): Appender = + ConsoleAppender(name, console, suppressedMessage = suppressedMessage) - def defaultScreen(console: ConsoleOut): AbstractLogger = ConsoleLogger(console) - def defaultScreen(console: ConsoleOut, suppressedMessage: SuppressedTraceContext => Option[String]): AbstractLogger = - ConsoleLogger(console, suppressedMessage = suppressedMessage) + def defaultBacked( + loggerName: String = generateGlobalBackingName, + useColor: Boolean = ConsoleAppender.formatEnabled + ): PrintWriter => Appender = + to => { + ConsoleAppender( + ConsoleAppender.generateName, + ConsoleOut.printWriterOut(to), useColor = useColor + ) + } - def defaultBacked(useColor: Boolean = ConsoleLogger.formatEnabled): PrintWriter => ConsoleLogger = - to => ConsoleLogger(ConsoleOut.printWriterOut(to), useColor = useColor) + final case class MainAppenderConfig( + consoleOpt: Option[Appender], backed: Appender, extra: List[Appender], + screenLevel: Level.Value, backingLevel: Level.Value, screenTrace: Int, backingTrace: Int + ) } - -final case class MultiLoggerConfig(console: AbstractLogger, backed: AbstractLogger, extra: List[AbstractLogger], - screenLevel: Level.Value, backingLevel: Level.Value, screenTrace: Int, backingTrace: Int) diff --git a/internal/util-logging/src/main/scala/sbt/internal/util/ManagedLogger.scala b/internal/util-logging/src/main/scala/sbt/internal/util/ManagedLogger.scala new file mode 100644 index 000000000..90c84b6aa --- /dev/null +++ b/internal/util-logging/src/main/scala/sbt/internal/util/ManagedLogger.scala @@ -0,0 +1,25 @@ +package sbt.internal.util + +import sbt.util._ +import org.apache.logging.log4j.{ Logger => XLogger } +import org.apache.logging.log4j.message.ObjectMessage + +/** + * Delegates log events to the associated LogExchange. + */ +class ManagedLogger( + val name: String, + val channelName: Option[String], + val execId: Option[String], + xlogger: XLogger +) extends Logger { + override def trace(t: => Throwable): Unit = () // exchange.appendLog(new Trace(t)) + override def log(level: Level.Value, message: => String): Unit = + { + xlogger.log( + ConsoleAppender.toXLevel(level), + new ObjectMessage(ChannelLogEntry(level.toString, message, channelName, execId)) + ) + } + override def success(message: => String): Unit = xlogger.info(message) +} diff --git a/internal/util-logging/src/main/scala/sbt/internal/util/MultiLogger.scala b/internal/util-logging/src/main/scala/sbt/internal/util/MultiLogger.scala index 84168fd27..c5f7d1103 100644 --- a/internal/util-logging/src/main/scala/sbt/internal/util/MultiLogger.scala +++ b/internal/util-logging/src/main/scala/sbt/internal/util/MultiLogger.scala @@ -41,7 +41,7 @@ class MultiLogger(delegates: List[AbstractLogger]) extends BasicLogger { private[this] def removeEscapes(event: LogEvent): LogEvent = { - import ConsoleLogger.{ removeEscapeSequences => rm } + import ConsoleAppender.{ removeEscapeSequences => rm } event match { case s: Success => new Success(rm(s.msg)) case l: Log => new Log(l.level, rm(l.msg)) diff --git a/internal/util-logging/src/main/scala/sbt/util/LogExchange.scala b/internal/util-logging/src/main/scala/sbt/util/LogExchange.scala new file mode 100644 index 000000000..0f967da61 --- /dev/null +++ b/internal/util-logging/src/main/scala/sbt/util/LogExchange.scala @@ -0,0 +1,75 @@ +package sbt.util + +import sbt.internal.util._ +import org.apache.logging.log4j.{ LogManager => XLogManager, Level => XLevel } +import org.apache.logging.log4j.core._ +import org.apache.logging.log4j.core.appender.AsyncAppender +import org.apache.logging.log4j.core.config.{ AppenderRef, LoggerConfig } +import scala.collection.JavaConverters._ + +// http://logging.apache.org/log4j/2.x/manual/customconfig.html +// https://logging.apache.org/log4j/2.x/log4j-core/apidocs/index.html + +sealed abstract class LogExchange { + private[sbt] lazy val context: LoggerContext = init() + private[sbt] lazy val asyncStdout: AsyncAppender = buildAsyncStdout + + def logger(name: String): ManagedLogger = logger(name, None, None) + def logger(name: String, channelName: Option[String], execId: Option[String]): ManagedLogger = { + val _ = context + val ctx = XLogManager.getContext(false) match { case x: LoggerContext => x } + val config = ctx.getConfiguration + val loggerConfig = LoggerConfig.createLogger(false, XLevel.DEBUG, name, + "true", Array[AppenderRef](), null, config, null) + config.addLogger(name, loggerConfig) + ctx.updateLoggers + val logger = ctx.getLogger(name) + new ManagedLogger(name, channelName, execId, logger) + } + def unbindLoggerAppenders(loggerName: String): Unit = { + val lc = loggerConfig(loggerName) + lc.getAppenders.asScala foreach { + case (k, v) => lc.removeAppender(k) + } + } + def bindLoggerAppenders(loggerName: String, appenders: List[(Appender, Level.Value)]): Unit = { + val lc = loggerConfig(loggerName) + appenders foreach { + case (x, lv) => lc.addAppender(x, ConsoleAppender.toXLevel(lv), null) + } + } + def loggerConfig(loggerName: String): LoggerConfig = { + val ctx = XLogManager.getContext(false) match { case x: LoggerContext => x } + val config = ctx.getConfiguration + config.getLoggerConfig(loggerName) + } + private[sbt] def buildAsyncStdout: AsyncAppender = { + val ctx = XLogManager.getContext(false) match { case x: LoggerContext => x } + val config = ctx.getConfiguration + // val layout = PatternLayout.newBuilder + // .withPattern(PatternLayout.SIMPLE_CONVERSION_PATTERN) + // .build + val appender = ConsoleAppender("Stdout") + // CustomConsoleAppenderImpl.createAppender("Stdout", layout, null, null) + appender.start + config.addAppender(appender) + val asyncAppender: AsyncAppender = (AsyncAppender.newBuilder(): AsyncAppender.Builder) + .setName("AsyncStdout") + .setAppenderRefs(Array(AppenderRef.createAppenderRef("Stdout", XLevel.DEBUG, null))) + .setBlocking(false) + .setConfiguration(config) + .build + asyncAppender.start + config.addAppender(asyncAppender) + asyncAppender + } + private[sbt] def init(): LoggerContext = { + import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory + import org.apache.logging.log4j.core.config.Configurator + val builder = ConfigurationBuilderFactory.newConfigurationBuilder + builder.setConfigurationName("sbt.util.logging") + val ctx = Configurator.initialize(builder.build()) + ctx match { case x: LoggerContext => x } + } +} +object LogExchange extends LogExchange diff --git a/internal/util-logging/src/test/resources/log4j2.component.properties b/internal/util-logging/src/test/resources/log4j2.component.properties new file mode 100644 index 000000000..ee7c90784 --- /dev/null +++ b/internal/util-logging/src/test/resources/log4j2.component.properties @@ -0,0 +1 @@ +Log4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector diff --git a/internal/util-logging/src/test/scala/Escapes.scala b/internal/util-logging/src/test/scala/Escapes.scala index 9078f4d59..a226e4d3b 100644 --- a/internal/util-logging/src/test/scala/Escapes.scala +++ b/internal/util-logging/src/test/scala/Escapes.scala @@ -4,7 +4,7 @@ import org.scalacheck._ import Prop._ import Gen.{ listOf, oneOf } -import ConsoleLogger.{ ESC, hasEscapeSequence, isEscapeTerminator, removeEscapeSequences } +import ConsoleAppender.{ ESC, hasEscapeSequence, isEscapeTerminator, removeEscapeSequences } object Escapes extends Properties("Escapes") { property("genTerminator only generates terminators") = diff --git a/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala b/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala new file mode 100644 index 000000000..d063fbf2c --- /dev/null +++ b/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala @@ -0,0 +1,52 @@ +package sbt.internal.util + +import org.scalatest._ +import sbt.util._ +import java.io.{ File, PrintWriter } +import sbt.io.Using + +class ManagedLoggerSpec extends FlatSpec with Matchers { + "ManagedLogger" should "log to console" in { + val log = LogExchange.logger("foo") + LogExchange.bindLoggerAppenders("foo", List(LogExchange.asyncStdout -> Level.Info)) + log.info("test") + log.debug("test") + } + + "global logging" should "log immediately after initialization" in { + // this is passed into State normally + val global0 = initialGlobalLogging + val full = global0.full + (1 to 3).toList foreach { x => full.info(s"test$x") } + } + + // This is done in Mainloop.scala + it should "create a new backing with newAppender" in { + val global0 = initialGlobalLogging + val logBacking0 = global0.backing + val global1 = Using.fileWriter(append = true)(logBacking0.file) { writer => + val out = new PrintWriter(writer) + val g = global0.newAppender(global0.full, out, logBacking0) + val full = g.full + (1 to 3).toList foreach { x => full.info(s"newAppender $x") } + assert(logBacking0.file.exists) + g + } + val logBacking1 = global1.backing + Using.fileWriter(append = true)(logBacking1.file) { writer => + val out = new PrintWriter(writer) + val g = global1.newAppender(global1.full, out, logBacking1) + val full = g.full + (1 to 3).toList foreach { x => full.info(s"newAppender $x") } + // println(logBacking.file) + // print("Press enter to continue. ") + // System.console.readLine + assert(logBacking1.file.exists) + } + } + + val console = ConsoleOut.systemOut + def initialGlobalLogging: GlobalLogging = GlobalLogging.initial( + MainAppender.globalDefault(console), File.createTempFile("sbt", ".log"), console + ) +} diff --git a/project/Dependencies.scala b/project/Dependencies.scala index f020e4384..20e317e57 100644 --- a/project/Dependencies.scala +++ b/project/Dependencies.scala @@ -35,10 +35,15 @@ object Dependencies { val scalaCheck = "org.scalacheck" %% "scalacheck" % "1.13.4" val scalatest = "org.scalatest" %% "scalatest" % "3.0.1" - val parserCombinator211 = "org.scala-lang.modules" %% "scala-parser-combinators" % "1.0.4" val sjsonnewVersion = "0.7.0" val sjsonnew = "com.eed3si9n" %% "sjson-new-core" % sjsonnewVersion val sjsonnewScalaJson = "com.eed3si9n" %% "sjson-new-scalajson" % sjsonnewVersion + + def log4jVersion = "2.7" + val log4jApi = "org.apache.logging.log4j" % "log4j-api" % log4jVersion + val log4jCore = "org.apache.logging.log4j" % "log4j-core" % log4jVersion + val log4jSlf4jImpl = "org.apache.logging.log4j" % "log4j-slf4j-impl" % log4jVersion + val disruptor = "com.lmax" % "disruptor" % "3.3.6" } diff --git a/project/contraband.sbt b/project/contraband.sbt new file mode 100644 index 000000000..88961b8f9 --- /dev/null +++ b/project/contraband.sbt @@ -0,0 +1 @@ +addSbtPlugin("org.scala-sbt" % "sbt-contraband" % "0.3.0-M3")