Merge pull request #71 from eed3si9n/wip/eventlogging

event logging

build.sbt

@@ -99,12 +99,12 @@ lazy val utilComplete = (project in internalPath / "util-complete").
 // logging
 lazy val utilLogging = (project in internalPath / "util-logging").
   enablePlugins(ContrabandPlugin, JsonCodecPlugin).
-  dependsOn(utilInterface, utilTesting % Test).
+  dependsOn(utilInterface, utilCollection, utilTesting % Test).
   settings(
     commonSettings,
     crossScalaVersions := Seq(scala210, scala211, scala212),
     name := "Util Logging",
-    libraryDependencies ++= Seq(jline, log4jApi, log4jCore, disruptor, sjsonnewScalaJson),
+    libraryDependencies ++= Seq(jline, log4jApi, log4jCore, disruptor, sjsonnewScalaJson, scalaReflect.value),
     sourceManaged in (Compile, generateContrabands) := baseDirectory.value / "src" / "main" / "contraband-scala"
   )
 

internal/util-collection/src/main/scala/sbt/internal/util/INode.scala

@@ -95,7 +95,7 @@ abstract class EvaluateSettings[Scope] {
       keyString
 
     private[this] def keyString =
-      (static.toSeq.flatMap { case (key, value) => if (value eq this) init.showFullKey(key) :: Nil else Nil }).headOption getOrElse "non-static"
+      (static.toSeq.flatMap { case (key, value) => if (value eq this) init.showFullKey.show(key) :: Nil else Nil }).headOption getOrElse "non-static"
 
     final def get: T = synchronized {
       assert(value != null, toString + " not evaluated")

internal/util-collection/src/main/scala/sbt/internal/util/Settings.scala

@@ -6,6 +6,7 @@ package sbt.internal.util
 import scala.language.existentials
 
 import Types._
+import sbt.util.Show
 
 sealed trait Settings[Scope] {
   def data: Map[Scope, AttributeMap]
@@ -119,7 +120,7 @@ trait Init[Scope] {
   def mapScope(f: Scope => Scope): MapScoped = new MapScoped {
     def apply[T](k: ScopedKey[T]): ScopedKey[T] = k.copy(scope = f(k.scope))
   }
-  private final class InvalidReference(val key: ScopedKey[_]) extends RuntimeException("Internal settings error: invalid reference to " + showFullKey(key))
+  private final class InvalidReference(val key: ScopedKey[_]) extends RuntimeException("Internal settings error: invalid reference to " + showFullKey.show(key))
 
   private[this] def applyDefaults(ss: Seq[Setting[_]]): Seq[Setting[_]] =
     {
@@ -215,11 +216,11 @@ trait Init[Scope] {
     {
       val guessed = guessIntendedScope(validKeys, delegates, u.referencedKey)
       val derived = u.defining.isDerived
-      val refString = display(u.defining.key)
+      val refString = display.show(u.defining.key)
       val sourceString = if (derived) "" else parenPosString(u.defining)
-      val guessedString = if (derived) "" else guessed.map(g => "\n     Did you mean " + display(g) + " ?").toList.mkString
+      val guessedString = if (derived) "" else guessed.map(g => "\n     Did you mean " + display.show(g) + " ?").toList.mkString
       val derivedString = if (derived) ", which is a derived setting that needs this key to be defined in this scope." else ""
-      display(u.referencedKey) + " from " + refString + sourceString + derivedString + guessedString
+      display.show(u.referencedKey) + " from " + refString + sourceString + derivedString + guessedString
     }
   private[this] def parenPosString(s: Setting[_]): String =
     s.positionString match { case None => ""; case Some(s) => " (" + s + ")" }
@@ -255,7 +256,7 @@ trait Init[Scope] {
       new Uninitialized(keys, prefix + suffix + " to undefined setting" + suffix + ": " + keysString + "\n ")
     }
   final class Compiled[T](val key: ScopedKey[T], val dependencies: Iterable[ScopedKey[_]], val settings: Seq[Setting[T]]) {
-    override def toString = showFullKey(key)
+    override def toString = showFullKey.show(key)
   }
   final class Flattened(val key: ScopedKey[_], val dependencies: Iterable[ScopedKey[_]])
 

internal/util-collection/src/main/scala/sbt/internal/util/Show.scala

@@ -1,8 +0,0 @@
-package sbt.internal.util
-
-trait Show[T] {
-  def apply(t: T): String
-}
-object Show {
-  def apply[T](f: T => String): Show[T] = new Show[T] { def apply(t: T): String = f(t) }
-}

internal/util-collection/src/main/scala/sbt/util/Show.scala

@@ -0,0 +1,12 @@
+package sbt.util
+
+trait Show[A] {
+  def show(a: A): String
+}
+object Show {
+  def apply[A](f: A => String): Show[A] = new Show[A] { def show(a: A): String = f(a) }
+
+  def fromToString[A]: Show[A] = new Show[A] {
+    def show(a: A): String = a.toString
+  }
+}

internal/util-collection/src/main/scala/sbt/util/ShowLines.scala

@@ -1,4 +1,4 @@
-package sbt.internal.util
+package sbt.util
 
 trait ShowLines[A] {
   def showLines(a: A): Seq[String]

internal/util-collection/src/test/scala/SettingsExample.scala

@@ -1,5 +1,7 @@
 package sbt.internal.util
 
+import sbt.util.Show
+
 /** Define our settings system */
 
 // A basic scope indexed by an integer.
@@ -12,9 +14,10 @@ final case class Scope(nestIndex: Int, idAtIndex: Int = 0)
 //  That would be a general pain.)
 case class SettingsExample() extends Init[Scope] {
   // Provides a way of showing a Scope+AttributeKey[_]
-  val showFullKey: Show[ScopedKey[_]] = new Show[ScopedKey[_]] {
+  val showFullKey: Show[ScopedKey[_]] = Show[ScopedKey[_]]((key: ScopedKey[_]) =>
-    def apply(key: ScopedKey[_]) = s"${key.scope.nestIndex}(${key.scope.idAtIndex})/${key.key.label}"
+    {
-  }
+      s"${key.scope.nestIndex}(${key.scope.idAtIndex})/${key.key.label}"
+    })
 
   // A sample delegation function that delegates to a Scope with a lower index.
   val delegates: Scope => Seq[Scope] = {

internal/util-interface/src/main/java/xsbti/Position.java

@@ -3,16 +3,19 @@
  */
 package xsbti;
 
+import java.io.File;
+import java.util.Optional;
+
 public interface Position
 {
-	Maybe<Integer> line();
+	Optional<Integer> line();
 	String lineContent();
-	Maybe<Integer> offset();
+	Optional<Integer> offset();
 
 	// pointer to the column position of the error/warning
-	Maybe<Integer> pointer();
+	Optional<Integer> pointer();
-	Maybe<String> pointerSpace();
+	Optional<String> pointerSpace();
 
-	Maybe<String> sourcePath();
+	Optional<String> sourcePath();
-	Maybe<java.io.File> sourceFile();	
+	Optional<File> sourceFile();
-}
+}

internal/util-logging/src/main/contraband-scala/sbt/internal/util/AbstractEntry.scala

@@ -1,5 +1,5 @@
 /**
- * This code is generated using sbt-datatype.
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
  */
 
 // DO NOT EDIT MANUALLY

internal/util-logging/src/main/contraband-scala/sbt/internal/util/ChannelLogEntry.scala

@@ -1,51 +0,0 @@
-/**
- * This code is generated using sbt-datatype.
- */
-
-// DO NOT EDIT MANUALLY
-package sbt.internal.util
-final class ChannelLogEntry private (
-  val level: String,
-  val message: String,
-  channelName: Option[String],
-  execId: Option[String]) extends sbt.internal.util.AbstractEntry(channelName, execId) with Serializable {
-  
-  
-  
-  override def equals(o: Any): Boolean = o match {
-    case x: ChannelLogEntry => (this.level == x.level) && (this.message == x.message) && (this.channelName == x.channelName) && (this.execId == x.execId)
-    case _ => false
-  }
-  override def hashCode: Int = {
-    37 * (37 * (37 * (37 * (17 + level.##) + message.##) + channelName.##) + execId.##)
-  }
-  override def toString: String = {
-    "ChannelLogEntry(" + level + ", " + message + ", " + channelName + ", " + execId + ")"
-  }
-  protected[this] def copy(level: String = level, message: String = message, channelName: Option[String] = channelName, execId: Option[String] = execId): ChannelLogEntry = {
-    new ChannelLogEntry(level, message, channelName, execId)
-  }
-  def withLevel(level: String): ChannelLogEntry = {
-    copy(level = level)
-  }
-  def withMessage(message: String): ChannelLogEntry = {
-    copy(message = message)
-  }
-  def withChannelName(channelName: Option[String]): ChannelLogEntry = {
-    copy(channelName = channelName)
-  }
-  def withChannelName(channelName: String): ChannelLogEntry = {
-    copy(channelName = Option(channelName))
-  }
-  def withExecId(execId: Option[String]): ChannelLogEntry = {
-    copy(execId = execId)
-  }
-  def withExecId(execId: String): ChannelLogEntry = {
-    copy(execId = Option(execId))
-  }
-}
-object ChannelLogEntry {
-  
-  def apply(level: String, message: String, channelName: Option[String], execId: Option[String]): ChannelLogEntry = new ChannelLogEntry(level, message, channelName, execId)
-  def apply(level: String, message: String, channelName: String, execId: String): ChannelLogEntry = new ChannelLogEntry(level, message, Option(channelName), Option(execId))
-}

internal/util-logging/src/main/contraband-scala/sbt/internal/util/StringEvent.scala

@@ -0,0 +1,51 @@
+/**
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
+ */
+
+// DO NOT EDIT MANUALLY
+package sbt.internal.util
+final class StringEvent private (
+  val level: String,
+  val message: String,
+  channelName: Option[String],
+  execId: Option[String]) extends sbt.internal.util.AbstractEntry(channelName, execId) with Serializable {
+  
+  
+  
+  override def equals(o: Any): Boolean = o match {
+    case x: StringEvent => (this.level == x.level) && (this.message == x.message) && (this.channelName == x.channelName) && (this.execId == x.execId)
+    case _ => false
+  }
+  override def hashCode: Int = {
+    37 * (37 * (37 * (37 * (17 + level.##) + message.##) + channelName.##) + execId.##)
+  }
+  override def toString: String = {
+    "StringEvent(" + level + ", " + message + ", " + channelName + ", " + execId + ")"
+  }
+  protected[this] def copy(level: String = level, message: String = message, channelName: Option[String] = channelName, execId: Option[String] = execId): StringEvent = {
+    new StringEvent(level, message, channelName, execId)
+  }
+  def withLevel(level: String): StringEvent = {
+    copy(level = level)
+  }
+  def withMessage(message: String): StringEvent = {
+    copy(message = message)
+  }
+  def withChannelName(channelName: Option[String]): StringEvent = {
+    copy(channelName = channelName)
+  }
+  def withChannelName(channelName: String): StringEvent = {
+    copy(channelName = Option(channelName))
+  }
+  def withExecId(execId: Option[String]): StringEvent = {
+    copy(execId = execId)
+  }
+  def withExecId(execId: String): StringEvent = {
+    copy(execId = Option(execId))
+  }
+}
+object StringEvent {
+  
+  def apply(level: String, message: String, channelName: Option[String], execId: Option[String]): StringEvent = new StringEvent(level, message, channelName, execId)
+  def apply(level: String, message: String, channelName: String, execId: String): StringEvent = new StringEvent(level, message, Option(channelName), Option(execId))
+}

internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/AbstractEntryFormats.scala

@@ -1,10 +1,10 @@
 /**
- * This code is generated using sbt-datatype.
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
  */
 
 // DO NOT EDIT MANUALLY
 package sbt.internal.util.codec
 import _root_.sjsonnew.{ deserializationError, serializationError, Builder, JsonFormat, Unbuilder }
-trait AbstractEntryFormats { self: sjsonnew.BasicJsonProtocol with sbt.internal.util.codec.ChannelLogEntryFormats =>
+trait AbstractEntryFormats { self: sjsonnew.BasicJsonProtocol with sbt.internal.util.codec.StringEventFormats =>
-implicit lazy val AbstractEntryFormat: JsonFormat[sbt.internal.util.AbstractEntry] = flatUnionFormat1[sbt.internal.util.AbstractEntry, sbt.internal.util.ChannelLogEntry]("type")
+implicit lazy val AbstractEntryFormat: JsonFormat[sbt.internal.util.AbstractEntry] = flatUnionFormat1[sbt.internal.util.AbstractEntry, sbt.internal.util.StringEvent]("type")
 }

internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/JsonProtocol.scala

@@ -1,10 +1,10 @@
 /**
- * This code is generated using sbt-datatype.
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
  */
 
 // DO NOT EDIT MANUALLY
 package sbt.internal.util.codec
 trait JsonProtocol extends sjsonnew.BasicJsonProtocol
-  with sbt.internal.util.codec.ChannelLogEntryFormats
+  with sbt.internal.util.codec.StringEventFormats
   with sbt.internal.util.codec.AbstractEntryFormats
 object JsonProtocol extends JsonProtocol

internal/util-logging/src/main/contraband-scala/sbt/internal/util/codec/StringEventFormats.scala

@@ -1,13 +1,13 @@
 /**
- * This code is generated using sbt-datatype.
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
  */
 
 // DO NOT EDIT MANUALLY
 package sbt.internal.util.codec
 import _root_.sjsonnew.{ deserializationError, serializationError, Builder, JsonFormat, Unbuilder }
-trait ChannelLogEntryFormats { self: sjsonnew.BasicJsonProtocol =>
+trait StringEventFormats { self: sjsonnew.BasicJsonProtocol =>
-implicit lazy val ChannelLogEntryFormat: JsonFormat[sbt.internal.util.ChannelLogEntry] = new JsonFormat[sbt.internal.util.ChannelLogEntry] {
+implicit lazy val StringEventFormat: JsonFormat[sbt.internal.util.StringEvent] = new JsonFormat[sbt.internal.util.StringEvent] {
-  override def read[J](jsOpt: Option[J], unbuilder: Unbuilder[J]): sbt.internal.util.ChannelLogEntry = {
+  override def read[J](jsOpt: Option[J], unbuilder: Unbuilder[J]): sbt.internal.util.StringEvent = {
     jsOpt match {
       case Some(js) =>
       unbuilder.beginObject(js)
@@ -16,12 +16,12 @@ implicit lazy val ChannelLogEntryFormat: JsonFormat[sbt.internal.util.ChannelLog
       val channelName = unbuilder.readField[Option[String]]("channelName")
       val execId = unbuilder.readField[Option[String]]("execId")
       unbuilder.endObject()
-      sbt.internal.util.ChannelLogEntry(level, message, channelName, execId)
+      sbt.internal.util.StringEvent(level, message, channelName, execId)
       case None =>
       deserializationError("Expected JsObject but found None")
     }
   }
-  override def write[J](obj: sbt.internal.util.ChannelLogEntry, builder: Builder[J]): Unit = {
+  override def write[J](obj: sbt.internal.util.StringEvent, builder: Builder[J]): Unit = {
     builder.beginObject()
     builder.addField("level", obj.level)
     builder.addField("message", obj.message)

internal/util-logging/src/main/contraband/interface.contra.txt

@@ -0,0 +1,26 @@
+package sbt.internal.util
+@target(Java)
+@codecPackage("sbt.internal.util.codec")
+@fullCodec("JsonProtocol")
+
+enum Severity
+{
+  Info, Warn, Error
+}
+
+type Position {
+  line: Int
+  lineContent: String!
+  offset: Int
+  pointer: Int
+  pointerSpace: String
+  sourcePath: String
+  sourceFile: java.io.File
+}
+
+type Problem {
+  category: String!
+  severity: Severity!
+  message: String!
+  position: Position!
+}

internal/util-logging/src/main/contraband/logging.contra

@@ -8,7 +8,7 @@ interface AbstractEntry {
   execId: String
 }
 
-type ChannelLogEntry implements sbt.internal.util.AbstractEntry {
+type StringEvent implements sbt.internal.util.AbstractEntry {
   level: String!
   message: String!
   channelName: String

internal/util-logging/src/main/scala/sbt/internal/util/BufferedLogger.scala

@@ -5,6 +5,76 @@ 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.appender.AbstractAppender
+import org.apache.logging.log4j.core.layout.PatternLayout
+import java.util.concurrent.atomic.AtomicInteger
+
+object BufferedAppender {
+  def generateName: String =
+    "buffered-" + generateId.incrementAndGet
+  private val generateId: AtomicInteger = new AtomicInteger
+  def apply(delegate: Appender): BufferedAppender =
+    apply(generateName, delegate)
+  def apply(name: String, delegate: Appender): BufferedAppender =
+    {
+      val appender = new BufferedAppender(name, delegate)
+      appender.start
+      appender
+    }
+}
+
+/**
+ * Am appender that can buffer the logging done on it and then can flush the buffer
+ * to the delegate appender provided in the constructor.  Use 'record()' to
+ * start buffering and then 'play' to flush the buffer to the backing appender.
+ *  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) {
+  private[this] val buffer = new ListBuffer[XLogEvent]
+  private[this] var recording = false
+
+  def append(event: XLogEvent): Unit =
+    {
+      if (recording) {
+        buffer += event
+      } else delegate.append(event)
+    }
+
+  /** Enables buffering. */
+  def record() = synchronized { recording = true }
+  def buffer[T](f: => T): T = {
+    record()
+    try { f }
+    finally { stopQuietly() }
+  }
+  def bufferQuietly[T](f: => T): T = {
+    record()
+    try {
+      val result = f
+      clearBuffer()
+      result
+    } catch { case e: Throwable => stopQuietly(); throw e }
+  }
+  def stopQuietly() = synchronized { try { stopBuffer() } catch { case e: Exception => () } }
+
+  /**
+   * Flushes the buffer to the delegate logger.  This method calls logAll on the delegate
+   * so that the messages are written consecutively. The buffer is cleared in the process.
+   */
+  def play(): Unit =
+    synchronized {
+      buffer.toList foreach {
+        delegate.append
+      }
+      buffer.clear()
+    }
+  /** Clears buffered events and disables buffering. */
+  def clearBuffer(): Unit = synchronized { buffer.clear(); recording = false }
+  /** Plays buffered events and disables buffering. */
+  def stopBuffer(): Unit = synchronized { play(); clearBuffer() }
+}
 
 /**
  * A logger that can buffer the logging done on it and then can flush the buffer

internal/util-logging/src/main/scala/sbt/internal/util/ConsoleAppender.scala

@@ -5,11 +5,10 @@ import java.io.{ PrintStream, PrintWriter }
 import java.util.Locale
 import java.util.concurrent.atomic.AtomicInteger
 import org.apache.logging.log4j.{ Level => XLevel }
-import org.apache.logging.log4j.message.{ Message, ParameterizedMessage, ObjectMessage, ReusableObjectMessage }
+import org.apache.logging.log4j.message.{ Message, ObjectMessage, ReusableObjectMessage }
 import org.apache.logging.log4j.core.{ LogEvent => XLogEvent }
 import org.apache.logging.log4j.core.appender.AbstractAppender
 import org.apache.logging.log4j.core.layout.PatternLayout
-import org.apache.logging.log4j.core.async.RingBufferLogEvent
 
 import ConsoleAppender._
 
@@ -149,7 +148,7 @@ object ConsoleAppender {
     }
   }
 
-  val formatEnabled =
+  val formatEnabled: Boolean =
     {
       import java.lang.Boolean.{ getBoolean, parseBoolean }
       val value = System.getProperty("sbt.log.format")
@@ -180,8 +179,16 @@ object ConsoleAppender {
 
   def apply(out: PrintStream): ConsoleAppender = apply(generateName, ConsoleOut.printStreamOut(out))
   def apply(out: PrintWriter): ConsoleAppender = apply(generateName, ConsoleOut.printWriterOut(out))
-  def apply(name: String = generateName, out: ConsoleOut = ConsoleOut.systemOut, ansiCodesSupported: Boolean = formatEnabled,
+  def apply(): ConsoleAppender = apply(generateName, ConsoleOut.systemOut)
-    useColor: Boolean = formatEnabled, suppressedMessage: SuppressedTraceContext => Option[String] = noSuppressedMessage): ConsoleAppender =
+  def apply(name: String): ConsoleAppender = apply(name, ConsoleOut.systemOut, formatEnabled, formatEnabled, noSuppressedMessage)
+  def apply(out: ConsoleOut): ConsoleAppender = apply(generateName, out, formatEnabled, formatEnabled, noSuppressedMessage)
+  def apply(name: String, out: ConsoleOut): ConsoleAppender = apply(name, out, formatEnabled, formatEnabled, noSuppressedMessage)
+  def apply(name: String, out: ConsoleOut, suppressedMessage: SuppressedTraceContext => Option[String]): ConsoleAppender =
+    apply(name, out, formatEnabled, formatEnabled, suppressedMessage)
+  def apply(name: String, out: ConsoleOut, useColor: Boolean): ConsoleAppender =
+    apply(name, out, formatEnabled, useColor, noSuppressedMessage)
+  def apply(name: String, out: ConsoleOut, ansiCodesSupported: Boolean,
+    useColor: Boolean, suppressedMessage: SuppressedTraceContext => Option[String]): ConsoleAppender =
     {
       val appender = new ConsoleAppender(name, out, ansiCodesSupported, useColor, suppressedMessage)
       appender.start
@@ -238,24 +245,30 @@ class ConsoleAppender private[ConsoleAppender] (
     {
       val level = ConsoleAppender.toLevel(event.getLevel)
       val message = event.getMessage
-      val str = messageToString(message)
+      // val str = messageToString(message)
-      appendLog(level, str)
+      appendMessage(level, message)
     }
 
-  def messageToString(msg: Message): String =
+  def appendMessage(level: Level.Value, msg: Message): Unit =
     msg match {
-      case p: ParameterizedMessage  => p.getFormattedMessage
+      case o: ObjectMessage         => objectToLines(o.getParameter) foreach { appendLog(level, _) }
-      case r: RingBufferLogEvent    => r.getFormattedMessage
+      case o: ReusableObjectMessage => objectToLines(o.getParameter) foreach { appendLog(level, _) }
-      case o: ObjectMessage         => objectToString(o.getParameter)
+      case _                        => appendLog(level, msg.getFormattedMessage)
-      case o: ReusableObjectMessage => objectToString(o.getParameter)
-      case _                        => msg.getFormattedMessage
     }
-  def objectToString(o: AnyRef): String =
+  def objectToLines(o: AnyRef): Vector[String] =
     o match {
-      case x: ChannelLogEntry => x.message
+      case x: StringEvent    => Vector(x.message)
-      case _                  => o.toString
+      case x: ObjectEvent[_] => objectEventToLines(x)
+      case _                 => Vector(o.toString)
+    }
+  def objectEventToLines(oe: ObjectEvent[_]): Vector[String] =
+    {
+      val tag = oe.tag
+      LogExchange.stringCodec[AnyRef](tag) match {
+        case Some(codec) => codec.showLines(oe.message.asInstanceOf[AnyRef]).toVector
+        case _           => Vector(oe.message.toString)
+      }
     }
-
   def messageColor(level: Level.Value) = RESET
   def labelColor(level: Level.Value) =
     level match {

internal/util-logging/src/main/scala/sbt/internal/util/MainLogging.scala

@@ -48,14 +48,15 @@ object MainAppender {
   def defaultScreen(name: String, console: ConsoleOut, suppressedMessage: SuppressedTraceContext => Option[String]): Appender =
     ConsoleAppender(name, console, suppressedMessage = suppressedMessage)
 
-  def defaultBacked(
+  def defaultBacked: PrintWriter => Appender = defaultBacked(generateGlobalBackingName, ConsoleAppender.formatEnabled)
-    loggerName: String = generateGlobalBackingName,
+  def defaultBacked(loggerName: String): PrintWriter => Appender = defaultBacked(loggerName, ConsoleAppender.formatEnabled)
-    useColor: Boolean = ConsoleAppender.formatEnabled
+  def defaultBacked(useColor: Boolean): PrintWriter => Appender = defaultBacked(generateGlobalBackingName, useColor)
-  ): PrintWriter => Appender =
+  def defaultBacked(loggerName: String, useColor: Boolean): PrintWriter => Appender =
     to => {
       ConsoleAppender(
         ConsoleAppender.generateName,
-        ConsoleOut.printWriterOut(to), useColor = useColor
+        ConsoleOut.printWriterOut(to),
+        useColor = useColor
       )
     }
 

internal/util-logging/src/main/scala/sbt/internal/util/ManagedLogger.scala

@@ -3,6 +3,8 @@ package sbt.internal.util
 import sbt.util._
 import org.apache.logging.log4j.{ Logger => XLogger }
 import org.apache.logging.log4j.message.ObjectMessage
+import sjsonnew.JsonFormat
+import scala.reflect.runtime.universe.TypeTag
 
 /**
  * Delegates log events to the associated LogExchange.
@@ -18,8 +20,32 @@ class ManagedLogger(
     {
       xlogger.log(
         ConsoleAppender.toXLevel(level),
-        new ObjectMessage(ChannelLogEntry(level.toString, message, channelName, execId))
+        new ObjectMessage(StringEvent(level.toString, message, channelName, execId))
       )
     }
   override def success(message: => String): Unit = xlogger.info(message)
+
+  def registerStringCodec[A: ShowLines: TypeTag]: Unit =
+    {
+      val tag = StringTypeTag[A]
+      val ev = implicitly[ShowLines[A]]
+      // println(s"registerStringCodec ${tag.key}")
+      val _ = LogExchange.getOrElseUpdateStringCodec(tag.key, ev)
+    }
+  final def debugEvent[A: JsonFormat: TypeTag](event: => A): Unit = logEvent(Level.Debug, event)
+  final def infoEvent[A: JsonFormat: TypeTag](event: => A): Unit = logEvent(Level.Info, event)
+  final def warnEvent[A: JsonFormat: TypeTag](event: => A): Unit = logEvent(Level.Warn, event)
+  final def errorEvent[A: JsonFormat: TypeTag](event: => A): Unit = logEvent(Level.Error, event)
+  def logEvent[A: JsonFormat: TypeTag](level: Level.Value, event: => A): Unit =
+    {
+      val v: A = event
+      val tag = StringTypeTag[A]
+      LogExchange.getOrElseUpdateJsonCodec(tag.key, implicitly[JsonFormat[A]])
+      // println("logEvent " + tag.key)
+      val entry: ObjectEvent[A] = new ObjectEvent(level, v, channelName, execId, tag.key)
+      xlogger.log(
+        ConsoleAppender.toXLevel(level),
+        new ObjectMessage(entry)
+      )
+    }
 }

internal/util-logging/src/main/scala/sbt/internal/util/ObjectEvent.scala

@@ -0,0 +1,15 @@
+package sbt
+package internal
+package util
+
+import sbt.util.Level
+import sjsonnew.JsonFormat
+
+final class ObjectEvent[A](
+  val level: Level.Value,
+  val message: A,
+  val channelName: Option[String],
+  val execId: Option[String],
+  val tag: String
+) extends Serializable {
+}

internal/util-logging/src/main/scala/sbt/internal/util/StringTypeTag.scala

@@ -0,0 +1,29 @@
+package sbt.internal.util
+
+import scala.reflect.runtime.universe._
+
+/** This is used to carry type information in JSON. */
+final case class StringTypeTag[A](key: String) {
+  override def toString: String = key
+}
+
+object StringTypeTag {
+  def apply[A: TypeTag]: StringTypeTag[A] =
+    {
+      val tag = implicitly[TypeTag[A]]
+      val tpe = tag.tpe
+      val k = typeToString(tpe)
+      // println(tpe.getClass.toString + " " + k)
+      StringTypeTag[A](k)
+    }
+  def typeToString(tpe: Type): String =
+    tpe match {
+      case ref: TypeRef =>
+        if (ref.args.nonEmpty) {
+          val typeCon = ref.typeConstructor.typeSymbol.asType.fullName
+          val typeArgs = ref.typeArgs map typeToString
+          s"""$typeCon[${typeArgs.mkString(",")}]"""
+        } else tpe.toString
+      case _ => tpe.toString
+    }
+}

internal/util-logging/src/main/scala/sbt/internal/util/codecs/PositionFormats.scala

@@ -0,0 +1,49 @@
+/**
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
+ */
+
+package sbt.internal.util.codec
+import _root_.sjsonnew.{ deserializationError, Builder, JsonFormat, Unbuilder }
+import xsbti.Position
+import java.util.Optional
+
+trait PositionFormats { self: sjsonnew.BasicJsonProtocol =>
+  implicit lazy val PositionFormat: JsonFormat[Position] = new JsonFormat[Position] {
+    override def read[J](jsOpt: Option[J], unbuilder: Unbuilder[J]): Position = {
+      jsOpt match {
+        case Some(js) =>
+          unbuilder.beginObject(js)
+          val line0 = unbuilder.readField[Optional[java.lang.Integer]]("line")
+          val lineContent0 = unbuilder.readField[String]("lineContent")
+          val offset0 = unbuilder.readField[Optional[java.lang.Integer]]("offset")
+          val pointer0 = unbuilder.readField[Optional[java.lang.Integer]]("pointer")
+          val pointerSpace0 = unbuilder.readField[Optional[String]]("pointerSpace")
+          val sourcePath0 = unbuilder.readField[Optional[String]]("sourcePath")
+          val sourceFile0 = unbuilder.readField[Optional[java.io.File]]("sourceFile")
+          unbuilder.endObject()
+          new Position() {
+            override val line = line0
+            override val lineContent = lineContent0
+            override val offset = offset0
+            override val pointer = pointer0
+            override val pointerSpace = pointerSpace0
+            override val sourcePath = sourcePath0
+            override val sourceFile = sourceFile0
+          }
+        case None =>
+          deserializationError("Expected JsObject but found None")
+      }
+    }
+    override def write[J](obj: Position, builder: Builder[J]): Unit = {
+      builder.beginObject()
+      builder.addField("line", obj.line)
+      builder.addField("lineContent", obj.lineContent)
+      builder.addField("offset", obj.offset)
+      builder.addField("pointer", obj.pointer)
+      builder.addField("pointerSpace", obj.pointerSpace)
+      builder.addField("sourcePath", obj.sourcePath)
+      builder.addField("sourceFile", obj.sourceFile)
+      builder.endObject()
+    }
+  }
+}

internal/util-logging/src/main/scala/sbt/internal/util/codecs/ProblemFormats.scala

@@ -0,0 +1,36 @@
+/**
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
+ */
+
+package sbt.internal.util.codec
+
+import xsbti.{ Problem, Severity, Position }
+import sbt.util.InterfaceUtil.problem
+import _root_.sjsonnew.{ deserializationError, Builder, JsonFormat, Unbuilder }
+
+trait ProblemFormats { self: SeverityFormats with PositionFormats with sjsonnew.BasicJsonProtocol =>
+  implicit lazy val ProblemFormat: JsonFormat[Problem] = new JsonFormat[Problem] {
+    override def read[J](jsOpt: Option[J], unbuilder: Unbuilder[J]): Problem = {
+      jsOpt match {
+        case Some(js) =>
+          unbuilder.beginObject(js)
+          val category = unbuilder.readField[String]("category")
+          val severity = unbuilder.readField[Severity]("severity")
+          val message = unbuilder.readField[String]("message")
+          val position = unbuilder.readField[Position]("position")
+          unbuilder.endObject()
+          problem(category, position, message, severity)
+        case None =>
+          deserializationError("Expected JsObject but found None")
+      }
+    }
+    override def write[J](obj: Problem, builder: Builder[J]): Unit = {
+      builder.beginObject()
+      builder.addField("category", obj.category)
+      builder.addField("severity", obj.severity)
+      builder.addField("message", obj.message)
+      builder.addField("position", obj.position)
+      builder.endObject()
+    }
+  }
+}

internal/util-logging/src/main/scala/sbt/internal/util/codecs/SeverityFormats.scala

@@ -0,0 +1,33 @@
+/**
+ * This code is generated using [[http://www.scala-sbt.org/contraband/ sbt-contraband]].
+ */
+
+package sbt.internal.util.codec
+
+import _root_.sjsonnew.{ deserializationError, Builder, JsonFormat, Unbuilder }
+import xsbti.Severity;
+
+trait SeverityFormats { self: sjsonnew.BasicJsonProtocol =>
+  implicit lazy val SeverityFormat: JsonFormat[Severity] = new JsonFormat[Severity] {
+    override def read[J](jsOpt: Option[J], unbuilder: Unbuilder[J]): Severity = {
+      jsOpt match {
+        case Some(js) =>
+          unbuilder.readString(js) match {
+            case "Info"  => Severity.Info
+            case "Warn"  => Severity.Warn
+            case "Error" => Severity.Error
+          }
+        case None =>
+          deserializationError("Expected JsString but found None")
+      }
+    }
+    override def write[J](obj: Severity, builder: Builder[J]): Unit = {
+      val str = obj match {
+        case Severity.Info  => "Info"
+        case Severity.Warn  => "Warn"
+        case Severity.Error => "Error"
+      }
+      builder.writeString(str)
+    }
+  }
+}

internal/util-logging/src/main/scala/sbt/util/InterfaceUtil.scala

@@ -2,6 +2,7 @@ package sbt.util
 
 import xsbti.{ Maybe, F0, F1, T2, Position, Problem, Severity }
 import java.io.File
+import java.util.Optional
 
 object InterfaceUtil {
   def f0[A](a: => A): F0[A] = new ConcreteF0[A](a)
@@ -18,6 +19,16 @@ object InterfaceUtil {
       case None    => Maybe.nothing()
     }
 
+  def jo2o[A](o: Optional[A]): Option[A] =
+    if (o.isPresent) Some(o.get)
+    else None
+
+  def o2jo[A](o: Option[A]): Optional[A] =
+    o match {
+      case Some(v) => Optional.ofNullable(v)
+      case None    => Optional.empty[A]()
+    }
+
   def position(line0: Option[Integer], content: String, offset0: Option[Integer], pointer0: Option[Integer],
     pointerSpace0: Option[String], sourcePath0: Option[String], sourceFile0: Option[File]): Position =
     new ConcretePosition(line0, content, offset0, pointer0, pointerSpace0, sourcePath0, sourceFile0)
@@ -61,13 +72,13 @@ object InterfaceUtil {
     sourcePath0: Option[String],
     sourceFile0: Option[File]
   ) extends Position {
-    val line = o2m(line0)
+    val line = o2jo(line0)
     val lineContent = content
-    val offset = o2m(offset0)
+    val offset = o2jo(offset0)
-    val pointer = o2m(pointer0)
+    val pointer = o2jo(pointer0)
-    val pointerSpace = o2m(pointerSpace0)
+    val pointerSpace = o2jo(pointerSpace0)
-    val sourcePath = o2m(sourcePath0)
+    val sourcePath = o2jo(sourcePath0)
-    val sourceFile = o2m(sourceFile0)
+    val sourceFile = o2jo(sourceFile0)
   }
 
   private final class ConcreteProblem(

internal/util-logging/src/main/scala/sbt/util/LogExchange.scala

@@ -6,6 +6,8 @@ import org.apache.logging.log4j.core._
 import org.apache.logging.log4j.core.appender.AsyncAppender
 import org.apache.logging.log4j.core.config.{ AppenderRef, LoggerConfig }
 import scala.collection.JavaConverters._
+import scala.collection.concurrent
+import sjsonnew.JsonFormat
 
 // http://logging.apache.org/log4j/2.x/manual/customconfig.html
 // https://logging.apache.org/log4j/2.x/log4j-core/apidocs/index.html
@@ -13,6 +15,8 @@ import scala.collection.JavaConverters._
 sealed abstract class LogExchange {
   private[sbt] lazy val context: LoggerContext = init()
   private[sbt] lazy val asyncStdout: AsyncAppender = buildAsyncStdout
+  private[sbt] val jsonCodecs: concurrent.Map[String, JsonFormat[_]] = concurrent.TrieMap()
+  private[sbt] val stringCodecs: concurrent.Map[String, ShowLines[_]] = concurrent.TrieMap()
 
   def logger(name: String): ManagedLogger = logger(name, None, None)
   def logger(name: String, channelName: Option[String], execId: Option[String]): ManagedLogger = {
@@ -43,6 +47,19 @@ sealed abstract class LogExchange {
     val config = ctx.getConfiguration
     config.getLoggerConfig(loggerName)
   }
+  def jsonCodec[A](tag: String): Option[JsonFormat[A]] =
+    jsonCodecs.get(tag) map { _.asInstanceOf[JsonFormat[A]] }
+  def hasJsonCodec(tag: String): Boolean =
+    jsonCodecs.contains(tag)
+  def getOrElseUpdateJsonCodec[A](tag: String, v: JsonFormat[A]): JsonFormat[A] =
+    jsonCodecs.getOrElseUpdate(tag, v).asInstanceOf[JsonFormat[A]]
+  def stringCodec[A](tag: String): Option[ShowLines[A]] =
+    stringCodecs.get(tag) map { _.asInstanceOf[ShowLines[A]] }
+  def hasStringCodec(tag: String): Boolean =
+    stringCodecs.contains(tag)
+  def getOrElseUpdateStringCodec[A](tag: String, v: ShowLines[A]): ShowLines[A] =
+    stringCodecs.getOrElseUpdate(tag, v).asInstanceOf[ShowLines[A]]
+
   private[sbt] def buildAsyncStdout: AsyncAppender = {
     val ctx = XLogManager.getContext(false) match { case x: LoggerContext => x }
     val config = ctx.getConfiguration

internal/util-logging/src/main/scala/sbt/util/Logger.scala

@@ -9,6 +9,7 @@ import sys.process.ProcessLogger
 import sbt.internal.util.{ BufferedLogger, FullLogger }
 
 import java.io.File
+import java.util.Optional
 
 /**
  * This is intended to be the simplest logging interface for use by code that wants to log.
@@ -88,6 +89,8 @@ object Logger {
   def f0[A](a: => A): F0[A] = InterfaceUtil.f0[A](a)
   def m2o[A](m: Maybe[A]): Option[A] = InterfaceUtil.m2o(m)
   def o2m[A](o: Option[A]): Maybe[A] = InterfaceUtil.o2m(o)
+  def jo2o[A](o: Optional[A]): Option[A] = InterfaceUtil.jo2o(o)
+  def o2jo[A](o: Option[A]): Optional[A] = InterfaceUtil.o2jo(o)
   def position(line0: Option[Integer], content: String, offset0: Option[Integer], pointer0: Option[Integer],
     pointerSpace0: Option[String], sourcePath0: Option[String], sourceFile0: Option[File]): Position =
     InterfaceUtil.position(line0, content, offset0, pointer0, pointerSpace0, sourcePath0, sourceFile0)

internal/util-logging/src/test/scala/ManagedLoggerSpec.scala

@@ -13,6 +13,40 @@ class ManagedLoggerSpec extends FlatSpec with Matchers {
     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))
+    log.infoEvent(1)
+  }
+
+  it should "allow registering Show[Int]" in {
+    import sjsonnew.BasicJsonProtocol._
+    val log = LogExchange.logger("foo")
+    LogExchange.bindLoggerAppenders("foo", List(LogExchange.asyncStdout -> Level.Info))
+    implicit val intShow: ShowLines[Int] = ShowLines({ (x: Int) => Vector(s"String representation of $x") })
+    log.registerStringCodec[Int]
+    log.infoEvent(1)
+  }
+
+  it should "allow registering Show[Array[Int]]" in {
+    import sjsonnew.BasicJsonProtocol._
+    val log = LogExchange.logger("foo")
+    LogExchange.bindLoggerAppenders("foo", List(LogExchange.asyncStdout -> Level.Info))
+    implicit val intArrayShow: ShowLines[Array[Int]] = ShowLines({ (x: Array[Int]) => Vector(s"String representation of ${x.mkString}") })
+    log.registerStringCodec[Array[Int]]
+    log.infoEvent(Array(1, 2, 3))
+  }
+
+  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))
+    implicit val intVectorShow: ShowLines[Vector[Vector[Int]]] = ShowLines({ (xss: Vector[Vector[Int]]) => Vector(s"String representation of $xss") })
+    log.registerStringCodec[Vector[Vector[Int]]]
+    log.infoEvent(Vector(Vector(1, 2, 3)))
+  }
+
   "global logging" should "log immediately after initialization" in {
     // this is passed into State normally
     val global0 = initialGlobalLogging

internal/util-scripted/src/main/scala/sbt/internal/scripted/ScriptedTests.scala

@@ -3,18 +3,18 @@ package internal
 package scripted
 
 import java.io.File
-import sbt.util.Logger
+import sbt.util.{ Logger, LogExchange, Level }
-import sbt.internal.util.{ ConsoleLogger, BufferedLogger, FullLogger }
+import sbt.internal.util.{ ManagedLogger, ConsoleOut, MainAppender, ConsoleAppender, BufferedAppender }
 import sbt.io.IO.wrapNull
 import sbt.io.{ DirectoryFilter, HiddenFileFilter }
 import sbt.io.syntax._
 import sbt.internal.io.Resources
+import java.util.concurrent.atomic.AtomicInteger
 
 object ScriptedRunnerImpl {
   def run(resourceBaseDirectory: File, bufferLog: Boolean, tests: Array[String], handlersProvider: HandlersProvider): Unit = {
     val runner = new ScriptedTests(resourceBaseDirectory, bufferLog, handlersProvider)
-    val logger = ConsoleLogger()
+    val logger = newLogger
-    logger.setLevel(sbt.util.Level.Debug)
     val allTests = get(tests, resourceBaseDirectory, logger) flatMap {
       case ScriptedTest(group, name) =>
         runner.scriptedTest(group, name, logger)
@@ -26,29 +26,36 @@ object ScriptedRunnerImpl {
     if (errors.nonEmpty)
       sys.error(errors.mkString("Failed tests:\n\t", "\n\t", "\n"))
   }
-  def get(tests: Seq[String], baseDirectory: File, log: Logger): Seq[ScriptedTest] =
+  def get(tests: Seq[String], baseDirectory: File, log: ManagedLogger): Seq[ScriptedTest] =
     if (tests.isEmpty) listTests(baseDirectory, log) else parseTests(tests)
-  def listTests(baseDirectory: File, log: Logger): Seq[ScriptedTest] =
+  def listTests(baseDirectory: File, log: ManagedLogger): Seq[ScriptedTest] =
     (new ListTests(baseDirectory, _ => true, log)).listTests
   def parseTests(in: Seq[String]): Seq[ScriptedTest] =
     for (testString <- in) yield {
       val Array(group, name) = testString.split("/").map(_.trim)
       ScriptedTest(group, name)
     }
+  private[sbt] val generateId: AtomicInteger = new AtomicInteger
+  private[sbt] def newLogger: ManagedLogger =
+    {
+      val loggerName = "scripted-" + generateId.incrementAndGet
+      val x = LogExchange.logger(loggerName)
+      x
+    }
 }
 
 final class ScriptedTests(resourceBaseDirectory: File, bufferLog: Boolean, handlersProvider: HandlersProvider) {
-  // import ScriptedTests._
   private val testResources = new Resources(resourceBaseDirectory)
+  private val consoleAppender: ConsoleAppender = ConsoleAppender()
 
   val ScriptFilename = "test"
   val PendingScriptFilename = "pending"
 
   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: Logger): Seq[() => Option[String]] =
+  def scriptedTest(group: String, name: String, log: ManagedLogger): Seq[() => Option[String]] =
     scriptedTest(group, name, { _ => () }, log)
-  def scriptedTest(group: String, name: String, prescripted: File => Unit, log: Logger): Seq[() => Option[String]] = {
+  def scriptedTest(group: String, name: String, prescripted: File => Unit, log: ManagedLogger): Seq[() => Option[String]] = {
     for (groupDir <- (resourceBaseDirectory * group).get; nme <- (groupDir * name).get) yield {
       val g = groupDir.getName
       val n = nme.getName
@@ -69,19 +76,20 @@ final class ScriptedTests(resourceBaseDirectory: File, bufferLog: Boolean, handl
     }
   }
 
-  private def scriptedTest(label: String, testDirectory: File, prescripted: File => Unit, log: Logger): Unit =
+  private def scriptedTest(label: String, testDirectory: File, prescripted: File => Unit, log: ManagedLogger): Unit =
     {
-      val buffered = new BufferedLogger(new FullLogger(log))
+      val buffered = BufferedAppender(consoleAppender)
-      buffered.setLevel(sbt.util.Level.Debug)
+      LogExchange.unbindLoggerAppenders(log.name)
-      if (bufferLog)
+      LogExchange.bindLoggerAppenders(log.name, (buffered -> Level.Debug) :: Nil)
+      if (bufferLog) {
         buffered.record()
-
+      }
       def createParser() =
         {
           // val fileHandler = new FileCommands(testDirectory)
           // // val sbtHandler = new SbtHandler(testDirectory, launcher, buffered, launchOpts)
           // new TestScriptParser(Map('$' -> fileHandler, /* '>' -> sbtHandler, */ '#' -> CommentHandler))
-          val scriptConfig = new ScriptConfig(label, testDirectory, buffered)
+          val scriptConfig = new ScriptConfig(label, testDirectory, log)
           new TestScriptParser(handlersProvider getHandlers scriptConfig)
         }
       val (file, pending) = {
@@ -98,31 +106,31 @@ final class ScriptedTests(resourceBaseDirectory: File, bufferLog: Boolean, handl
           run(parser.parse(file))
         }
       def testFailed(): Unit = {
-        if (pending) buffered.clear() else buffered.stop()
+        if (pending) buffered.clearBuffer() else buffered.stopBuffer()
-        buffered.error("x " + label + pendingString)
+        log.error("x " + label + pendingString)
       }
 
       try {
         prescripted(testDirectory)
         runTest()
-        buffered.info("+ " + label + pendingString)
+        log.info("+ " + label + pendingString)
         if (pending) throw new PendingTestSuccessException(label)
       } catch {
         case e: TestException =>
           testFailed()
           e.getCause match {
-            case null | _: java.net.SocketException => buffered.error("   " + e.getMessage)
+            case null | _: java.net.SocketException => log.error("   " + e.getMessage)
             case _                                  => if (!pending) e.printStackTrace
           }
           if (!pending) throw e
         case e: PendingTestSuccessException =>
           testFailed()
-          buffered.error("  Mark as passing to remove this failure.")
+          log.error("  Mark as passing to remove this failure.")
           throw e
         case e: Exception =>
           testFailed()
           if (!pending) throw e
-      } finally { buffered.clear() }
+      } finally { buffered.clearBuffer() }
     }
 }
 

project/contraband.sbt

@@ -1 +1 @@
-addSbtPlugin("org.scala-sbt" % "sbt-contraband" % "0.3.0-M3")
+addSbtPlugin("org.scala-sbt" % "sbt-contraband" % "0.3.0-M4")