diff --git a/main/src/main/scala/sbt/Defaults.scala b/main/src/main/scala/sbt/Defaults.scala index 243f10602..eaf771149 100644 --- a/main/src/main/scala/sbt/Defaults.scala +++ b/main/src/main/scala/sbt/Defaults.scala @@ -27,6 +27,7 @@ import sbt.ScopeAxis.{ Select, This, Zero } import sbt.State.StateOpsImpl import sbt.coursierint.* import sbt.internal.CommandStrings.ExportStream +import sbt.internal.CompileDebugLogger import sbt.internal.* import sbt.internal.classpath.AlternativeZincUtil import sbt.internal.inc.JavaInterfaceUtil.* @@ -2217,9 +2218,16 @@ object Defaults extends BuildCommon { ) ) + private def projectIdFromScope(s: TaskStreams): String = + s.key.scope.project match { + case Select(ref: ProjectRef) => ref.project + case _ => "root" + } + private val cachedCompileIncrementalTask = Def .cachedTask { val s = streams.value + val projectId = projectIdFromScope(s) val ci = (compile / compileInputs).value val bspTask = (compile / bspCompileTask).value // This is a cacheable version @@ -2229,7 +2237,7 @@ object Defaults extends BuildCommon { val store = analysisStore(compileAnalysisFile) val c = fileConverter.value // TODO - Should readAnalysis + saveAnalysis be scoped by the compile task too? - val analysisResult = Retry.io(compileIncrementalTaskImpl(bspTask, s, ci, ping)) + val analysisResult = Retry.io(compileIncrementalTaskImpl(bspTask, s, ci, ping, projectId)) val analysisOut = c.toVirtualFile(setup.cachePath()) val contents = AnalysisContents.create(analysisResult.analysis(), analysisResult.setup()) store.set(contents) @@ -2245,15 +2253,17 @@ object Defaults extends BuildCommon { private val incCompiler = ZincUtil.defaultIncrementalCompiler private[sbt] def compileJavaTask: Initialize[Task[CompileResult]] = Def.task { val s = streams.value + val projectId = thisProject.value.id val r = compileScalaBackend.value val in0 = (compileJava / compileInputs).value val in = in0.withPreviousResult(PreviousResult.of(r.analysis, r.setup)) val reporter = (compile / bspReporter).value + val log = CompileDebugLogger(projectId, s.log) try { if (r.hasModified) { val result0 = incCompiler .asInstanceOf[sbt.internal.inc.IncrementalCompilerImpl] - .compileAllJava(in, s.log) + .compileAllJava(in, log) reporter.sendSuccessReport(result0.analysis()) result0.withHasModified(result0.hasModified || r.hasModified) } else r @@ -2268,7 +2278,8 @@ object Defaults extends BuildCommon { task: BspCompileTask, s: TaskStreams, ci: Inputs, - promise: PromiseWrap[Boolean] + promise: PromiseWrap[Boolean], + projectId: String ): CompileResult = { lazy val x = s.text(ExportStream) def onArgs(cs: Compilers) = @@ -2283,7 +2294,8 @@ object Defaults extends BuildCommon { val compilers: Compilers = ci.compilers val setup: Setup = ci.setup val i = ci.withCompilers(onArgs(compilers)).withSetup(onProgress(setup)) - try incCompiler.compile(i, s.log) + val log = CompileDebugLogger(projectId, s.log) + try incCompiler.compile(i, log) catch case e: Throwable => if !promise.isCompleted then diff --git a/main/src/main/scala/sbt/internal/CompileDebugLogger.scala b/main/src/main/scala/sbt/internal/CompileDebugLogger.scala new file mode 100644 index 000000000..a3fc26268 --- /dev/null +++ b/main/src/main/scala/sbt/internal/CompileDebugLogger.scala @@ -0,0 +1,39 @@ +/* + * sbt + * Copyright 2023, Scala center + * Copyright 2011 - 2022, Lightbend, Inc. + * Copyright 2008 - 2010, Mark Harrah + * Licensed under Apache License 2.0 (see LICENSE) + */ + +package sbt.internal + +import java.util.function.Supplier +import sbt.util.{ Level, Logger } + +/** + * Wraps a Logger and prefixes info and debug messages with a tag (e.g. project id). + * Used so that incremental compiler output (e.g. "compiling X sources", invalidations) + * can be attributed to a project in multi-project builds (fixes #408). + */ +private[sbt] object CompileDebugLogger { + def apply(prefix: String, delegate: Logger): Logger = + new Logger { + private def prefixed(msg: String): String = + if (msg == null || msg.isEmpty) s"[$prefix]" + else s"[$prefix] $msg" + + override def log(level: Level.Value, message: => String): Unit = + if (level == Level.Debug || level == Level.Info) + delegate.log(level, prefixed(message)) + else delegate.log(level, message) + + override def log(level: Level.Value, msg: Supplier[String]): Unit = + if (level == Level.Debug || level == Level.Info) + delegate.log(level, () => prefixed(msg.get())) + else delegate.log(level, msg) + + def trace(t: => Throwable): Unit = delegate.trace(t) + def success(message: => String): Unit = delegate.success(message) + } +} diff --git a/main/src/test/scala/sbt/internal/CompileDebugLoggerSpec.scala b/main/src/test/scala/sbt/internal/CompileDebugLoggerSpec.scala new file mode 100644 index 000000000..72b0c85ce --- /dev/null +++ b/main/src/test/scala/sbt/internal/CompileDebugLoggerSpec.scala @@ -0,0 +1,54 @@ +/* + * sbt + * Copyright 2023, Scala center + * Copyright 2011 - 2022, Lightbend, Inc. + * Copyright 2008 - 2010, Mark Harrah + * Licensed under Apache License 2.0 (see LICENSE) + */ + +package sbt.internal + +import java.util.concurrent.CopyOnWriteArrayList +import scala.jdk.CollectionConverters.* +import sbt.util.{ Level, Logger } + +object CompileDebugLoggerSpec extends verify.BasicTestSuite { + + test("CompileDebugLogger prefixes debug and info messages with project id (#408)") { + val messages = new CopyOnWriteArrayList[(Level.Value, String)]() + val delegate: Logger = new Logger { + def log(level: Level.Value, message: => String): Unit = + if (level == Level.Debug || level == Level.Info) messages.add((level, message)) + def trace(t: => Throwable): Unit = () + def success(message: => String): Unit = () + } + val prefixed = CompileDebugLogger("myProject", delegate) + prefixed.debug("Initial source changes: ") + prefixed.debug("removed:Set()") + prefixed.info("compiling 1 Scala source to ...") + assert(messages.size() >= 3) + assert(messages.get(0) == (Level.Debug, "[myProject] Initial source changes: ")) + assert(messages.get(1) == (Level.Debug, "[myProject] removed:Set()")) + assert(messages.get(2) == (Level.Info, "[myProject] compiling 1 Scala source to ...")) + } + + test("CompileDebugLogger does not prefix warn/error") { + val allMessages = new CopyOnWriteArrayList[(Level.Value, String)]() + val delegate: Logger = new Logger { + def log(level: Level.Value, message: => String): Unit = + allMessages.add((level, message)) + def trace(t: => Throwable): Unit = () + def success(message: => String): Unit = () + } + val prefixed = CompileDebugLogger("p", delegate) + prefixed.debug("debug msg") + prefixed.info("info msg") + prefixed.warn("warn msg") + prefixed.error("error msg") + val list = allMessages.asScala.toSeq + val prefixedLevels = list.filter { case (_, msg) => msg.startsWith("[p] ") }.map(_._1) + val notPrefixed = list.filter { case (_, msg) => !msg.startsWith("[p] ") } + assert(prefixedLevels.forall(l => l == Level.Debug || l == Level.Info)) + assert(notPrefixed.map(_._1).forall(l => l == Level.Warn || l == Level.Error)) + } +} diff --git a/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/a/src/main/scala/A.scala b/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/a/src/main/scala/A.scala new file mode 100644 index 000000000..c636727e7 --- /dev/null +++ b/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/a/src/main/scala/A.scala @@ -0,0 +1 @@ +object A { def value: Int = 1 } diff --git a/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/b/src/main/scala/B.scala b/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/b/src/main/scala/B.scala new file mode 100644 index 000000000..837d74e9e --- /dev/null +++ b/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/b/src/main/scala/B.scala @@ -0,0 +1 @@ +object B { def use: Int = A.value } diff --git a/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/build.sbt b/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/build.sbt new file mode 100644 index 000000000..fc9604be3 --- /dev/null +++ b/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/build.sbt @@ -0,0 +1,16 @@ +// #408: incremental compile debug output should indicate project in multi-project builds. +// project/build.properties uses sbt 2.0.0-RC9-bin-SNAPSHOT so scripted runs with the built sbt, +// where CompileDebugLogger prefixes debug/info lines with [projectId] (e.g. [a], [b]). +scalaVersion := "2.12.21" +resolvers += Resolver.mavenLocal + +lazy val root = (project in file(".")) + .aggregate(a, b) + .settings(name := "root") + +lazy val a = (project in file("a")) + .settings(name := "a") + +lazy val b = (project in file("b")) + .dependsOn(a) + .settings(name := "b") diff --git a/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/modified/A_scala b/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/modified/A_scala new file mode 100644 index 000000000..6e0a06ee6 --- /dev/null +++ b/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/modified/A_scala @@ -0,0 +1,2 @@ +object A { def value: Int = 1 } +// trigger incremental diff --git a/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/modified/B_scala b/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/modified/B_scala new file mode 100644 index 000000000..91962cca4 --- /dev/null +++ b/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/modified/B_scala @@ -0,0 +1,2 @@ +object B { def use: Int = A.value } +// trigger incremental diff --git a/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/test b/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/test new file mode 100644 index 000000000..86cc51697 --- /dev/null +++ b/sbt-app/src/sbt-test/tests/i408-debug-invalidation-prefix/test @@ -0,0 +1,13 @@ +# #408: With logLevel Debug, incremental compile debug output should show project id per block. +# project/build.properties sets sbt.version=2.0.0-RC9-bin-SNAPSHOT so scripted runs built sbt. +# First compile (full), then change sources and compile again to trigger incremental compilation +# so Zinc emits debug lines (Initial source changes, changed = Set(...), invalidated, etc.) +# with our projectId prefix. See HOWTO-SEE-PROJECT-ID.md to view the logs. + +> set ThisBuild / logLevel := Level.Debug +> a/compile +> b/compile +$ copy-file modified/A_scala a/src/main/scala/A.scala +$ copy-file modified/B_scala b/src/main/scala/B.scala +> a/compile +> b/compile \ No newline at end of file diff --git a/scripted-sbt/src/main/scala/sbt/scriptedtest/ScriptedTests.scala b/scripted-sbt/src/main/scala/sbt/scriptedtest/ScriptedTests.scala index 4c81e47b9..3750163ea 100644 --- a/scripted-sbt/src/main/scala/sbt/scriptedtest/ScriptedTests.scala +++ b/scripted-sbt/src/main/scala/sbt/scriptedtest/ScriptedTests.scala @@ -347,7 +347,10 @@ final class ScriptedTests( log.clear() log.error(" Pending test passed. Mark as passing to remove this failure.") Some(label) - } else None + } else { + log.play() + None + } } } }