From f74e3e66f1336cb68e582cb91f9d38c397f85a37 Mon Sep 17 00:00:00 2001 From: Eugene Yokota Date: Thu, 24 Aug 2017 17:51:50 -0400 Subject: [PATCH 1/3] Trying to reproduce sbt/util#119 --- .../src/test/scala/ManagedLoggerSpec.scala | 24 +++++++++++++++++++ 1 file changed, 24 insertions(+) diff --git a/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala b/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala index a0cf1e569..40601f1c4 100644 --- a/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala +++ b/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala @@ -50,6 +50,30 @@ class ManagedLoggerSpec extends FlatSpec with Matchers { log.infoEvent(Vector(Vector(1, 2, 3))) } + it should "be thread safe" in { + import java.util.concurrent.{ Executors, TimeUnit } + import sjsonnew.BasicJsonProtocol._ + val pool = Executors.newFixedThreadPool(100) + + for { + i <- 1 to 10000 + } { + pool.submit(new Runnable { + def run(): Unit = { + val stringTypeTag = StringTypeTag[List[Int]] + val log = LogExchange.logger(s"foo$i") + LogExchange.bindLoggerAppenders(s"foo$i", List(LogExchange.asyncStdout -> Level.Info)) + if (i % 100 == 0) { + log.info(s"foo$i test $stringTypeTag") + } + Thread.sleep(1) + } + }) + } + pool.shutdown + pool.awaitTermination(30, TimeUnit.SECONDS) + } + "global logging" should "log immediately after initialization" in { // this is passed into State normally val global0 = initialGlobalLogging From b2be0f766ac58454a0b095c03610342c4e9704e2 Mon Sep 17 00:00:00 2001 From: Eugene Yokota Date: Fri, 25 Aug 2017 10:39:40 -0400 Subject: [PATCH 2/3] Attempt to solve the logger NPE issue Fixes sbt/util#119 1. perform the string codec registration once. 2. add retries. --- .../sbt/internal/util/ManagedLogger.scala | 12 ++------ .../sbt/internal/util/StringTypeTag.scala | 30 ++++++++++++++----- .../src/main/scala/sbt/util/LogExchange.scala | 19 ++++++++++++ .../src/test/scala/ManagedLoggerSpec.scala | 9 ++++-- 4 files changed, 51 insertions(+), 19 deletions(-) diff --git a/internal/util-logging/src/main/scala/sbt/internal/util/ManagedLogger.scala b/internal/util-logging/src/main/scala/sbt/internal/util/ManagedLogger.scala index 0fa390c2e..d4cef3fe0 100644 --- a/internal/util-logging/src/main/scala/sbt/internal/util/ManagedLogger.scala +++ b/internal/util-logging/src/main/scala/sbt/internal/util/ManagedLogger.scala @@ -5,9 +5,6 @@ import org.apache.logging.log4j.{ Logger => XLogger } import org.apache.logging.log4j.message.ObjectMessage import sjsonnew.JsonFormat import scala.reflect.runtime.universe.TypeTag -import sbt.internal.util.codec.ThrowableShowLines._ -import sbt.internal.util.codec.TraceEventShowLines._ -import sbt.internal.util.codec.SuccessEventShowLines._ import sbt.internal.util.codec.JsonProtocol._ /** @@ -34,14 +31,9 @@ class ManagedLogger( } 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) + LogExchange.registerStringCodec[A] } - registerStringCodec[Throwable] - registerStringCodec[TraceEvent] - registerStringCodec[SuccessEvent] + 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) diff --git a/internal/util-logging/src/main/scala/sbt/internal/util/StringTypeTag.scala b/internal/util-logging/src/main/scala/sbt/internal/util/StringTypeTag.scala index 00f30d7d2..aa635c975 100644 --- a/internal/util-logging/src/main/scala/sbt/internal/util/StringTypeTag.scala +++ b/internal/util-logging/src/main/scala/sbt/internal/util/StringTypeTag.scala @@ -8,13 +8,29 @@ final case class StringTypeTag[A](key: String) { } 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 apply[A: TypeTag]: StringTypeTag[A] = + synchronized { + def doApply: StringTypeTag[A] = { + val tag = implicitly[TypeTag[A]] + val tpe = tag.tpe + val k = typeToString(tpe) + // println(tpe.getClass.toString + " " + k) + StringTypeTag[A](k) + } + def retry(n: Int): StringTypeTag[A] = + try { + doApply + } catch { + case e: NullPointerException => + if (n < 1) throw new RuntimeException("NPE in StringTypeTag", e) + else { + Thread.sleep(1) + retry(n - 1) + } + } + retry(3) + } + def typeToString(tpe: Type): String = tpe match { case TypeRef(_, sym, args) => diff --git a/internal/util-logging/src/main/scala/sbt/util/LogExchange.scala b/internal/util-logging/src/main/scala/sbt/util/LogExchange.scala index ba3114643..0c35c98ee 100644 --- a/internal/util-logging/src/main/scala/sbt/util/LogExchange.scala +++ b/internal/util-logging/src/main/scala/sbt/util/LogExchange.scala @@ -8,6 +8,7 @@ import org.apache.logging.log4j.core.config.{ AppenderRef, LoggerConfig } import org.apache.logging.log4j.core.layout.PatternLayout import scala.collection.JavaConverters._ import scala.collection.concurrent +import scala.reflect.runtime.universe.TypeTag import sjsonnew.JsonFormat // http://logging.apache.org/log4j/2.x/manual/customconfig.html @@ -15,6 +16,7 @@ import sjsonnew.JsonFormat 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] val jsonCodecs: concurrent.Map[String, JsonFormat[_]] = concurrent.TrieMap() private[sbt] val stringCodecs: concurrent.Map[String, ShowLines[_]] = concurrent.TrieMap() @@ -22,6 +24,7 @@ sealed abstract class LogExchange { 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( @@ -57,6 +60,16 @@ sealed abstract class LogExchange { config.getLoggerConfig(loggerName) } + private[sbt] def initStringCodecs(): Unit = { + import sbt.internal.util.codec.ThrowableShowLines._ + import sbt.internal.util.codec.TraceEventShowLines._ + import sbt.internal.util.codec.SuccessEventShowLines._ + + registerStringCodec[Throwable] + registerStringCodec[TraceEvent] + registerStringCodec[SuccessEvent] + } + // This is a dummy layout to avoid casting error during PatternLayout.createDefaultLayout() // that was originally used for ConsoleAppender. // The stacktrace shows it's having issue initializing default DefaultConfiguration. @@ -85,6 +98,12 @@ sealed abstract class LogExchange { def getOrElseUpdateStringCodec[A](tag: String, v: ShowLines[A]): ShowLines[A] = stringCodecs.getOrElseUpdate(tag, v).asInstanceOf[ShowLines[A]] + def registerStringCodec[A: ShowLines: TypeTag]: Unit = { + val tag = StringTypeTag[A] + val ev = implicitly[ShowLines[A]] + val _ = getOrElseUpdateStringCodec(tag.key, ev) + } + private[sbt] def buildAsyncStdout: AsyncAppender = { val ctx = XLogManager.getContext(false) match { case x: LoggerContext => x } val config = ctx.getConfiguration diff --git a/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala b/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala index 40601f1c4..8e9c905e1 100644 --- a/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala +++ b/internal/util-logging/src/test/scala/ManagedLoggerSpec.scala @@ -20,6 +20,13 @@ class ManagedLoggerSpec extends FlatSpec with Matchers { log.infoEvent(1) } + 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)) + log.infoEvent(SuccessEvent("yes")) + } + it should "allow registering Show[Int]" in { import sjsonnew.BasicJsonProtocol._ val log = LogExchange.logger("foo") @@ -52,9 +59,7 @@ class ManagedLoggerSpec extends FlatSpec with Matchers { it should "be thread safe" in { import java.util.concurrent.{ Executors, TimeUnit } - import sjsonnew.BasicJsonProtocol._ val pool = Executors.newFixedThreadPool(100) - for { i <- 1 to 10000 } { From 32412e4625659547a1761b7274eebc5ce7f1056a Mon Sep 17 00:00:00 2001 From: Eugene Yokota Date: Sat, 26 Aug 2017 13:13:04 -0400 Subject: [PATCH 3/3] Use sbt 1.0.0 --- build.sbt | 2 +- project/build.properties | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/build.sbt b/build.sbt index 75189bece..24db64b6d 100644 --- a/build.sbt +++ b/build.sbt @@ -32,7 +32,7 @@ def commonSettings: Seq[Setting[_]] = Seq( val mimaSettings = Def settings ( mimaPreviousArtifacts := Set( - organization.value % moduleName.value % "1.0.0-RC3" + organization.value % moduleName.value % "1.0.0" cross (if (crossPaths.value) CrossVersion.binary else CrossVersion.disabled) ) ) diff --git a/project/build.properties b/project/build.properties index 12c38d389..94005e587 100644 --- a/project/build.properties +++ b/project/build.properties @@ -1 +1 @@ -sbt.version=1.0.0-RC3 +sbt.version=1.0.0