diff --git a/build.sbt b/build.sbt index 11c3cf8d6..582a7ef93 100644 --- a/build.sbt +++ b/build.sbt @@ -410,6 +410,16 @@ lazy val utilLogging = (project in file("internal") / "util-logging") exclude[InheritedNewAbstractMethodProblem]( "sbt.internal.util.codec.JsonProtocol.ProgressEventFormat" ), + exclude[DirectMissingMethodProblem]("sbt.internal.util.MainAppender.*"), + exclude[IncompatibleMethTypeProblem]("sbt.internal.util.BufferedAppender.*"), + exclude[IncompatibleMethTypeProblem]("sbt.internal.util.ManagedLogger.this"), + exclude[IncompatibleMethTypeProblem]("sbt.internal.util.ManagedLogger.this"), + exclude[IncompatibleMethTypeProblem]("sbt.internal.util.MainAppender*"), + exclude[IncompatibleMethTypeProblem]("sbt.internal.util.GlobalLogging.*"), + exclude[IncompatibleSignatureProblem]("sbt.internal.util.GlobalLogging.*"), + exclude[IncompatibleSignatureProblem]("sbt.internal.util.MainAppender*"), + exclude[MissingTypesProblem]("sbt.internal.util.ConsoleAppender"), + exclude[MissingTypesProblem]("sbt.internal.util.BufferedAppender"), ), ) .configure(addSbtIO) @@ -1004,6 +1014,9 @@ lazy val mainProj = (project in file("main")) exclude[DirectMissingMethodProblem]("sbt.Classpaths.productsTask"), exclude[DirectMissingMethodProblem]("sbt.Classpaths.jarProductsTask"), exclude[DirectMissingMethodProblem]("sbt.StandardMain.cache"), + // internal logging apis, + exclude[IncompatibleSignatureProblem]("sbt.internal.LogManager*"), + exclude[MissingTypesProblem]("sbt.internal.RelayAppender"), ) ) .configure( diff --git a/internal/util-logging/src/main/scala/sbt/internal/util/BufferedLogger.scala b/internal/util-logging/src/main/scala/sbt/internal/util/BufferedLogger.scala index d4d1dc7fd..827cfa82f 100644 --- a/internal/util-logging/src/main/scala/sbt/internal/util/BufferedLogger.scala +++ b/internal/util-logging/src/main/scala/sbt/internal/util/BufferedLogger.scala @@ -9,10 +9,11 @@ package sbt.internal.util import sbt.util._ import scala.collection.mutable.ListBuffer -import org.apache.logging.log4j.core.{ LogEvent => XLogEvent, Appender } +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 java.util.concurrent.atomic.AtomicInteger +import java.util.concurrent.atomic.AtomicReference object BufferedAppender { def generateName: String = @@ -23,11 +24,8 @@ object BufferedAppender { def apply(delegate: Appender): BufferedAppender = apply(generateName, delegate) - def apply(name: String, delegate: Appender): BufferedAppender = { - val appender = new BufferedAppender(name, delegate) - appender.start - appender - } + def apply(name: String, delegate: Appender): BufferedAppender = + new BufferedAppender(name, delegate) } /** @@ -37,17 +35,52 @@ object BufferedAppender { * The logging level set at the time a message is originally logged is used, not * the level at the time 'play' is called. */ -class BufferedAppender private[BufferedAppender] (name: String, delegate: Appender) - extends AbstractAppender(name, null, PatternLayout.createDefaultLayout(), true, Array.empty) { +class BufferedAppender(override val name: String, delegate: Appender) extends Appender { + override def close(): Unit = log4j.get match { + case null => + case a => a.stop() + } + override private[sbt] def properties: ConsoleAppender.Properties = delegate.properties + override private[sbt] def suppressedMessage: SuppressedTraceContext => Option[String] = + delegate.suppressedMessage + private[this] val log4j = new AtomicReference[AbstractAppender] + override private[sbt] def toLog4J = log4j.get match { + case null => + val a = new AbstractAppender( + delegate.name + "-log4j", + null, + PatternLayout.createDefaultLayout(), + true, + Array.empty + ) { + start() + override def append(event: XLogEvent): Unit = { + if (recording) { + Util.ignoreResult(buffer.add(Left(event.toImmutable))) + } else { + delegate.toLog4J.append(event) + } + } + } + log4j.set(a) + a + case a => a + } - private[this] val buffer = new ListBuffer[XLogEvent] + private[this] val buffer = + new java.util.Vector[Either[XLogEvent, (Level.Value, Option[String], Option[ObjectEvent[_]])]] private[this] var recording = false - def append(event: XLogEvent): Unit = { - if (recording) { - buffer += event.toImmutable - } else delegate.append(event) - () + override def appendLog(level: Level.Value, message: => String): Unit = { + if (recording) Util.ignoreResult(buffer.add(Right((level, Some(message), None)))) + else delegate.appendLog(level, message) + } + override private[sbt] def appendObjectEvent[T]( + level: Level.Value, + message: => ObjectEvent[T] + ): Unit = { + if (recording) Util.ignoreResult(buffer.add(Right(((level, None, Some(message)))))) + else delegate.appendObjectEvent(level, message) } /** Enables buffering. */ @@ -80,8 +113,11 @@ class BufferedAppender private[BufferedAppender] (name: String, delegate: Append */ def play(): Unit = synchronized { - buffer.toList foreach { - delegate.append + buffer.forEach { + case Right((l, Some(m), _)) => delegate.appendLog(l, m) + case Right((l, _, Some(oe))) => delegate.appendObjectEvent(l, oe) + case Left(x) => delegate.toLog4J.append(x) + case _ => } buffer.clear() } diff --git a/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala b/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala index c6eac168a..d8230c95a 100644 --- a/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala +++ b/internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala @@ -13,11 +13,14 @@ import java.nio.channels.ClosedChannelException import java.util.concurrent.atomic.{ AtomicBoolean, AtomicInteger } import org.apache.logging.log4j.core.appender.AbstractAppender -import org.apache.logging.log4j.core.{ LogEvent => XLogEvent } +import org.apache.logging.log4j.core.{ Appender => XAppender, LogEvent => XLogEvent } import org.apache.logging.log4j.message.{ Message, ObjectMessage, ReusableObjectMessage } import org.apache.logging.log4j.{ Level => XLevel } import sbt.internal.util.ConsoleAppender._ import sbt.util._ +import org.apache.logging.log4j.core.AbstractLogEvent +import org.apache.logging.log4j.message.StringFormatterMessageFactory +import java.util.concurrent.atomic.AtomicReference object ConsoleLogger { // These are provided so other modules do not break immediately. @@ -80,7 +83,7 @@ class ConsoleLogger private[ConsoleLogger] ( suppressedMessage: SuppressedTraceContext => Option[String] ) extends BasicLogger { - private[sbt] val appender: ConsoleAppender = + private[sbt] val appender: Appender = ConsoleAppender(generateName(), out, ansiCodesSupported, useFormat, suppressedMessage) override def control(event: ControlEvent.Value, message: => String): Unit = @@ -117,12 +120,12 @@ object ConsoleAppender { private[this] val showProgressHolder: AtomicBoolean = new AtomicBoolean(false) def setShowProgress(b: Boolean): Unit = showProgressHolder.set(b) def showProgress: Boolean = showProgressHolder.get - private[ConsoleAppender] trait Properties { + private[sbt] trait Properties { def isAnsiSupported: Boolean def isColorEnabled: Boolean def out: ConsoleOut } - object Properties { + private[sbt] object Properties { def from(terminal: Terminal): Properties = new Properties { override def isAnsiSupported: Boolean = terminal.isAnsiSupported override def isColorEnabled: Boolean = terminal.isColorEnabled @@ -187,7 +190,7 @@ object ConsoleAppender { * * @return A new `ConsoleAppender` that writes to standard output. */ - def apply(): ConsoleAppender = apply(ConsoleOut.systemOut) + def apply(): Appender = apply(ConsoleOut.systemOut) /** * A new `ConsoleAppender` that appends log message to `out`. @@ -195,7 +198,7 @@ object ConsoleAppender { * @param out Where to write messages. * @return A new `ConsoleAppender`. */ - def apply(out: PrintStream): ConsoleAppender = apply(ConsoleOut.printStreamOut(out)) + def apply(out: PrintStream): Appender = apply(ConsoleOut.printStreamOut(out)) /** * A new `ConsoleAppender` that appends log messages to `out`. @@ -203,7 +206,7 @@ object ConsoleAppender { * @param out Where to write messages. * @return A new `ConsoleAppender`. */ - def apply(out: PrintWriter): ConsoleAppender = apply(ConsoleOut.printWriterOut(out)) + def apply(out: PrintWriter): Appender = apply(ConsoleOut.printWriterOut(out)) /** * A new `ConsoleAppender` that writes to `out`. @@ -211,7 +214,7 @@ object ConsoleAppender { * @param out Where to write messages. * @return A new `ConsoleAppender that writes to `out`. */ - def apply(out: ConsoleOut): ConsoleAppender = apply(generateName(), out) + def apply(out: ConsoleOut): Appender = apply(generateName(), out) /** * A new `ConsoleAppender` identified by `name`, and that writes to standard output. @@ -219,7 +222,7 @@ object ConsoleAppender { * @param name An identifier for the `ConsoleAppender`. * @return A new `ConsoleAppender` that writes to standard output. */ - def apply(name: String): ConsoleAppender = apply(name, ConsoleOut.systemOut) + def apply(name: String): Appender = apply(name, ConsoleOut.systemOut) /** * A new `ConsoleAppender` identified by `name`, and that writes to `out`. @@ -228,7 +231,7 @@ object ConsoleAppender { * @param out Where to write messages. * @return A new `ConsoleAppender` that writes to `out`. */ - def apply(name: String, out: ConsoleOut): ConsoleAppender = apply(name, out, formatEnabledInEnv) + def apply(name: String, out: ConsoleOut): Appender = apply(name, out, formatEnabledInEnv) /** * A new `ConsoleAppender` identified by `name`, and that writes to `out`. @@ -242,7 +245,7 @@ object ConsoleAppender { name: String, out: ConsoleOut, suppressedMessage: SuppressedTraceContext => Option[String] - ): ConsoleAppender = + ): Appender = apply(name, out, formatEnabledInEnv, formatEnabledInEnv, suppressedMessage) /** @@ -253,7 +256,7 @@ object ConsoleAppender { * @param useFormat `true` to enable format (color, bold, etc.), `false` to remove formatting. * @return A new `ConsoleAppender` that writes to `out`. */ - def apply(name: String, out: ConsoleOut, useFormat: Boolean): ConsoleAppender = + def apply(name: String, out: ConsoleOut, useFormat: Boolean): Appender = apply(name, out, useFormat || formatEnabledInEnv, useFormat, noSuppressedMessage) /** @@ -263,10 +266,8 @@ object ConsoleAppender { * @param terminal The terminal to which this appender corresponds * @return A new `ConsoleAppender` that writes to `out`. */ - def apply(name: String, terminal: Terminal): ConsoleAppender = { - val appender = new ConsoleAppender(name, Properties.from(terminal), noSuppressedMessage) - appender.start() - appender + def apply(name: String, terminal: Terminal): Appender = { + new ConsoleAppender(name, Properties.from(terminal), noSuppressedMessage) } /** @@ -281,10 +282,8 @@ object ConsoleAppender { name: String, terminal: Terminal, suppressedMessage: SuppressedTraceContext => Option[String] - ): ConsoleAppender = { - val appender = new ConsoleAppender(name, Properties.from(terminal), suppressedMessage) - appender.start() - appender + ): Appender = { + new ConsoleAppender(name, Properties.from(terminal), suppressedMessage) } /** @@ -303,10 +302,12 @@ object ConsoleAppender { ansiCodesSupported: Boolean, useFormat: Boolean, suppressedMessage: SuppressedTraceContext => Option[String] - ): ConsoleAppender = { - val appender = new ConsoleAppender(name, out, ansiCodesSupported, useFormat, suppressedMessage) - appender.start - appender + ): Appender = { + new ConsoleAppender( + name, + Properties.from(out, ansiCodesSupported, useFormat), + suppressedMessage + ) } /** @@ -356,18 +357,38 @@ object ConsoleAppender { * * This logger is not thread-safe. */ -class ConsoleAppender private[ConsoleAppender] ( - name: String, - properties: Properties, - suppressedMessage: SuppressedTraceContext => Option[String] -) extends AbstractAppender(name, null, LogExchange.dummyLayout, true, Array.empty) { - def this( - name: String, - out: ConsoleOut, - ansiCodesSupported: Boolean, - useFormat: Boolean, - suppressedMessage: SuppressedTraceContext => Option[String] - ) = this(name, Properties.from(out, ansiCodesSupported, useFormat), suppressedMessage) +class ConsoleAppender( + override private[sbt] val name: String, + override private[sbt] val properties: Properties, + override private[sbt] val suppressedMessage: SuppressedTraceContext => Option[String] +) extends Appender { + private[this] val log4j = new AtomicReference[XAppender](null) + override private[sbt] lazy val toLog4J = log4j.get match { + case null => + log4j.synchronized { + log4j.get match { + case null => + val l = new Log4JConsoleAppender(name, properties, suppressedMessage, { event => + val level = ConsoleAppender.toLevel(event.getLevel) + val message = event.getMessage + try appendMessage(level, message) + catch { case _: ClosedChannelException => } + }) + log4j.set(l) + l + case l => l + } + } + } + override def close(): Unit = log4j.get match { + case null => + case a => a.stop() + } +} +trait Appender extends AutoCloseable { + private[sbt] def name: String + private[sbt] def properties: Properties + private[sbt] def suppressedMessage: SuppressedTraceContext => Option[String] import scala.Console.{ BLUE, GREEN, RED, YELLOW } private[util] def out: ConsoleOut = properties.out @@ -392,12 +413,7 @@ class ConsoleAppender private[ConsoleAppender] ( */ def getTrace: Int = synchronized { traceEnabledVar } - override def append(event: XLogEvent): Unit = { - val level = ConsoleAppender.toLevel(event.getLevel) - val message = event.getMessage - try appendMessage(level, message) - catch { case _: ClosedChannelException => } - } + private[sbt] def toLog4J: XAppender /** * Logs the stack trace of `t`, possibly shortening it. @@ -497,7 +513,7 @@ class ConsoleAppender private[ConsoleAppender] ( out.println(toWrite) } - private def appendMessage(level: Level.Value, msg: Message): Unit = + private[util] def appendMessage(level: Level.Value, msg: Message): Unit = msg match { case o: ObjectMessage => appendMessageContent(level, o.getParameter) case o: ReusableObjectMessage => appendMessageContent(level, o.getParameter) @@ -550,6 +566,39 @@ class ConsoleAppender private[ConsoleAppender] ( case _ => Vector(o.toString) foreach { appendLog(level, _) } } } + private[sbt] def appendObjectEvent[T](level: Level.Value, message: => ObjectEvent[T]): Unit = + appendMessageContent(level, message) + +} +private[internal] class Log4JConsoleAppender( + override private[sbt] val name: String, + override private[sbt] val properties: Properties, + override private[sbt] val suppressedMessage: SuppressedTraceContext => Option[String], + appendEvent: XLogEvent => Unit, +) extends AbstractAppender(name, null, LogExchange.dummyLayout, true, Array.empty) + with Appender { + start() + override def close(): Unit = stop() + override private[sbt] def toLog4J: XAppender = this + override def append(event: XLogEvent): Unit = appendEvent(event) +} +private[sbt] class ConsoleAppenderFromLog4J( + override private[sbt] val name: String, + override private[sbt] val properties: Properties, + override private[sbt] val suppressedMessage: SuppressedTraceContext => Option[String], + val delegate: XAppender, +) extends Appender { + def this(name: String, delegate: XAppender) = + this(name, Properties.from(Terminal.get), _ => None, delegate) + override def close(): Unit = delegate.stop() + private[sbt] def toLog4J: XAppender = delegate + override def appendLog(level: sbt.util.Level.Value, message: => String): Unit = { + delegate.append(new AbstractLogEvent { + override def getLevel(): XLevel = ConsoleAppender.toXLevel(level) + override def getMessage(): Message = + StringFormatterMessageFactory.INSTANCE.newMessage(message.toString, Array.empty) + }) + } } final class SuppressedTraceContext(val traceLevel: Int, val useFormat: Boolean) 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 8ecef1db7..9be015da7 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 @@ -9,7 +9,6 @@ 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. @@ -25,7 +24,7 @@ final case class GlobalLogging( console: ConsoleOut, backed: Appender, backing: GlobalLogBacking, - newAppender: (ManagedLogger, PrintWriter, GlobalLogBacking) => GlobalLogging + newAppender: (ManagedLogger, PrintWriter, GlobalLogBacking, LoggerContext) => GlobalLogging ) final case class GlobalLogging1( @@ -78,14 +77,14 @@ object GlobalLogging { } def initial( - newAppender: (ManagedLogger, PrintWriter, GlobalLogBacking) => GlobalLogging, + newAppender: (ManagedLogger, PrintWriter, GlobalLogBacking, LoggerContext) => GlobalLogging, newBackingFile: => File, console: ConsoleOut ): GlobalLogging = { val loggerName = generateName - val log = LogExchange.logger(loggerName) + val log = LoggerContext.globalContext.logger(loggerName, None, None) val appender = ConsoleAppender(ConsoleAppender.generateName, console) - LogExchange.bindLoggerAppenders(loggerName, List(appender -> Level.Info)) + LoggerContext.globalContext.addAppender(loggerName, 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 b58fd97d2..d5573b6dc 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 @@ -9,7 +9,6 @@ package sbt.internal.util import sbt.util._ import java.io.PrintWriter -import org.apache.logging.log4j.core.Appender object MainAppender { import java.util.concurrent.atomic.AtomicInteger @@ -17,38 +16,36 @@ object MainAppender { "GlobalBacking" + generateId.incrementAndGet private val generateId: AtomicInteger = new AtomicInteger - def multiLogger(log: ManagedLogger, config: MainAppenderConfig): ManagedLogger = { + def multiLogger( + log: ManagedLogger, + config: MainAppenderConfig, + context: LoggerContext + ): ManagedLogger = { import config._ // TODO // backed setTrace backingTrace // multi: Logger - LogExchange.unbindLoggerAppenders(log.name) - LogExchange.bindLoggerAppenders( - log.name, - (consoleOpt.toList map { appender => - appender match { - case a: ConsoleAppender => - a.setTrace(screenTrace) - case _ => () - } - appender -> screenLevel - }) ::: - List(backed -> backingLevel) ::: - (extra map { x => - (x -> Level.Info) - }) - ) + context.clearAppenders(log.name) + consoleOpt match { + case Some(a: ConsoleAppender) => + a.setTrace(screenTrace) + context.addAppender(log.name, a -> screenLevel) + case _ => + } + context.addAppender(log.name, backed -> backingLevel) + extra.foreach(a => context.addAppender(log.name, a -> Level.Info)) log } def globalDefault( console: ConsoleOut - ): (ManagedLogger, PrintWriter, GlobalLogBacking) => GlobalLogging = { - lazy val newAppender: (ManagedLogger, PrintWriter, GlobalLogBacking) => GlobalLogging = - (log, writer, backing) => { + ): (ManagedLogger, PrintWriter, GlobalLogBacking, LoggerContext) => GlobalLogging = { + lazy val newAppender + : (ManagedLogger, PrintWriter, GlobalLogBacking, LoggerContext) => GlobalLogging = + (log, writer, backing, lc) => { val backed: Appender = defaultBacked(generateGlobalBackingName)(writer) - val full = multiLogger(log, defaultMultiConfig(Option(console), backed, Nil)) + val full = multiLogger(log, defaultMultiConfig(Option(console), backed, Nil), lc) GlobalLogging(full, console, backed, backing, newAppender) } newAppender 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 index 67aefeb52..21e2bbfa6 100644 --- a/internal/util-logging/src/main/scala/sbt/internal/util/ManagedLogger.scala +++ b/internal/util-logging/src/main/scala/sbt/internal/util/ManagedLogger.scala @@ -7,13 +7,16 @@ package sbt.internal.util -import org.apache.logging.log4j.{ Logger => XLogger } -import org.apache.logging.log4j.message.ObjectMessage import sbt.internal.util.codec.JsonProtocol._ import sbt.util._ import scala.reflect.runtime.universe.TypeTag import sjsonnew.JsonFormat +private[sbt] trait MiniLogger { + def log[T](level: Level.Value, message: ObjectEvent[T]): Unit + def log(level: Level.Value, message: => String): Unit +} + /** * Delegates log events to the associated LogExchange. */ @@ -21,19 +24,21 @@ class ManagedLogger( val name: String, val channelName: Option[String], val execId: Option[String], - xlogger: XLogger, - terminal: Option[Terminal] + xlogger: MiniLogger, + terminal: Option[Terminal], + private[sbt] val context: LoggerContext, ) extends Logger { - def this(name: String, channelName: Option[String], execId: Option[String], xlogger: XLogger) = - this(name, channelName, execId, xlogger, None) + def this( + name: String, + channelName: Option[String], + execId: Option[String], + xlogger: MiniLogger + ) = + this(name, channelName, execId, xlogger, None, LoggerContext.globalContext) override def trace(t: => Throwable): Unit = logEvent(Level.Error, TraceEvent("Error", t, channelName, execId)) - override def log(level: Level.Value, message: => String): Unit = { - xlogger.log( - ConsoleAppender.toXLevel(level), - new ObjectMessage(StringEvent(level.toString, message, channelName, execId)) - ) - } + override def log(level: Level.Value, message: => String): Unit = + xlogger.log(level, message) // send special event for success since it's not a real log level override def success(message: => String): Unit = { @@ -84,10 +89,7 @@ class ManagedLogger( val v: A = event // println("logEvent " + tag.key) val entry: ObjectEvent[A] = ObjectEvent(level, v, channelName, execId, tag.key) - xlogger.log( - ConsoleAppender.toXLevel(level), - new ObjectMessage(entry) - ) + xlogger.log(level, entry) } @deprecated("No longer used.", "1.0.0") diff --git a/internal/util-logging/src/main/scala/sbt/util/LogExchange.scala b/internal/util-logging/src/main/scala/sbt/util/LogExchange.scala index 90e6cc39f..9c5d3c34a 100644 --- a/internal/util-logging/src/main/scala/sbt/util/LogExchange.scala +++ b/internal/util-logging/src/main/scala/sbt/util/LogExchange.scala @@ -7,64 +7,71 @@ package sbt.util -import sbt.internal.util._ +import java.util.concurrent.ConcurrentHashMap 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.{ Appender => XAppender, LoggerContext => XLoggerContext } import org.apache.logging.log4j.core.config.{ AppenderRef, LoggerConfig } import org.apache.logging.log4j.core.layout.PatternLayout -import scala.collection.JavaConverters._ +import sbt.internal.util._ import scala.collection.concurrent import sjsonnew.JsonFormat +import org.apache.logging.log4j.core.appender.AsyncAppender // 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 builtInStringCodecs: Unit = initStringCodecs() - private[sbt] lazy val asyncStdout: AsyncAppender = buildAsyncStdout + private[sbt] lazy val context: XLoggerContext = init() private[sbt] val stringCodecs: concurrent.Map[String, ShowLines[_]] = concurrent.TrieMap() + private[sbt] val builtInStringCodecs: Unit = initStringCodecs() + private[util] val configs = new ConcurrentHashMap[String, LoggerConfig] + private[util] def addConfig(name: String, config: LoggerConfig): Unit = + Util.ignoreResult(configs.putIfAbsent(name, config)) + private[util] def removeConfig(name: String): Option[LoggerConfig] = Option(configs.remove(name)) + @deprecated("Use LoggerContext to create loggers", "1.4.0") def logger(name: String): ManagedLogger = logger(name, None, None) - def logger(name: String, channelName: Option[String], execId: Option[String]): ManagedLogger = { - val _ = context - val codecs = builtInStringCodecs - val ctx = XLogManager.getContext(false) match { case x: LoggerContext => x } - val config = ctx.getConfiguration - val loggerConfig = LoggerConfig.createLogger( - false, - XLevel.DEBUG, - name, - // disable the calculation of caller location as it is very expensive - // https://issues.apache.org/jira/browse/LOG4J2-153 - "false", - Array[AppenderRef](), - null, - config, - null - ) - config.addLogger(name, loggerConfig) - ctx.updateLoggers - val logger = ctx.getLogger(name) - new ManagedLogger(name, channelName, execId, logger, Some(Terminal.get)) - } + @deprecated("Use LoggerContext to create loggers", "1.4.0") + def logger(name: String, channelName: Option[String], execId: Option[String]): ManagedLogger = + LoggerContext.globalContext.logger(name, channelName, execId) + @deprecated("Use LoggerContext to unbind appenders", "1.4.0") def unbindLoggerAppenders(loggerName: String): Unit = { - val lc = loggerConfig(loggerName) - lc.getAppenders.asScala foreach { - case (k, v) => lc.removeAppender(k) + LoggerContext.globalContext.clearAppenders(loggerName) + } + @deprecated("Use LoggerContext to bind appenders", "1.4.0") + def bindLoggerAppenders( + loggerName: String, + appenders: List[(XAppender, Level.Value)] + ): Unit = { + appenders.foreach { + case (a, l) => + LoggerContext.globalContext + .addAppender(loggerName, new ConsoleAppenderFromLog4J(loggerName, a) -> l) } } - 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 } + @deprecated("unused", "1.4.0") + def loggerConfig(loggerName: String): LoggerConfig = configs.get(loggerName) + + @deprecated("unused", "1.4.0") + lazy val asyncStdout = buildAsyncStdout + @deprecated("unused", "1.4.0") + private[sbt] def buildAsyncStdout: AsyncAppender = { + val ctx = XLogManager.getContext(false) match { case x: XLoggerContext => x } val config = ctx.getConfiguration - config.getLoggerConfig(loggerName) + val appender = ConsoleAppender("Stdout").toLog4J + // CustomConsoleAppender.createAppender("Stdout", layout, null, null) + appender.start + config.addAppender(appender) + val asyncAppender: AsyncAppender = AsyncAppender + .newBuilder() + .setName("AsyncStdout") + .setAppenderRefs(Array(AppenderRef.createAppenderRef("Stdout", XLevel.DEBUG, null))) + .setBlocking(false) + .setConfiguration(config) + .build + asyncAppender.start + config.addAppender(asyncAppender) + asyncAppender } // Construct these StringTypeTags manually, because they're used at the very startup of sbt @@ -90,7 +97,7 @@ sealed abstract class LogExchange { // Since we currently do not use Layout inside ConsoleAppender, the actual pattern is not relevant. private[sbt] lazy val dummyLayout: PatternLayout = { val _ = context - val ctx = XLogManager.getContext(false) match { case x: LoggerContext => x } + val ctx = XLogManager.getContext(false) match { case x: XLoggerContext => x } val config = ctx.getConfiguration val lo = PatternLayout.newBuilder .withConfiguration(config) @@ -131,31 +138,14 @@ sealed abstract class LogExchange { val _ = getOrElseUpdateStringCodec(tag.key, ev) } - private[sbt] def buildAsyncStdout: AsyncAppender = { - val ctx = XLogManager.getContext(false) match { case x: LoggerContext => x } - val config = ctx.getConfiguration - val appender = ConsoleAppender("Stdout") - // CustomConsoleAppenderImpl.createAppender("Stdout", layout, null, null) - appender.start - config.addAppender(appender) - val asyncAppender: AsyncAppender = AsyncAppender - .newBuilder() - .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 = { + private[sbt] def init(): XLoggerContext = { 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 } + ctx match { case x: XLoggerContext => x } } + private[sbt] def init(name: String): XLoggerContext = new XLoggerContext(name) } object LogExchange extends LogExchange diff --git a/internal/util-logging/src/main/scala/sbt/util/LoggerContext.scala b/internal/util-logging/src/main/scala/sbt/util/LoggerContext.scala new file mode 100644 index 000000000..8fa789765 --- /dev/null +++ b/internal/util-logging/src/main/scala/sbt/util/LoggerContext.scala @@ -0,0 +1,189 @@ +/* + * sbt + * Copyright 2011 - 2018, Lightbend, Inc. + * Copyright 2008 - 2010, Mark Harrah + * Licensed under Apache License 2.0 (see LICENSE) + */ + +package sbt.util + +import java.util.concurrent.ConcurrentHashMap +import java.util.concurrent.atomic.AtomicBoolean +import org.apache.logging.log4j.{ Level => XLevel } +import org.apache.logging.log4j.core.{ Appender => XAppender, LoggerContext => XLoggerContext } +import org.apache.logging.log4j.core.config.{ AppenderRef, LoggerConfig } +import sbt.internal.util._ +import scala.collection.JavaConverters._ +import org.apache.logging.log4j.core.config.AbstractConfiguration +import org.apache.logging.log4j.message.ObjectMessage + +/** + * Provides a context for generating loggers during task evaluation. The logger context + * can be initialized for a single command evaluation run and all of the resources + * created (such as cached logger appenders) can be cleaned up after task evaluation. + * This trait evolved out of LogExchange when it became clear that it was very difficult + * to manage the loggers and appenders without introducing memory leaks. + */ +sealed trait LoggerContext extends AutoCloseable { + def logger(name: String, channelName: Option[String], execId: Option[String]): ManagedLogger + def clearAppenders(loggerName: String): Unit + def addAppender( + loggerName: String, + appender: (Appender, Level.Value) + ): Unit + def appenders(loggerName: String): Seq[Appender] + def remove(name: String): Unit +} +object LoggerContext { + private[this] val useLog4J = System.getProperty("sbt.log.uselog4j", "false") == "true" + private[this] lazy val global = new LoggerContext.LoggerContextImpl + private[this] lazy val globalLog4J = new LoggerContext.Log4JLoggerContext(LogExchange.context) + private[sbt] lazy val globalContext = if (useLog4J) globalLog4J else global + private[util] class Log4JLoggerContext(val xlc: XLoggerContext) extends LoggerContext { + private val config = xlc.getConfiguration match { + case a: AbstractConfiguration => a + case _ => throw new IllegalStateException("") + } + val loggers = new java.util.Vector[String] + private[this] val closed = new AtomicBoolean(false) + override def logger( + name: String, + channelName: Option[String], + execId: Option[String] + ): ManagedLogger = { + if (closed.get) { + throw new IllegalStateException("Tried to create logger for closed LoggerContext") + } + val loggerConfig = LoggerConfig.createLogger( + false, + XLevel.DEBUG, + name, + // disable the calculation of caller location as it is very expensive + // https://issues.apache.org/jira/browse/LOG4J2-153 + "false", + Array[AppenderRef](), + null, + config, + null + ) + config.addLogger(name, loggerConfig) + val logger = xlc.getLogger(name) + LogExchange.addConfig(name, loggerConfig) + loggers.add(name) + val xlogger = new MiniLogger { + def log(level: Level.Value, message: => String): Unit = + logger.log( + ConsoleAppender.toXLevel(level), + new ObjectMessage(StringEvent(level.toString, message, channelName, execId)) + ) + def log[T](level: Level.Value, message: ObjectEvent[T]): Unit = + logger.log(ConsoleAppender.toXLevel(level), new ObjectMessage(message)) + } + new ManagedLogger(name, channelName, execId, xlogger, Some(Terminal.get), this) + } + override def clearAppenders(loggerName: String): Unit = { + val lc = config.getLoggerConfig(loggerName) + lc.getAppenders.asScala foreach { + case (name, a) => + a.stop() + lc.removeAppender(name) + } + } + override def addAppender( + loggerName: String, + appender: (Appender, Level.Value) + ): Unit = { + val lc = config.getLoggerConfig(loggerName) + appender match { + case (x: XAppender, lv) => lc.addAppender(x, ConsoleAppender.toXLevel(lv), null) + case (x, lv) => lc.addAppender(x.toLog4J, ConsoleAppender.toXLevel(lv), null) + } + } + override def appenders(loggerName: String): Seq[Appender] = { + val lc = config.getLoggerConfig(loggerName) + lc.getAppenders.asScala.collect { case (name, ca: ConsoleAppender) => ca }.toVector + } + override def remove(name: String): Unit = { + val lc = config.getLoggerConfig(name) + config.removeLogger(name) + } + def close(): Unit = if (closed.compareAndSet(false, true)) { + loggers.forEach(l => remove(l)) + loggers.clear() + } + } + private[util] class LoggerContextImpl extends LoggerContext { + private class Log extends MiniLogger { + private val consoleAppenders: java.util.Vector[(Appender, Level.Value)] = + new java.util.Vector + def log(level: Level.Value, message: => String): Unit = + consoleAppenders.forEach { + case (a, l) => + if (level.compare(l) >= 0) a.appendLog(level, message) + } + def log[T](level: Level.Value, message: ObjectEvent[T]): Unit = { + consoleAppenders.forEach { + case (a, l) => + if (level.compare(l) >= 0) a.appendObjectEvent(level, message) + } + } + def addAppender(newAppender: (Appender, Level.Value)): Unit = + Util.ignoreResult(consoleAppenders.add(newAppender)) + def clearAppenders(): Unit = { + consoleAppenders.forEach { case (a, _) => a.close() } + consoleAppenders.clear() + } + def appenders: Seq[Appender] = consoleAppenders.asScala.map(_._1).toVector + } + private[this] val loggers = new ConcurrentHashMap[String, Log] + private[this] val closed = new AtomicBoolean(false) + override def logger( + name: String, + channelName: Option[String], + execId: Option[String] + ): ManagedLogger = { + if (closed.get) { + throw new IllegalStateException("Tried to create logger for closed LoggerContext") + } + val xlogger = new Log + loggers.put(name, xlogger) + new ManagedLogger(name, channelName, execId, xlogger, Some(Terminal.get), this) + } + override def clearAppenders(loggerName: String): Unit = { + loggers.get(loggerName) match { + case null => + case l => l.clearAppenders() + } + } + override def addAppender( + loggerName: String, + appender: (Appender, Level.Value) + ): Unit = { + if (closed.get) { + throw new IllegalStateException("Tried to add appender for closed LoggerContext") + } + loggers.get(loggerName) match { + case null => + case l => l.addAppender(appender) + } + } + override def appenders(loggerName: String): Seq[Appender] = { + loggers.get(loggerName) match { + case null => Nil + case l => l.appenders + } + } + override def remove(name: String): Unit = { + loggers.remove(name) match { + case null => + case l => l.clearAppenders() + } + } + def close(): Unit = { + loggers.forEach((name, l) => l.clearAppenders()) + loggers.clear() + } + } + private[sbt] def apply(useLog4J: Boolean) = + if (useLog4J) new Log4JLoggerContext(LogExchange.context) else new LoggerContextImpl +} diff --git a/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala b/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala index b5c99ca38..7586cfbce 100644 --- a/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala +++ b/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala @@ -11,25 +11,30 @@ import org.scalatest._ import sbt.util._ import java.io.{ File, PrintWriter } import sbt.io.Using +import com.github.ghik.silencer.silent class ManagedLoggerSpec extends FlatSpec with Matchers { + val context = LoggerContext(useLog4J = true) + @silent + val asyncStdout = new ConsoleAppenderFromLog4J("asyncStdout", LogExchange.asyncStdout) + def newLogger(name: String): ManagedLogger = context.logger(name, None, None) "ManagedLogger" should "log to console" in { - val log = LogExchange.logger("foo") - LogExchange.bindLoggerAppenders("foo", List(LogExchange.asyncStdout -> Level.Info)) + val log = newLogger("foo") + context.addAppender("foo", asyncStdout -> Level.Info) log.info("test") log.debug("test") } it should "support event logging" in { import sjsonnew.BasicJsonProtocol._ - val log = LogExchange.logger("foo") - LogExchange.bindLoggerAppenders("foo", List(LogExchange.asyncStdout -> Level.Info)) + val log = newLogger("foo") + context.addAppender("foo", asyncStdout -> Level.Info) log.infoEvent(1) } it should "validate performance improvement of disabling location calculation for async loggers" in { - val log = LogExchange.logger("foo") - LogExchange.bindLoggerAppenders("foo", List(LogExchange.asyncStdout -> Level.Info)) + val log = newLogger("foo") + context.addAppender("foo", asyncStdout -> Level.Info) val before = System.currentTimeMillis() 1 to 10000 foreach { _ => log.debug("test") @@ -41,15 +46,15 @@ class ManagedLoggerSpec extends FlatSpec with Matchers { it should "support logging Throwable out of the box" in { import sbt.internal.util.codec.JsonProtocol._ - val log = LogExchange.logger("foo") - LogExchange.bindLoggerAppenders("foo", List(LogExchange.asyncStdout -> Level.Info)) + val log = newLogger("foo") + context.addAppender("foo", asyncStdout -> Level.Info) log.infoEvent(SuccessEvent("yes")) } it should "allow registering Show[Int]" in { import sjsonnew.BasicJsonProtocol._ - val log = LogExchange.logger("foo") - LogExchange.bindLoggerAppenders("foo", List(LogExchange.asyncStdout -> Level.Info)) + val log = newLogger("foo") + context.addAppender("foo", asyncStdout -> Level.Info) implicit val intShow: ShowLines[Int] = ShowLines((x: Int) => Vector(s"String representation of $x")) log.registerStringCodec[Int] @@ -58,8 +63,8 @@ class ManagedLoggerSpec extends FlatSpec with Matchers { it should "allow registering Show[Array[Int]]" in { import sjsonnew.BasicJsonProtocol._ - val log = LogExchange.logger("foo") - LogExchange.bindLoggerAppenders("foo", List(LogExchange.asyncStdout -> Level.Info)) + val log = newLogger("foo") + context.addAppender("foo", asyncStdout -> Level.Info) implicit val intArrayShow: ShowLines[Array[Int]] = ShowLines((x: Array[Int]) => Vector(s"String representation of ${x.mkString}")) log.registerStringCodec[Array[Int]] @@ -68,8 +73,8 @@ class ManagedLoggerSpec extends FlatSpec with Matchers { it should "allow registering Show[Vector[Vector[Int]]]" in { import sjsonnew.BasicJsonProtocol._ - val log = LogExchange.logger("foo") - LogExchange.bindLoggerAppenders("foo", List(LogExchange.asyncStdout -> Level.Info)) + val log = newLogger("foo") + context.addAppender("foo", asyncStdout -> Level.Info) implicit val intVectorShow: ShowLines[Vector[Vector[Int]]] = ShowLines((xss: Vector[Vector[Int]]) => Vector(s"String representation of $xss")) log.registerStringCodec[Vector[Vector[Int]]] @@ -85,8 +90,8 @@ class ManagedLoggerSpec extends FlatSpec with Matchers { pool.submit(new Runnable { def run(): Unit = { val stringTypeTag = StringTypeTag.fast[List[Int]] - val log = LogExchange.logger(s"foo$i") - LogExchange.bindLoggerAppenders(s"foo$i", List(LogExchange.asyncStdout -> Level.Info)) + val log = newLogger(s"foo$i") + context.addAppender(s"foo$i", asyncStdout -> Level.Info) if (i % 100 == 0) { log.info(s"foo$i test $stringTypeTag") } @@ -113,7 +118,7 @@ class ManagedLoggerSpec extends FlatSpec with Matchers { 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 g = global0.newAppender(global0.full, out, logBacking0, context) val full = g.full (1 to 3).toList foreach (x => full.info(s"newAppender $x")) assert(logBacking0.file.exists) @@ -122,7 +127,7 @@ class ManagedLoggerSpec extends FlatSpec with Matchers { 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 g = global1.newAppender(global1.full, out, logBacking1, context) val full = g.full (1 to 3).toList foreach (x => full.info(s"newAppender $x")) // println(logBacking.file) diff --git a/internal/util-scripted/src/main/scala/sbt/internal/scripted/ScriptedTests.scala b/internal/util-scripted/src/main/scala/sbt/internal/scripted/ScriptedTests.scala index 12dc82c6f..ffdd4e685 100644 --- a/internal/util-scripted/src/main/scala/sbt/internal/scripted/ScriptedTests.scala +++ b/internal/util-scripted/src/main/scala/sbt/internal/scripted/ScriptedTests.scala @@ -10,8 +10,8 @@ package internal package scripted import java.io.File -import sbt.util.{ Logger, LogExchange, Level } -import sbt.internal.util.{ ManagedLogger, ConsoleAppender, BufferedAppender } +import sbt.util.{ Logger, LoggerContext, Level } +import sbt.internal.util.{ Appender, ManagedLogger, ConsoleAppender, BufferedAppender } import sbt.io.IO.wrapNull import sbt.io.{ DirectoryFilter, HiddenFileFilter } import sbt.io.syntax._ @@ -25,11 +25,13 @@ object ScriptedRunnerImpl { tests: Array[String], handlersProvider: HandlersProvider ): Unit = { + val context = + LoggerContext(useLog4J = System.getProperty("sbt.log.uselog4j", "false") == "true") val runner = new ScriptedTests(resourceBaseDirectory, bufferLog, handlersProvider) - val logger = newLogger + val logger = newLogger(context) val allTests = get(tests, resourceBaseDirectory, logger) flatMap { case ScriptedTest(group, name) => - runner.scriptedTest(group, name, logger) + runner.scriptedTest(group, name, logger, context) } runAll(allTests) } @@ -48,10 +50,9 @@ object ScriptedRunnerImpl { ScriptedTest(group, name) } private[sbt] val generateId: AtomicInteger = new AtomicInteger - private[sbt] def newLogger: ManagedLogger = { + private[sbt] def newLogger(context: LoggerContext): ManagedLogger = { val loggerName = "scripted-" + generateId.incrementAndGet - val x = LogExchange.logger(loggerName) - x + context.logger(loggerName, None, None) } } @@ -64,7 +65,7 @@ final class ScriptedTests( def this(resourceBaseDirectory: File, bufferLog: Boolean, handlersProvider: HandlersProvider) = this(resourceBaseDirectory, bufferLog, handlersProvider, true) private val testResources = new Resources(resourceBaseDirectory) - private val consoleAppender: ConsoleAppender = ConsoleAppender() + private val appender: Appender = ConsoleAppender() val ScriptFilename = "test" val PendingScriptFilename = "pending" @@ -72,14 +73,35 @@ final class ScriptedTests( def scriptedTest(group: String, name: String, log: xsbti.Logger): Seq[() => Option[String]] = scriptedTest(group, name, Logger.xlog2Log(log)) - def scriptedTest(group: String, name: String, log: ManagedLogger): Seq[() => Option[String]] = - scriptedTest(group, name, (_ => ()), log) + @deprecated("Use scriptedTest that takes a LoggerContext", "1.4.0") + def scriptedTest( + group: String, + name: String, + log: ManagedLogger, + ): Seq[() => Option[String]] = + scriptedTest(group, name, (_ => ()), log, LoggerContext.globalContext) + def scriptedTest( + group: String, + name: String, + log: ManagedLogger, + context: LoggerContext + ): Seq[() => Option[String]] = + scriptedTest(group, name, (_ => ()), log, context) + @deprecated("Use scriptedTest that provides LoggerContext", "1.4.0") def scriptedTest( group: String, name: String, prescripted: File => Unit, - log: ManagedLogger + log: ManagedLogger, + ): Seq[() => Option[String]] = + scriptedTest(group, name, prescripted, log, LoggerContext.globalContext) + def scriptedTest( + group: String, + name: String, + prescripted: File => Unit, + log: ManagedLogger, + context: LoggerContext, ): Seq[() => Option[String]] = { for (groupDir <- (resourceBaseDirectory * group).get; nme <- (groupDir * name).get) yield { val g = groupDir.getName @@ -94,7 +116,7 @@ final class ScriptedTests( None } else { try { - scriptedTest(str, testDirectory, prescripted, log); None + scriptedTest(str, testDirectory, prescripted, log, context); None } catch { case _: TestException | _: PendingTestSuccessException => Some(str) } @@ -108,11 +130,12 @@ final class ScriptedTests( label: String, testDirectory: File, prescripted: File => Unit, - log: ManagedLogger + log: ManagedLogger, + context: LoggerContext, ): Unit = { - val buffered = BufferedAppender(consoleAppender) - LogExchange.unbindLoggerAppenders(log.name) - LogExchange.bindLoggerAppenders(log.name, (buffered -> Level.Debug) :: Nil) + val buffered = BufferedAppender(appender) + context.clearAppenders(log.name) + context.addAppender(log.name, (buffered -> Level.Debug)) if (bufferLog) { buffered.record() } diff --git a/main/src/main/scala/sbt/Defaults.scala b/main/src/main/scala/sbt/Defaults.scala index 360564cfb..4173b0b68 100644 --- a/main/src/main/scala/sbt/Defaults.scala +++ b/main/src/main/scala/sbt/Defaults.scala @@ -17,6 +17,7 @@ import lmcoursier.CoursierDependencyResolution import lmcoursier.definitions.{ Configuration => CConfiguration } import org.apache.ivy.core.module.descriptor.ModuleDescriptor import org.apache.ivy.core.module.id.ModuleRevisionId +import org.apache.logging.log4j.core.{ Appender => XAppender } import org.scalasbt.ipcsocket.Win32SecurityLevel import sbt.Def.{ Initialize, ScopedKey, Setting, SettingsDefinition } import sbt.Keys._ @@ -359,9 +360,19 @@ object Defaults extends BuildCommon { try onUnload.value(s) finally IO.delete(taskTemporaryDirectory.value) }, - extraLoggers :== { _ => + // extraLoggers is deprecated + SettingKey[ScopedKey[_] => Seq[XAppender]]("extraLoggers") :== { _ => Nil }, + extraAppenders := { + val f = SettingKey[ScopedKey[_] => Seq[XAppender]]("extraLoggers").value + s => + f(s).map { + case a: Appender => a + case a => new ConsoleAppenderFromLog4J(a.getName, a) + } + }, + useLog4J :== SysProp.useLog4J, watchSources :== Nil, // Although this is deprecated, it can't be removed or it breaks += for legacy builds. skip :== false, taskTemporaryDirectory := { @@ -441,7 +452,7 @@ object Defaults extends BuildCommon { // TODO: This should be on the new default settings for a project. def projectCore: Seq[Setting[_]] = Seq( name := thisProject.value.id, - logManager := LogManager.defaults(extraLoggers.value, ConsoleOut.terminalOut), + logManager := LogManager.defaults(extraAppenders.value, ConsoleOut.terminalOut), onLoadMessage := (onLoadMessage or Def.setting { s"set current project to ${name.value} (in build ${thisProjectRef.value.build})" @@ -1046,13 +1057,15 @@ object Defaults extends BuildCommon { inTask(key)( Seq( testListeners := { + val stateLogLevel = state.value.get(Keys.logLevel.key).getOrElse(Level.Info) TestLogger.make( streams.value.log, closeableTestLogger( streamsManager.value, test in resolvedScoped.value.scope, logBuffered.value - ) + ), + Keys.logLevel.?.value.getOrElse(stateLogLevel), ) +: new TestStatusReporter(succeededFile(streams.in(test).value.cacheDirectory)) +: testListeners.in(TaskZero).value diff --git a/main/src/main/scala/sbt/Keys.scala b/main/src/main/scala/sbt/Keys.scala index 504b69a74..70b0127aa 100644 --- a/main/src/main/scala/sbt/Keys.scala +++ b/main/src/main/scala/sbt/Keys.scala @@ -15,7 +15,7 @@ import lmcoursier.definitions.{ CacheLogger, ModuleMatchers, Reconciliation } import lmcoursier.{ CoursierConfiguration, FallbackDependency } import org.apache.ivy.core.module.descriptor.ModuleDescriptor import org.apache.ivy.core.module.id.ModuleRevisionId -import org.apache.logging.log4j.core.Appender +import org.apache.logging.log4j.core.{ Appender => XAppender } import sbt.BuildSyntax._ import sbt.Def.ScopedKey import sbt.KeyRanks._ @@ -27,7 +27,7 @@ import sbt.internal.io.WatchState import sbt.internal.librarymanagement.{ CompatibilityWarningOptions, IvySbt } import sbt.internal.remotecache.RemoteCacheArtifact import sbt.internal.server.ServerHandler -import sbt.internal.util.{ AttributeKey, ProgressState, SourcePosition } +import sbt.internal.util.{ Appender, AttributeKey, ProgressState, SourcePosition } import sbt.io._ import sbt.librarymanagement.Configurations.CompilerPlugin import sbt.librarymanagement.LibraryManagementCodec._ @@ -35,7 +35,7 @@ import sbt.librarymanagement._ import sbt.librarymanagement.ivy.{ Credentials, IvyConfiguration, IvyPaths, UpdateOptions } import sbt.nio.file.Glob import sbt.testing.Framework -import sbt.util.{ Level, Logger } +import sbt.util.{ Level, Logger, LoggerContext } import xsbti.{ FileConverter, VirtualFile } import xsbti.compile._ import xsbti.compile.analysis.ReadStamps @@ -59,8 +59,12 @@ object Keys { val showSuccess = settingKey[Boolean]("If true, displays a success message after running a command successfully.").withRank(CSetting) val showTiming = settingKey[Boolean]("If true, the command success message includes the completion time.").withRank(CSetting) val timingFormat = settingKey[java.text.DateFormat]("The format used for displaying the completion time.").withRank(CSetting) - val extraLoggers = settingKey[ScopedKey[_] => Seq[Appender]]("A function that provides additional loggers for a given setting.").withRank(DSetting) + @deprecated("", "1.4.0") + val extraLoggers = settingKey[ScopedKey[_] => Seq[XAppender]]("A function that provides additional loggers for a given setting.").withRank(DSetting) + val extraAppenders = settingKey[ScopedKey[_] => Seq[Appender]]("A function that provides additional loggers for a given setting.").withRank(DSetting) + val useLog4J = settingKey[Boolean]("Toggles whether or not to use log4j for sbt internal loggers.").withRank(Invisible) val logManager = settingKey[LogManager]("The log manager, which creates Loggers for different contexts.").withRank(DSetting) + private[sbt] val loggerContext = AttributeKey[LoggerContext]("sbt-logger-context", "The logger config which creates Loggers for different contexts.", Int.MaxValue) val logBuffered = settingKey[Boolean]("True if logging should be buffered until work completes.").withRank(CSetting) val sLog = settingKey[Logger]("Logger usable by settings during project loading.").withRank(CSetting) val serverLog = taskKey[Unit]("A dummy task to set server log level using Global / serverLog / logLevel.").withRank(CTask) diff --git a/main/src/main/scala/sbt/Main.scala b/main/src/main/scala/sbt/Main.scala index 61777b2ec..70e291940 100644 --- a/main/src/main/scala/sbt/Main.scala +++ b/main/src/main/scala/sbt/Main.scala @@ -930,8 +930,9 @@ object BuiltinCommands { val session = Load.initialSession(structure, eval, s0) SessionSettings.checkSession(session, s2) val s3 = addCacheStoreFactoryFactory(Project.setProject(session, structure, s2)) - val s4 = setupGlobalFileTreeRepository(s3) - CheckBuildSources.init(LintUnused.lintUnusedFunc(s4)) + val s4 = s3.put(Keys.useLog4J.key, Project.extract(s3).get(Keys.useLog4J)) + val s5 = setupGlobalFileTreeRepository(s4) + CheckBuildSources.init(LintUnused.lintUnusedFunc(s5)) } private val setupGlobalFileTreeRepository: State => State = { state => diff --git a/main/src/main/scala/sbt/MainLoop.scala b/main/src/main/scala/sbt/MainLoop.scala index b1822aa31..0d2f57c2e 100644 --- a/main/src/main/scala/sbt/MainLoop.scala +++ b/main/src/main/scala/sbt/MainLoop.scala @@ -19,7 +19,7 @@ import sbt.internal.util.{ ErrorHandling, GlobalLogBacking, Terminal } import sbt.internal.{ ConsoleUnpromptEvent, ShutdownHooks } import sbt.io.{ IO, Using } import sbt.protocol._ -import sbt.util.Logger +import sbt.util.{ Logger, LoggerContext } import scala.annotation.tailrec import scala.util.control.NonFatal @@ -63,7 +63,7 @@ object MainLoop { } /** Runs the next sequence of commands, cleaning up global logging after any exceptions. */ - def runAndClearLast(state: State, logBacking: GlobalLogBacking): RunNext = + def runAndClearLast(state: State, logBacking: GlobalLogBacking): RunNext = { try runWithNewLog(state, logBacking) catch { case e: xsbti.FullReload => @@ -80,6 +80,7 @@ object MainLoop { deleteLastLog(logBacking) throw e } + } /** Deletes the previous global log file. */ def deleteLastLog(logBacking: GlobalLogBacking): Unit = @@ -108,16 +109,20 @@ object MainLoop { } /** Runs the next sequence of commands with global logging in place. */ - def runWithNewLog(state: State, logBacking: GlobalLogBacking): RunNext = + def runWithNewLog(state: State, logBacking: GlobalLogBacking): RunNext = { Using.fileWriter(append = true)(logBacking.file) { writer => val out = new PrintWriter(writer) val full = state.globalLogging.full - val newLogging = state.globalLogging.newAppender(full, out, logBacking) + val newLogging = + state.globalLogging.newAppender(full, out, logBacking, LoggerContext.globalContext) // transferLevels(state, newLogging) val loggedState = state.copy(globalLogging = newLogging) try run(loggedState) - finally out.close() + finally { + out.close() + } } + } // /** Transfers logging and trace levels from the old global loggers to the new ones. */ // private[this] def transferLevels(state: State, logging: GlobalLogging): Unit = { @@ -143,15 +148,16 @@ object MainLoop { case ret: State.Return => new Return(ret.result) } - def next(state: State): State = + def next(state: State): State = { + val context = LoggerContext(useLog4J = state.get(Keys.useLog4J.key).getOrElse(false)) try { ErrorHandling.wideConvert { - state.process(processCommand) + state.put(Keys.loggerContext, context).process(processCommand) } match { - case Right(s) => s + case Right(s) => s.remove(Keys.loggerContext) case Left(t: xsbti.FullReload) => throw t case Left(t: RebootCurrent) => throw t - case Left(t) => state.handleError(t) + case Left(t) => state.remove(Keys.loggerContext).handleError(t) } } catch { case oom: OutOfMemoryError @@ -180,7 +186,8 @@ object MainLoop { state.log.error(msg) state.log.error("\n") state.handleError(oom) - } + } finally context.close() + } /** This is the main function State transfer function of the sbt command processing. */ def processCommand(exec: Exec, state: State): State = { @@ -202,20 +209,31 @@ object MainLoop { StandardMain.exchange.setState(progressState) StandardMain.exchange.setExec(Some(exec)) StandardMain.exchange.unprompt(ConsoleUnpromptEvent(exec.source)) - val terminal = channelName.flatMap(exchange.channelForName(_).map(_.terminal)) - val prevTerminal = terminal.map(Terminal.set) + val restoreTerminal = channelName.flatMap(exchange.channelForName) match { + case Some(c) => + val prevTerminal = Terminal.set(c.terminal) + () => { + Terminal.set(prevTerminal) + c.terminal.flush() + } + case _ => () => () + } /* * FastTrackCommands.evaluate can be significantly faster than Command.process because * it avoids an expensive parsing step for internal commands that are easy to parse. * Dropping (FastTrackCommands.evaluate ... getOrElse) should be functionally identical * but slower. */ - val newState = FastTrackCommands.evaluate(progressState, exec.commandLine) getOrElse - Command.process(exec.commandLine, progressState) - // Flush the terminal output after command evaluation to ensure that all output - // is displayed in the thin client before we report the command status. - terminal.foreach(_.flush()) - prevTerminal.foreach(Terminal.set) + val newState = try { + FastTrackCommands + .evaluate(progressState, exec.commandLine) + .getOrElse(Command.process(exec.commandLine, progressState)) + } finally { + // Flush the terminal output after command evaluation to ensure that all output + // is displayed in the thin client before we report the command status. Also + // set the promt to whatever it was before we started evaluating the task. + restoreTerminal() + } if (exec.execId.fold(true)(!_.startsWith(networkExecPrefix)) && !exec.commandLine.startsWith(networkExecPrefix)) { val doneEvent = ExecStatusEvent( diff --git a/main/src/main/scala/sbt/internal/Continuous.scala b/main/src/main/scala/sbt/internal/Continuous.scala index 80cf2206b..0f13a36b4 100644 --- a/main/src/main/scala/sbt/internal/Continuous.scala +++ b/main/src/main/scala/sbt/internal/Continuous.scala @@ -258,14 +258,16 @@ private[sbt] object Continuous extends DeprecatedContinuous { commands: Seq[String], fileStampCache: FileStamp.Cache, dynamicInputs: mutable.Set[DynamicInput], + context: LoggerContext ): Callbacks = { implicit val extracted: Extracted = Project.extract(s) - implicit val logger: Logger = LogExchange.logger(channel.name + "-watch") + implicit val logger: Logger = + context.logger(channel.name + "-watch", None, None) validateCommands(s, commands) val configs = getAllConfigs(s, commands, dynamicInputs) val appender = ConsoleAppender(channel.name + "-watch", channel.terminal) val level = configs.minBy(_.watchSettings.logLevel).watchSettings.logLevel - LogExchange.bindLoggerAppenders(channel.name + "-watch", (appender -> level) :: Nil) + context.addAppender(channel.name + "-watch", appender -> level) aggregate( configs, logger, @@ -1141,8 +1143,9 @@ private[sbt] object ContinuousCommands { .channelForName(channelName) .getOrElse(throw new IllegalStateException(s"No channel with name $channelName")) val dynamicInputs = mutable.Set.empty[DynamicInput] + val context = LoggerContext(useLog4J = state.get(Keys.useLog4J.key).getOrElse(false)) def cb: Continuous.Callbacks = - Continuous.getCallbacks(state, channel, commands, cache, dynamicInputs) + Continuous.getCallbacks(state, channel, commands, cache, dynamicInputs, context) val s = new ContinuousState( count = count, @@ -1178,8 +1181,9 @@ private[sbt] object ContinuousCommands { restoredState.remove(persistentFileStampCache).remove(Continuous.DynamicInputs) }, afterWatch = state => { - LogExchange.unbindLoggerAppenders(channelName + "-watch") + context.clearAppenders(channelName + "-watch") repo.close() + context.close() state.get(watchStates) match { case None => state case Some(ws) => state.put(watchStates, ws - channelName) diff --git a/main/src/main/scala/sbt/internal/DefaultBackgroundJobService.scala b/main/src/main/scala/sbt/internal/DefaultBackgroundJobService.scala index 92cfd75f9..357e398a2 100644 --- a/main/src/main/scala/sbt/internal/DefaultBackgroundJobService.scala +++ b/main/src/main/scala/sbt/internal/DefaultBackgroundJobService.scala @@ -21,10 +21,11 @@ import sbt.internal.inc.classpath.ClasspathFilter import sbt.internal.util.{ Attributed, ManagedLogger } import sbt.io.syntax._ import sbt.io.{ Hash, IO } -import sbt.util.{ LogExchange, Logger } +import sbt.util.Logger import scala.concurrent.ExecutionContext import scala.util.Try +import sbt.util.LoggerContext /** * Interface between sbt and a thing running in the background. @@ -63,6 +64,7 @@ private[sbt] abstract class AbstractBackgroundJobService extends BackgroundJobSe private val pool = new BackgroundThreadPool() private[sbt] def serviceTempDirBase: File + private[sbt] def useLog4J: Boolean private val serviceTempDirRef = new AtomicReference[File] private def serviceTempDir: File = serviceTempDirRef.synchronized { serviceTempDirRef.get match { @@ -76,6 +78,7 @@ private[sbt] abstract class AbstractBackgroundJobService extends BackgroundJobSe // hooks for sending start/stop events protected def onAddJob(@deprecated("unused", "") job: JobHandle): Unit = () protected def onRemoveJob(@deprecated("unused", "") job: JobHandle): Unit = () + private val context = LoggerContext(useLog4J) // this mutable state could conceptually go on State except // that then every task that runs a background job would have @@ -111,7 +114,8 @@ private[sbt] abstract class AbstractBackgroundJobService extends BackgroundJobSe // logger.close() removeJob(this) IO.delete(workingDirectory) - LogExchange.unbindLoggerAppenders(logger.name) + context.clearAppenders(logger.name) + context.close() } addJob(this) override final def equals(other: Any): Boolean = other match { @@ -472,10 +476,12 @@ private[sbt] class BackgroundThreadPool extends java.io.Closeable { } } -private[sbt] class DefaultBackgroundJobService(private[sbt] val serviceTempDirBase: File) - extends AbstractBackgroundJobService { +private[sbt] class DefaultBackgroundJobService( + private[sbt] val serviceTempDirBase: File, + override private[sbt] val useLog4J: Boolean +) extends AbstractBackgroundJobService { @deprecated("Use the constructor that specifies the background job temporary directory", "1.4.0") - def this() = this(IO.createTemporaryDirectory) + def this() = this(IO.createTemporaryDirectory, false) override def makeContext(id: Long, spawningTask: ScopedKey[_], state: State): ManagedLogger = { val extracted = Project.extract(state) LogManager.constructBackgroundLog(extracted.structure.data, state)(spawningTask) @@ -491,7 +497,8 @@ private[sbt] object DefaultBackgroundJobService { private[sbt] lazy val backgroundJobServiceSetting: Setting[_] = (Keys.bgJobService in GlobalScope) := { val path = (sbt.Keys.bgJobServiceDirectory in GlobalScope).value - val newService = new DefaultBackgroundJobService(path) + val useLog4J = (Keys.useLog4J in GlobalScope).value + val newService = new DefaultBackgroundJobService(path, useLog4J) backgroundJobServices.putIfAbsent(path, newService) match { case null => newService case s => diff --git a/main/src/main/scala/sbt/internal/LogManager.scala b/main/src/main/scala/sbt/internal/LogManager.scala index a9db8d34b..99722dbf6 100644 --- a/main/src/main/scala/sbt/internal/LogManager.scala +++ b/main/src/main/scala/sbt/internal/LogManager.scala @@ -10,23 +10,38 @@ package internal import java.io.PrintWriter -import org.apache.logging.log4j.core.Appender import sbt.Def.ScopedKey import sbt.Keys._ import sbt.Scope.GlobalScope import sbt.internal.util.MainAppender._ import sbt.internal.util._ -import sbt.util.{ Level, LogExchange, Logger } +import sbt.util.{ Level, LogExchange, Logger, LoggerContext } sealed abstract class LogManager { def apply( data: Settings[Scope], state: State, task: ScopedKey[_], - writer: PrintWriter + writer: PrintWriter, + context: LoggerContext, ): ManagedLogger + @deprecated("Use alternate apply that provides a LoggerContext", "1.4.0") + def apply( + data: Settings[Scope], + state: State, + task: ScopedKey[_], + writer: PrintWriter + ): ManagedLogger = apply(data, state, task, writer, LoggerContext.globalContext) - def backgroundLog(data: Settings[Scope], state: State, task: ScopedKey[_]): ManagedLogger + def backgroundLog( + data: Settings[Scope], + state: State, + task: ScopedKey[_], + context: LoggerContext + ): ManagedLogger + @deprecated("Use alternate background log that provides a LoggerContext", "1.4.0") + final def backgroundLog(data: Settings[Scope], state: State, task: ScopedKey[_]): ManagedLogger = + backgroundLog(data, state, task, LoggerContext.globalContext) } object LogManager { @@ -34,14 +49,16 @@ object LogManager { private val generateId: AtomicInteger = new AtomicInteger // This is called by mkStreams + // def construct( data: Settings[Scope], state: State ): (ScopedKey[_], PrintWriter) => ManagedLogger = (task: ScopedKey[_], to: PrintWriter) => { + val context = state.get(Keys.loggerContext).getOrElse(LoggerContext.globalContext) val manager: LogManager = (logManager in task.scope).get(data) getOrElse defaultManager(state.globalLogging.console) - manager(data, state, task, to) + manager(data, state, task, to, context) } def constructBackgroundLog( @@ -51,7 +68,8 @@ object LogManager { (task: ScopedKey[_]) => { val manager: LogManager = (logManager in task.scope).get(data) getOrElse defaultManager(state.globalLogging.console) - manager.backgroundLog(data, state, task) + val context = state.get(Keys.loggerContext).getOrElse(LoggerContext.globalContext) + manager.backgroundLog(data, state, task, context) } def defaultManager(console: ConsoleOut): LogManager = @@ -84,7 +102,8 @@ object LogManager { data: Settings[Scope], state: State, task: ScopedKey[_], - to: PrintWriter + to: PrintWriter, + context: LoggerContext, ): ManagedLogger = defaultLogger( data, @@ -93,12 +112,18 @@ object LogManager { screen(task, state), backed(to), relay(()), - extra(task).toList + extra(task).toList, + context, ) - def backgroundLog(data: Settings[Scope], state: State, task: ScopedKey[_]): ManagedLogger = { + def backgroundLog( + data: Settings[Scope], + state: State, + task: ScopedKey[_], + context: LoggerContext + ): ManagedLogger = { val console = screen(task, state) - LogManager.backgroundLog(data, state, task, console, relay(())) + LogManager.backgroundLog(data, state, task, console, relay(()), context) } } @@ -112,7 +137,7 @@ object LogManager { ): T = data.get(scope, key) orElse state.get(key) getOrElse default - // This is the main function that is used to generate the logger for tasks. + @deprecated("Use defaultLogger that provides a LoggerContext", "1.4.0") def defaultLogger( data: Settings[Scope], state: State, @@ -121,12 +146,24 @@ object LogManager { backed: Appender, relay: Appender, extra: List[Appender] + ): ManagedLogger = + defaultLogger(data, state, task, console, backed, relay, extra, LoggerContext.globalContext) + // This is the main function that is used to generate the logger for tasks. + def defaultLogger( + data: Settings[Scope], + state: State, + task: ScopedKey[_], + console: Appender, + backed: Appender, + relay: Appender, + extra: List[Appender], + context: LoggerContext, ): ManagedLogger = { val execOpt = state.currentCommand val loggerName: String = s"${task.key.label}-${generateId.incrementAndGet}" val channelName: Option[String] = execOpt flatMap (_.source map (_.channelName)) val execId: Option[String] = execOpt flatMap { _.execId } - val log = LogExchange.logger(loggerName, channelName, execId) + val log = context.logger(loggerName, channelName, execId) val scope = task.scope val screenLevel = getOr(logLevel.key, data, scope, state, Level.Info) val backingLevel = getOr(persistLogLevel.key, data, scope, state, Level.Debug) @@ -143,7 +180,7 @@ object LogManager { screenTrace, backingTrace ) - multiLogger(log, config) + multiLogger(log, config, context) } // Return None if the exec is not from console origin. @@ -191,6 +228,7 @@ object LogManager { console: Appender, /* TODO: backed: Appender,*/ relay: Appender, + context: LoggerContext, ): ManagedLogger = { val scope = task.scope val screenLevel = getOr(logLevel.key, data, scope, state, Level.Info) @@ -200,18 +238,16 @@ object LogManager { val loggerName: String = s"bg-${task.key.label}-${generateId.incrementAndGet}" val channelName: Option[String] = execOpt flatMap (_.source map (_.channelName)) // val execId: Option[String] = execOpt flatMap { _.execId } - val log = LogExchange.logger(loggerName, channelName, None) - LogExchange.unbindLoggerAppenders(loggerName) + val log = context.logger(loggerName, channelName, None) + context.clearAppenders(loggerName) val consoleOpt = consoleLocally(state, console) map { - case a: ConsoleAppender => + case a: Appender => a.setTrace(screenTrace) a case a => a } - LogExchange.bindLoggerAppenders( - loggerName, - (consoleOpt.toList map { _ -> screenLevel }) ::: (relay -> backingLevel) :: Nil - ) + consoleOpt.foreach(a => context.addAppender(loggerName, a -> screenLevel)) + context.addAppender(loggerName, relay -> backingLevel) log } @@ -238,30 +274,23 @@ object LogManager { def setGlobalLogLevel(s: State, level: Level.Value): State = { val s1 = s.put(BasicKeys.explicitGlobalLogLevels, true).put(Keys.logLevel.key, level) val gl = s1.globalLogging - LogExchange.unbindLoggerAppenders(gl.full.name) - LogExchange.bindLoggerAppenders(gl.full.name, (gl.backed -> level) :: Nil) + LoggerContext.globalContext.clearAppenders(gl.full.name) + LoggerContext.globalContext.addAppender(gl.full.name, gl.backed -> level) s1 } @deprecated("No longer used.", "1.4.0") - private[sbt] def progressLogger(appender: Appender): ManagedLogger = { + private[sbt] def progressLogger(appender: ConsoleAppender): ManagedLogger = { val log = LogExchange.logger("progress", None, None) - LogExchange.unbindLoggerAppenders("progress") - LogExchange.bindLoggerAppenders( - "progress", - List(appender -> Level.Info) - ) + LoggerContext.globalContext.clearAppenders("progress") + LoggerContext.globalContext.addAppender("progress", appender -> Level.Info) log } // This is the default implementation for the relay appender - val defaultRelay: Unit => Appender = _ => defaultRelayImpl + val defaultRelay: Unit => ConsoleAppender = _ => defaultRelayImpl - private[this] lazy val defaultRelayImpl: RelayAppender = { - val appender = new RelayAppender("Relay0") - appender.start() - appender - } + private[this] lazy val defaultRelayImpl: ConsoleAppender = new RelayAppender("Relay0") private[sbt] def settingsLogger(state: State): Def.Setting[_] = // strict to avoid retaining a reference to `state` diff --git a/main/src/main/scala/sbt/internal/RelayAppender.scala b/main/src/main/scala/sbt/internal/RelayAppender.scala index e140754b6..ed9355b37 100644 --- a/main/src/main/scala/sbt/internal/RelayAppender.scala +++ b/main/src/main/scala/sbt/internal/RelayAppender.scala @@ -8,45 +8,18 @@ package sbt package internal -import org.apache.logging.log4j.message._ -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 org.apache.logging.log4j.core.config.Property -import sbt.util.Level import sbt.internal.util._ import sbt.protocol.LogEvent +import sbt.util.Level -class RelayAppender(name: String) - extends AbstractAppender( +class RelayAppender(override val name: String) + extends ConsoleAppender( name, - null, - PatternLayout.createDefaultLayout(), - true, - Property.EMPTY_ARRAY + ConsoleAppender.Properties.from(ConsoleOut.globalProxy, true, true), + _ => None ) { lazy val exchange = StandardMain.exchange - - def append(event: XLogEvent): Unit = { - val level = ConsoleAppender.toLevel(event.getLevel) - val message = event.getMessage - message match { - case o: ObjectMessage => appendEvent(o.getParameter) - case p: ParameterizedMessage => appendLog(level, p.getFormattedMessage) - case r: RingBufferLogEvent => appendLog(level, r.getFormattedMessage) - case _ => appendLog(level, message.toString) - } + override def appendLog(level: Level.Value, message: => String): Unit = { + exchange.logMessage(LogEvent(level = level.toString, message = message)) } - def appendLog(level: Level.Value, message: => String): Unit = { - exchange.logMessage(LogEvent(level.toString, message)) - } - def appendEvent(event: AnyRef): Unit = - event match { - case x: StringEvent => exchange.logMessage(LogEvent(level = x.level, message = x.message)) - case x: ObjectEvent[_] => // ignore object events - case _ => - println(s"appendEvent: ${event.getClass}") - () - } } diff --git a/main/src/main/scala/sbt/internal/SysProp.scala b/main/src/main/scala/sbt/internal/SysProp.scala index 15c971af4..c02038e87 100644 --- a/main/src/main/scala/sbt/internal/SysProp.scala +++ b/main/src/main/scala/sbt/internal/SysProp.scala @@ -115,6 +115,7 @@ object SysProp { def banner: Boolean = getOrTrue("sbt.banner") + def useLog4J: Boolean = getOrFalse("sbt.log.uselog4j") def turbo: Boolean = getOrFalse("sbt.turbo") def pipelining: Boolean = getOrFalse("sbt.pipelining") diff --git a/sbt/src/test/scala/sbt/RunFromSourceMain.scala b/sbt/src/test/scala/sbt/RunFromSourceMain.scala index 67d00c322..e53ae2b79 100644 --- a/sbt/src/test/scala/sbt/RunFromSourceMain.scala +++ b/sbt/src/test/scala/sbt/RunFromSourceMain.scala @@ -10,10 +10,11 @@ package sbt import java.io.File.pathSeparator import sbt.internal.scriptedtest.ScriptedLauncher -import sbt.util.LogExchange +import sbt.util.LoggerContext import scala.annotation.tailrec import scala.sys.process.Process +import sbt.internal.SysProp object RunFromSourceMain { def fork( @@ -43,8 +44,10 @@ object RunFromSourceMain { implicit val runner = new ForkRun(fo) val options = Vector(workingDirectory.toString, scalaVersion, sbtVersion, cp.mkString(pathSeparator)) - val log = LogExchange.logger("RunFromSourceMain.fork", None, None) - runner.fork("sbt.RunFromSourceMain", cp, options, log) + val context = LoggerContext(useLog4J = SysProp.useLog4J) + val log = context.logger("RunFromSourceMain.fork", None, None) + try runner.fork("sbt.RunFromSourceMain", cp, options, log) + finally context.close() } def main(args: Array[String]): Unit = args match { @@ -54,7 +57,9 @@ object RunFromSourceMain { ) case Array(wd, scalaVersion, sbtVersion, classpath, args @ _*) => System.setProperty("jna.nosys", "true") - run(file(wd), scalaVersion, sbtVersion, classpath, args) + val context = LoggerContext(useLog4J = SysProp.useLog4J) + try run(file(wd), scalaVersion, sbtVersion, classpath, args, context) + finally context.close() } // this arrangement is because Scala does not always properly optimize away @@ -65,9 +70,10 @@ object RunFromSourceMain { sbtVersion: String, classpath: String, args: Seq[String], + context: LoggerContext ): Unit = - runImpl(baseDir, scalaVersion, sbtVersion, classpath, args) match { - case Some((baseDir, args)) => run(baseDir, scalaVersion, sbtVersion, classpath, args) + runImpl(baseDir, scalaVersion, sbtVersion, classpath, args, context: LoggerContext) match { + case Some((baseDir, args)) => run(baseDir, scalaVersion, sbtVersion, classpath, args, context) case None => () } @@ -77,8 +83,9 @@ object RunFromSourceMain { sbtVersion: String, classpath: String, args: Seq[String], + context: LoggerContext, ): Option[(File, Seq[String])] = { - try launch(defaultBootDirectory, baseDir, scalaVersion, sbtVersion, classpath, args) map exit + try launch(defaultBootDirectory, baseDir, scalaVersion, sbtVersion, classpath, args, context) map exit catch { case r: xsbti.FullReload => Some((baseDir, r.arguments())) case scala.util.control.NonFatal(e) => e.printStackTrace(); errorAndExit(e.toString) @@ -92,10 +99,11 @@ object RunFromSourceMain { sbtVersion: String, classpath: String, arguments: Seq[String], + context: LoggerContext, ): Option[Int] = { ScriptedLauncher .launch( - scalaHome(bootDirectory, scalaVersion), + scalaHome(bootDirectory, scalaVersion, context), sbtVersion, scalaVersion, bootDirectory, @@ -112,8 +120,8 @@ object RunFromSourceMain { private lazy val defaultBootDirectory: File = file(sys.props("user.home")) / ".sbt" / "scripted" / "boot" - private def scalaHome(bootDirectory: File, scalaVersion: String): File = { - val log = sbt.util.LogExchange.logger("run-from-source") + private def scalaHome(bootDirectory: File, scalaVersion: String, context: LoggerContext): File = { + val log = context.logger("run-from-source", None, None) val scalaHome0 = bootDirectory / s"scala-$scalaVersion" if ((scalaHome0 / "lib" / "scala-library.jar").exists) scalaHome0 else { diff --git a/testing/src/main/scala/sbt/internal/testing/TestLogger.scala b/testing/src/main/scala/sbt/internal/testing/TestLogger.scala index 62da7f6d8..0b094eaad 100644 --- a/testing/src/main/scala/sbt/internal/testing/TestLogger.scala +++ b/testing/src/main/scala/sbt/internal/testing/TestLogger.scala @@ -10,10 +10,9 @@ package internal.testing import testing.{ Logger => TLogger } import sbt.internal.util.{ BufferedAppender, ConsoleAppender, ManagedLogger } -import sbt.util.{ Level, LogExchange, ShowLines } +import sbt.util.{ Level, ShowLines } import sbt.protocol.testing._ import java.util.concurrent.atomic.AtomicInteger -import scala.collection.JavaConverters._ object TestLogger { import sbt.protocol.testing.codec.JsonProtocol._ @@ -35,20 +34,28 @@ object TestLogger { val buffered: Boolean ) - def make(global: ManagedLogger, perTest: TestDefinition => PerTest): TestLogger = { + @deprecated("Use make variant that accepts a log level.", "1.4.0") + def make( + global: ManagedLogger, + perTest: TestDefinition => PerTest, + ): TestLogger = make(global, perTest, Level.Debug) + + def make( + global: ManagedLogger, + perTest: TestDefinition => PerTest, + level: Level.Value + ): TestLogger = { + val context = global.context + val as = context.appenders(global.name) def makePerTest(tdef: TestDefinition): ContentLogger = { val per = perTest(tdef) val l0 = per.log - val config = LogExchange.loggerConfig(l0.name) - val as = config.getAppenders.asScala - val buffs: List[BufferedAppender] = (as map { - case (_, v) => BufferedAppender(generateBufferName, v) - }).toList - val newLog = LogExchange.logger(generateName, l0.channelName, l0.execId) - LogExchange.unbindLoggerAppenders(newLog.name) - LogExchange.bindLoggerAppenders(newLog.name, buffs map { x => - (x, Level.Debug) - }) + val buffs = as.map(a => BufferedAppender(generateBufferName, a)).toList + val newLog = context.logger(generateName, l0.channelName, l0.execId) + context.clearAppenders(newLog.name) + buffs.foreach { b => + context.addAppender(newLog.name, b -> level) + } if (per.buffered) { buffs foreach { _.record() } }