luke
/
sbt
mirror of https://github.com/sbt/sbt.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Add internal multi logger implementation 

Prior to these changes, sbt was leaking large amounts of memory via
log4j appenders. sbt has an unusual use case for log4j because it
creates many ephemeral loggers while also having a global logger that is
supposed to work for the duration of the sbt session. There is a lot of
shared global state in log4j and properly cleaning up the ephemeral task
appenders would break global logging. This commit fixes the behavior by
introducing an alternate logging implementation. Users can still use the
old log4j logging implementation but it will be off by default. The
internal implementation is very simple: it just blocks the current
thread and writes to all of the appenders. Nevertheless, I found the
performance to be roughly identical to that of log4j in my sample
project. As an experiment, I did the appending on a thread pool and got
a significant performance improvement but I'll defer that to a later PR
since parallel io is harder to reason about.

Background: I was testing sbt performance in
https://github.com/jtjeferreira/sbt-multi-module-sample and noticed that
performance rapidly degraded after I ran compile a few times. I took a
heap dump and it became obvious that sbt was leaking console appenders.
Further investigation revealed that all of the leaking appenders in the
project were coming from task streams. This made me think that the fix
would be to track what loggers were created during task evaluation and
clear them out when task evaluation completed. That almost worked except
that log4j has an internal append only data structure containing logger
names. Since we create unique logger names for each run, that internal
data structure grew without bound. It looked like this could be worked
around by creating a new log4j Configuration (where that data structure
was stored) but while creating new configurations with each task runs
did fix the leak, it also broke global logging, which was using a
different configuration. At this point, I decided to write an alternate
implementation of the appender api where I could be sure that the
appenders were cleaned up without breaking global logging.

Implementation: I made ConsoleAppender a trait and made it no longer
extends log4j AbstractAppender. To do this, I had to remove the one
log4j specific method, append(LogEvent). ConsoleAppender now has a
method toLog4J that, in most cases, will return a log4j Appender that is
almost identical to the Appenders that we previously used. To manage
the loggers created during task evaluation, I introduce a new class,
LoggerContext. The LoggerContext determines which logging backend to use
and keeps track of what appenders and loggers have been created. We can
create a fresh LoggerContext before each task evaluation and clear it
out, cleaning up all of its resources after task evaluation concludes.

In order to make this work, there were many places where we need to
either pass in a LoggerContext or create a new one. The main magic is
happening in the `next(State)` method in Main. This is where we create a
new LoggerContext prior to command evaluation and clean it up after the
evaluation completes.

Users can toggle log4j using the new useLog4J key. They also can set the
system property, sbt.log.uselog4j. The global logger will use the sbt
internal implementation unless the system property is set.

There are a fairly significant number of mima issues since I changed the
type of ConsoleAppender. All of the mima changes were in the
sbt.internal package so I think this should be ok.

Effects: the memory leaks are gone. I successfully ran 5000 no-op
compiles in the sbt-multi-module-sample above with no degradation of
performace. There was a noticeable degradation after 30 no-op compiles
before.

During the refactor, I had to work on TestLogger and in doing so I also
fixed https://github.com/sbt/sbt/issues/4480.

This also should fix https://github.com/sbt/sbt/issues/4773
This commit is contained in:
Ethan Atkins 2020-08-05 11:23:35 -07:00
parent 841b6dbfd8
commit 2e9805b9d0
21 changed files with 694 additions and 326 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

13
build.sbt
View File

@ -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(

68
internal/util-logging/src/main/scala/sbt/internal/util/BufferedLogger.scala
View File

@ -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()
}

135
internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala
View File

@ -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)

9
internal/util-logging/src/main/scala/sbt/internal/util/GlobalLogging.scala
View File

@ -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)
}
}

41
internal/util-logging/src/main/scala/sbt/internal/util/MainLogging.scala
View File

@ -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

34
internal/util-logging/src/main/scala/sbt/internal/util/ManagedLogger.scala
View File

@ -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")

114
internal/util-logging/src/main/scala/sbt/util/LogExchange.scala
View File

@ -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

189
internal/util-logging/src/main/scala/sbt/util/LoggerContext.scala Normal file
View File

@ -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
}

41
internal/util-logging/src/test/scala/ManagedLoggerSpec.scala
View File

@ -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)

55
internal/util-scripted/src/main/scala/sbt/internal/scripted/ScriptedTests.scala
View File

@ -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()
}

19
main/src/main/scala/sbt/Defaults.scala
View File

@ -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

12
main/src/main/scala/sbt/Keys.scala
View File

@ -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)

5
main/src/main/scala/sbt/Main.scala
View File

@ -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 =>

54
main/src/main/scala/sbt/MainLoop.scala
View File

@ -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(

12
main/src/main/scala/sbt/internal/Continuous.scala
View File

@ -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)

19
main/src/main/scala/sbt/internal/DefaultBackgroundJobService.scala
View File

@ -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 =>

97
main/src/main/scala/sbt/internal/LogManager.scala
View File

@ -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`

41
main/src/main/scala/sbt/internal/RelayAppender.scala
View File

@ -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}")
()
}
}

1
main/src/main/scala/sbt/internal/SysProp.scala
View File

@ -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")

28
sbt/src/test/scala/sbt/RunFromSourceMain.scala
View File

@ -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 {

33
testing/src/main/scala/sbt/internal/testing/TestLogger.scala
View File

@ -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() }
}