Use a macro to create StringTypeTag instances

Using the scala reflect library always introduces significant
classloading overhead. We can eliminate the classloading overhead by
generating StringTypeTags at compile time instead.

This sped up average project loading time by a few hundred milliseconds
on my computer. The ManagedLoggedReporter in zinc is still using the
type tag based apis but after the next sbt release, we can upgrade the
zinc apis. We also could consider breaking binary compatibility.
This commit is contained in:
Ethan Atkins 2020-07-29 14:55:19 -07:00
parent 20f725c73c
commit 6c50a85f93
9 changed files with 102 additions and 30 deletions

View File

@ -359,7 +359,7 @@ lazy val utilPosition = (project in file("internal") / "util-position")
lazy val utilLogging = (project in file("internal") / "util-logging") lazy val utilLogging = (project in file("internal") / "util-logging")
.enablePlugins(ContrabandPlugin, JsonCodecPlugin) .enablePlugins(ContrabandPlugin, JsonCodecPlugin)
.dependsOn(utilInterface, collectionProj) .dependsOn(utilInterface, collectionProj, coreMacrosProj)
.settings( .settings(
utilCommonSettings, utilCommonSettings,
name := "Util Logging", name := "Util Logging",
@ -781,7 +781,7 @@ lazy val commandProj = (project in file("main-command"))
lazy val coreMacrosProj = (project in file("core-macros")) lazy val coreMacrosProj = (project in file("core-macros"))
.dependsOn(collectionProj) .dependsOn(collectionProj)
.settings( .settings(
baseSettings, baseSettings :+ (crossScalaVersions := (scala212 :: scala213 :: Nil)),
name := "Core Macros", name := "Core Macros",
libraryDependencies += "org.scala-lang" % "scala-compiler" % scalaVersion.value, libraryDependencies += "org.scala-lang" % "scala-compiler" % scalaVersion.value,
mimaSettings, mimaSettings,

View File

@ -0,0 +1,27 @@
/*
* sbt
* Copyright 2011 - 2018, Lightbend, Inc.
* Copyright 2008 - 2010, Mark Harrah
* Licensed under Apache License 2.0 (see LICENSE)
*/
package sbt.internal.util.appmacro
import scala.reflect.macros.blackbox
object StringTypeTag {
def impl[A: c.WeakTypeTag](c: blackbox.Context): c.Tree = {
import c.universe._
val tpe = weakTypeOf[A]
def typeToString(tpe: Type): String = tpe match {
case TypeRef(_, sym, args) if args.nonEmpty =>
val typeCon = tpe.typeSymbol.fullName
val typeArgs = args map typeToString
s"""$typeCon[${typeArgs.mkString(",")}]"""
case _ => tpe.toString
}
val key = Literal(Constant(typeToString(tpe)))
q"new sbt.internal.util.StringTypeTag[$tpe]($key)"
}
}

View File

@ -7,12 +7,12 @@
package sbt.internal.util package sbt.internal.util
import sbt.util._
import org.apache.logging.log4j.{ Logger => XLogger } import org.apache.logging.log4j.{ Logger => XLogger }
import org.apache.logging.log4j.message.ObjectMessage import org.apache.logging.log4j.message.ObjectMessage
import sjsonnew.JsonFormat
import scala.reflect.runtime.universe.TypeTag
import sbt.internal.util.codec.JsonProtocol._ import sbt.internal.util.codec.JsonProtocol._
import sbt.util._
import scala.reflect.runtime.universe.TypeTag
import sjsonnew.JsonFormat
/** /**
* Delegates log events to the associated LogExchange. * Delegates log events to the associated LogExchange.
@ -35,29 +35,53 @@ class ManagedLogger(
) )
} }
private lazy val SuccessEventTag = scala.reflect.runtime.universe.typeTag[SuccessEvent]
// send special event for success since it's not a real log level // send special event for success since it's not a real log level
override def success(message: => String): Unit = { override def success(message: => String): Unit = {
if (terminal.fold(true)(_.isSuccessEnabled)) { if (terminal.fold(true)(_.isSuccessEnabled)) {
infoEvent[SuccessEvent](SuccessEvent(message))( infoEvent[SuccessEvent](SuccessEvent(message))(
implicitly[JsonFormat[SuccessEvent]], implicitly[JsonFormat[SuccessEvent]],
SuccessEventTag StringTypeTag.fast[SuccessEvent],
) )
} }
} }
def registerStringCodec[A: ShowLines: TypeTag]: Unit = { @deprecated("Use macro-powered StringTypeTag.fast instead", "1.4.0")
def registerStringCodec[A](
s: ShowLines[A],
tt: scala.reflect.runtime.universe.TypeTag[A]
): Unit = {
LogExchange.registerStringCodec[A](s, tt)
}
def registerStringCodec[A: ShowLines: StringTypeTag]: Unit = {
LogExchange.registerStringCodec[A] LogExchange.registerStringCodec[A]
} }
final def debugEvent[A: JsonFormat: TypeTag](event: => A): Unit = logEvent(Level.Debug, event) @deprecated("Use macro-powered StringTypeTag.fast instead", "1.4.0")
final def infoEvent[A: JsonFormat: TypeTag](event: => A): Unit = logEvent(Level.Info, event) final def debugEvent[A](event: => A, f: JsonFormat[A], t: TypeTag[A]): Unit =
final def warnEvent[A: JsonFormat: TypeTag](event: => A): Unit = logEvent(Level.Warn, event) debugEvent(event)(f, StringTypeTag.apply(t))
final def errorEvent[A: JsonFormat: TypeTag](event: => A): Unit = logEvent(Level.Error, event) @deprecated("Use macro-powered StringTypeTag.fast instead", "1.4.0")
def logEvent[A: JsonFormat: TypeTag](level: Level.Value, event: => A): Unit = { final def infoEvent[A](event: => A, f: JsonFormat[A], t: TypeTag[A]): Unit =
infoEvent(event)(f, StringTypeTag.apply(t))
@deprecated("Use macro-powered StringTypeTag.fast instead", "1.4.0")
final def warnEvent[A](event: => A, f: JsonFormat[A], t: TypeTag[A]): Unit =
warnEvent(event)(f, StringTypeTag.apply(t))
@deprecated("Use macro-powered StringTypeTag.fast instead", "1.4.0")
final def errorEvent[A](event: => A, f: JsonFormat[A], t: TypeTag[A]): Unit =
errorEvent(event)(f, StringTypeTag.apply(t))
final def debugEvent[A: JsonFormat: StringTypeTag](event: => A): Unit =
logEvent(Level.Debug, event)
final def infoEvent[A: JsonFormat: StringTypeTag](event: => A): Unit = logEvent(Level.Info, event)
final def warnEvent[A: JsonFormat: StringTypeTag](event: => A): Unit = logEvent(Level.Warn, event)
final def errorEvent[A: JsonFormat: StringTypeTag](event: => A): Unit =
logEvent(Level.Error, event)
@deprecated("Use macro-powered StringTypeTag.fast instead", "1.4.0")
def logEvent[A](level: Level.Value, event: => A, f: JsonFormat[A], t: TypeTag[A]): Unit =
logEvent(level, event)(f, StringTypeTag.apply(t))
def logEvent[A: JsonFormat](level: Level.Value, event: => A)(
implicit tag: StringTypeTag[A]
): Unit = {
val v: A = event val v: A = event
val tag = StringTypeTag[A]
LogExchange.getOrElseUpdateJsonCodec(tag.key, implicitly[JsonFormat[A]])
// println("logEvent " + tag.key) // println("logEvent " + tag.key)
val entry: ObjectEvent[A] = ObjectEvent(level, v, channelName, execId, tag.key) val entry: ObjectEvent[A] = ObjectEvent(level, v, channelName, execId, tag.key)
xlogger.log( xlogger.log(

View File

@ -7,6 +7,7 @@
package sbt.internal.util package sbt.internal.util
import scala.language.experimental.macros
import scala.reflect.runtime.universe._ import scala.reflect.runtime.universe._
/** This is used to carry type information in JSON. */ /** This is used to carry type information in JSON. */
@ -15,6 +16,10 @@ final case class StringTypeTag[A](key: String) {
} }
object StringTypeTag { object StringTypeTag {
/** Generates a StringTypeTag for any type at compile time. */
implicit def fast[A]: StringTypeTag[A] = macro appmacro.StringTypeTag.impl[A]
@deprecated("Prefer macro generated StringTypeTag", "1.4.0")
def apply[A: TypeTag]: StringTypeTag[A] = def apply[A: TypeTag]: StringTypeTag[A] =
synchronized { synchronized {
def doApply: StringTypeTag[A] = { def doApply: StringTypeTag[A] = {
@ -38,6 +43,7 @@ object StringTypeTag {
retry(3) retry(3)
} }
@deprecated("Prefer macro generated StringTypeTag", "1.4.0")
def typeToString(tpe: Type): String = def typeToString(tpe: Type): String =
tpe match { tpe match {
case TypeRef(_, sym, args) => case TypeRef(_, sym, args) =>

View File

@ -15,7 +15,6 @@ import org.apache.logging.log4j.core.config.{ AppenderRef, LoggerConfig }
import org.apache.logging.log4j.core.layout.PatternLayout import org.apache.logging.log4j.core.layout.PatternLayout
import scala.collection.JavaConverters._ import scala.collection.JavaConverters._
import scala.collection.concurrent import scala.collection.concurrent
import scala.reflect.runtime.universe.TypeTag
import sjsonnew.JsonFormat import sjsonnew.JsonFormat
// http://logging.apache.org/log4j/2.x/manual/customconfig.html // http://logging.apache.org/log4j/2.x/manual/customconfig.html
@ -114,9 +113,15 @@ sealed abstract class LogExchange {
def getOrElseUpdateStringCodec[A](tag: String, v: ShowLines[A]): ShowLines[A] = def getOrElseUpdateStringCodec[A](tag: String, v: ShowLines[A]): ShowLines[A] =
stringCodecs.getOrElseUpdate(tag, v).asInstanceOf[ShowLines[A]] stringCodecs.getOrElseUpdate(tag, v).asInstanceOf[ShowLines[A]]
def registerStringCodec[A: ShowLines: TypeTag]: Unit = { @deprecated("Prefer macro based registerStringCodec", "1.4.0")
val tag = StringTypeTag[A] def registerStringCodec[A](
registerStringCodecByStringTypeTag(tag) st: ShowLines[A],
tt: scala.reflect.runtime.universe.TypeTag[A]
): Unit = {
registerStringCodecByStringTypeTag(StringTypeTag.apply[A](tt))(st)
}
private[sbt] def registerStringCodec[A: ShowLines: StringTypeTag]: Unit = {
registerStringCodecByStringTypeTag(implicitly[StringTypeTag[A]])
} }
private[sbt] def registerStringCodecByStringTypeTag[A: ShowLines](tag: StringTypeTag[A]): Unit = { private[sbt] def registerStringCodecByStringTypeTag[A: ShowLines](tag: StringTypeTag[A]): Unit = {

View File

@ -14,9 +14,17 @@ import org.scalatest._
class LogExchangeSpec extends FlatSpec with Matchers { class LogExchangeSpec extends FlatSpec with Matchers {
import LogExchange._ import LogExchange._
checkTypeTag("stringTypeTagThrowable", stringTypeTagThrowable, StringTypeTag[Throwable]) checkTypeTag("stringTypeTagThrowable", stringTypeTagThrowable, StringTypeTag.fast[Throwable])
checkTypeTag("stringTypeTagTraceEvent", stringTypeTagTraceEvent, StringTypeTag[TraceEvent]) checkTypeTag(
checkTypeTag("stringTypeTagSuccessEvent", stringTypeTagSuccessEvent, StringTypeTag[SuccessEvent]) "stringTypeTagTraceEvent",
stringTypeTagTraceEvent,
StringTypeTag.fast[TraceEvent]
)
checkTypeTag(
"stringTypeTagSuccessEvent",
stringTypeTagSuccessEvent,
StringTypeTag.fast[SuccessEvent]
)
private def checkTypeTag[A](name: String, inc: StringTypeTag[A], exp: StringTypeTag[A]): Unit = private def checkTypeTag[A](name: String, inc: StringTypeTag[A], exp: StringTypeTag[A]): Unit =
s"LogExchange.$name" should s"match real StringTypeTag[$exp]" in { s"LogExchange.$name" should s"match real StringTypeTag[$exp]" in {

View File

@ -84,7 +84,7 @@ class ManagedLoggerSpec extends FlatSpec with Matchers {
} { } {
pool.submit(new Runnable { pool.submit(new Runnable {
def run(): Unit = { def run(): Unit = {
val stringTypeTag = StringTypeTag[List[Int]] val stringTypeTag = StringTypeTag.fast[List[Int]]
val log = LogExchange.logger(s"foo$i") val log = LogExchange.logger(s"foo$i")
LogExchange.bindLoggerAppenders(s"foo$i", List(LogExchange.asyncStdout -> Level.Info)) LogExchange.bindLoggerAppenders(s"foo$i", List(LogExchange.asyncStdout -> Level.Info))
if (i % 100 == 0) { if (i % 100 == 0) {

View File

@ -14,7 +14,6 @@ import java.util.concurrent.{ ExecutorService, Executors }
import ClassLoaderClose.close import ClassLoaderClose.close
import sbt.plugins.{ CorePlugin, IvyPlugin, JvmPlugin } import sbt.plugins.{ CorePlugin, IvyPlugin, JvmPlugin }
import sbt.util.LogExchange
import xsbti._ import xsbti._
private[internal] object ClassLoaderWarmup { private[internal] object ClassLoaderWarmup {
@ -29,7 +28,6 @@ private[internal] object ClassLoaderWarmup {
() ()
} }
submit(LogExchange.context)
submit(Class.forName("sbt.internal.parser.SbtParserInit").getConstructor().newInstance()) submit(Class.forName("sbt.internal.parser.SbtParserInit").getConstructor().newInstance())
submit(CorePlugin.projectSettings) submit(CorePlugin.projectSettings)
submit(IvyPlugin.projectSettings) submit(IvyPlugin.projectSettings)

View File

@ -11,7 +11,7 @@ import java.io.File
import sbt.StandardMain import sbt.StandardMain
import sbt.internal.bsp._ import sbt.internal.bsp._
import sbt.internal.inc.ManagedLoggedReporter import sbt.internal.inc.LoggedReporter
import sbt.internal.util.ManagedLogger import sbt.internal.util.ManagedLogger
import xsbti.{ Problem, Severity, Position => XPosition } import xsbti.{ Problem, Severity, Position => XPosition }
@ -30,7 +30,11 @@ class BuildServerReporter(
logger: ManagedLogger, logger: ManagedLogger,
sourcePositionMapper: XPosition => XPosition = identity[XPosition], sourcePositionMapper: XPosition => XPosition = identity[XPosition],
sources: Seq[File] sources: Seq[File]
) extends ManagedLoggedReporter(maximumErrors, logger, sourcePositionMapper) { ) extends LoggedReporter(maximumErrors, logger, sourcePositionMapper) {
import LoggedReporter.problemFormats._
import LoggedReporter.problemStringFormats._
logger.registerStringCodec[Problem]
import sbt.internal.bsp.codec.JsonProtocol._ import sbt.internal.bsp.codec.JsonProtocol._
import sbt.internal.inc.JavaInterfaceUtil._ import sbt.internal.inc.JavaInterfaceUtil._
@ -55,21 +59,21 @@ class BuildServerReporter(
publishDiagnostic(problem) publishDiagnostic(problem)
// console channel can keep using the xsbi.Problem // console channel can keep using the xsbi.Problem
super.logError(problem) logger.errorEvent(problem)
} }
override def logWarning(problem: Problem): Unit = { override def logWarning(problem: Problem): Unit = {
publishDiagnostic(problem) publishDiagnostic(problem)
// console channel can keep using the xsbi.Problem // console channel can keep using the xsbi.Problem
super.logWarning(problem) logger.warnEvent(problem)
} }
override def logInfo(problem: Problem): Unit = { override def logInfo(problem: Problem): Unit = {
publishDiagnostic(problem) publishDiagnostic(problem)
// console channel can keep using the xsbi.Problem // console channel can keep using the xsbi.Problem
super.logInfo(problem) logger.infoEvent(problem)
} }
private def publishDiagnostic(problem: Problem): Unit = { private def publishDiagnostic(problem: Problem): Unit = {