diff --git a/main/src/main/scala/sbt/Keys.scala b/main/src/main/scala/sbt/Keys.scala index 082abdb36..aba00c4b2 100644 --- a/main/src/main/scala/sbt/Keys.scala +++ b/main/src/main/scala/sbt/Keys.scala @@ -727,6 +727,8 @@ object Keys { } private[sbt] val currentCommandProgress = AttributeKey[ExecuteProgress2]("current-command-progress") private[sbt] val taskProgress = AttributeKey[sbt.internal.TaskProgress]("active-task-progress") + private[sbt] val resolutionProgress = + AttributeKey[sbt.coursierint.ResolutionProgress]("resolution-progress", Invisible) val useSuperShell = settingKey[Boolean]("Enables (true) or disables the super shell.") val superShellMaxTasks = settingKey[Int]("The max number of tasks to display in the supershell progress report") val superShellSleep = settingKey[FiniteDuration]("The minimum duration to sleep between progress reports") diff --git a/main/src/main/scala/sbt/MainLoop.scala b/main/src/main/scala/sbt/MainLoop.scala index 955cd50f1..7814a74ae 100644 --- a/main/src/main/scala/sbt/MainLoop.scala +++ b/main/src/main/scala/sbt/MainLoop.scala @@ -168,11 +168,13 @@ private[sbt] object MainLoop: state.get(Keys.superShellSleep.key).getOrElse(SysProp.supershellSleep.millis) val superShellThreshold = state.get(Keys.superShellThreshold.key).getOrElse(SysProp.supershellThreshold) + val resolutionProgress = new sbt.coursierint.ResolutionProgress val taskProgress = new TaskProgress( superShellSleep, superShellThreshold, state.log, + resolutionProgress, Project.configNameToIdent(state) ) val gcMonitor = if (SysProp.gcMonitor) Some(new sbt.internal.GCMonitor(state.log)) else None @@ -181,6 +183,7 @@ private[sbt] object MainLoop: state .put(Keys.loggerContext, context) .put(Keys.taskProgress, taskProgress) + .put(Keys.resolutionProgress, resolutionProgress) .process(processCommand) } match { case Right(s) => s.remove(Keys.loggerContext) diff --git a/main/src/main/scala/sbt/coursierint/LMCoursier.scala b/main/src/main/scala/sbt/coursierint/LMCoursier.scala index c63df19f2..3825617e5 100644 --- a/main/src/main/scala/sbt/coursierint/LMCoursier.scala +++ b/main/src/main/scala/sbt/coursierint/LMCoursier.scala @@ -255,7 +255,17 @@ object LMCoursier { def coursierLoggerTask: Def.Initialize[Task[Option[CacheLogger]]] = Def.task { val st = Keys.streams.value val progress = (ThisBuild / useSuperShell).value - if (progress) None + // Always supply a logger: this suppresses coursier's own per-module progress bar and lets + // resolution run in parallel across modules. Under the super shell we feed the per-command + // resolution-progress sink (rendered as one task-level line by TaskProgress); otherwise the + // quiet debug logger. + if (progress) + Some( + Keys.state.value + .get(Keys.resolutionProgress) + .map(new ResolutionProgressLogger(_)) + .getOrElse(CacheLogger.nop) + ) else Some(new CoursierLogger(st.log)) } diff --git a/main/src/main/scala/sbt/coursierint/ResolutionProgress.scala b/main/src/main/scala/sbt/coursierint/ResolutionProgress.scala new file mode 100644 index 000000000..5d5f2b592 --- /dev/null +++ b/main/src/main/scala/sbt/coursierint/ResolutionProgress.scala @@ -0,0 +1,112 @@ +/* + * 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 +package coursierint + +import java.util.concurrent.ConcurrentHashMap +import java.util.concurrent.atomic.{ AtomicInteger, AtomicLong } +import lmcoursier.definitions.CacheLogger + +/** + * Per-command running total of dependency-resolution progress. + * + * One instance is created per command in `MainLoop.next` (held under `Keys.resolutionProgress`, the + * same lifecycle as `Keys.taskProgress`). It is fed by [[ResolutionProgressLogger]] from coursier's + * download-pool threads and read by `TaskProgress` to render a single super-shell line. + * + * The counting model matches how coursier actually drives a `CacheLogger`: + * - `init`/`stop` arrive once per logger session — one per configuration resolution and one per + * artifacts run, plus network retries — NOT once per module, so no module count is reported; + * `inFlight` only controls when the line is visible. + * - `foundLocally`/`downloadedArtifact` fire on every cache check, repeating the same url across + * sessions and including checksum companions, so files are counted as distinct urls with + * checksum/signature companions excluded. + * - `downloadProgress` carries a cumulative per-url byte count; byte accounting takes a monotonic + * per-url delta and so can never double-count or go backwards. + * + * There is no cross-command reset: the instance is born empty and discarded with the command. + */ +private[sbt] final class ResolutionProgress { + private val inFlight = new AtomicInteger(0) + private val burstStartNanos = new AtomicLong(System.nanoTime()) + private val files = ConcurrentHashMap.newKeySet[String] + private val bytes = new AtomicLong(0L) + private val seen = new ConcurrentHashMap[String, java.lang.Long] + + def onInit(): Unit = { + val now = System.nanoTime() + // 0 -> 1 starts a new burst (e.g. the artifacts phase after an idle gap): restart the clock. + if (inFlight.getAndIncrement() == 0) burstStartNanos.set(now) + () + } + + def onStop(): Unit = { + inFlight.updateAndGet(n => math.max(0, n - 1)) + () + } + + def onFile(url: String): Unit = { + if (!ResolutionProgress.isChecksumLike(url)) files.add(url) + () + } + + def onProgress(url: String, downloaded: Long): Unit = { + // compute keeps the read-compare-add atomic per url, so concurrent progress callbacks for the + // same url can neither double-count nor lose a byte delta; `seen` always holds the max seen. + seen.compute( + url, + (_: String, prev: java.lang.Long) => { + val p: Long = if (prev == null) 0L else prev.longValue + if (downloaded > p) bytes.addAndGet(downloaded - p) + java.lang.Long.valueOf(math.max(downloaded, p)) + } + ) + () + } + + /** + * While at least one resolution is in flight: the render line plus the elapsed micros of the + * current burst (the super shell appends elapsed to every item, so this renders as a live + * counter). Else None (the line disappears). + */ + def snapshot(): Option[(String, Long)] = + if (inFlight.get() <= 0) None + else { + val n = files.size() + val mib = bytes.get().toDouble / (1024.0 * 1024.0) + val label = if (n == 1) "file" else "files" + val elapsedMicros = math.max(0L, (System.nanoTime() - burstStartNanos.get()) / 1000L) + Some((f"downloading $n $label, $mib%.1f MiB", elapsedMicros)) + } +} + +private[sbt] object ResolutionProgress { + // Checksum/signature companions go through the same cache callbacks as real files; counting + // them would roughly double the file count. + private val checksumLikeSuffixes = Seq(".sha1", ".sha256", ".sha512", ".md5", ".asc", ".sig") + private[coursierint] def isChecksumLike(url: String): Boolean = { + val lower = url.toLowerCase(java.util.Locale.ROOT) + checksumLikeSuffixes.exists(s => lower.endsWith(s)) + } +} + +/** + * A coursier `CacheLogger` that feeds a per-command [[ResolutionProgress]]. Supplying any logger to + * lm-coursier suppresses coursier's own per-module progress bar and lets resolution run in parallel + * across modules; the aggregate is rendered at the sbt task level instead. + */ +private[sbt] final class ResolutionProgressLogger(sink: ResolutionProgress) extends CacheLogger { + override def init(sizeHint: Option[Int]): Unit = sink.onInit() + override def stop(): Unit = sink.onStop() + override def foundLocally(url: String): Unit = sink.onFile(url) + override def downloadedArtifact(url: String, success: Boolean): Unit = + if (success) sink.onFile(url) + override def downloadProgress(url: String, downloaded: Long): Unit = + sink.onProgress(url, downloaded) +} diff --git a/main/src/main/scala/sbt/internal/TaskProgress.scala b/main/src/main/scala/sbt/internal/TaskProgress.scala index 1df8817a0..6e5b259cc 100644 --- a/main/src/main/scala/sbt/internal/TaskProgress.scala +++ b/main/src/main/scala/sbt/internal/TaskProgress.scala @@ -18,6 +18,7 @@ import scala.jdk.CollectionConverters.* import scala.concurrent.duration.* import java.util.concurrent.{ ConcurrentHashMap, Executors, TimeoutException } import sbt.util.Logger +import sbt.coursierint.ResolutionProgress /** * implements task progress display on the shell. @@ -26,6 +27,7 @@ private[sbt] class TaskProgress( sleepDuration: FiniteDuration, threshold: FiniteDuration, logger: Logger, + resolutionProgress: ResolutionProgress, configNameToIdent: String => String = Scope.guessConfigIdent ) extends AbstractTaskExecuteProgress(configNameToIdent) with ExecuteProgress @@ -181,6 +183,12 @@ private[sbt] class TaskProgress( val name = taskName(task) distinct.put(name, ProgressItem(name, elapsed)) } + // Append one aggregate dependency-resolution line while `update` resolves in parallel, + // since coursier no longer renders its own per-module progress bars. The burst elapsed + // renders as a live counter like any task's. + resolutionProgress.snapshot().foreach { (line, elapsed) => + distinct.put(line, ProgressItem(line, elapsed)) + } ProgressEvent( "Info", distinct.values.asScala.toVector, diff --git a/main/src/test/scala/sbt/coursierint/ResolutionProgressSpec.scala b/main/src/test/scala/sbt/coursierint/ResolutionProgressSpec.scala new file mode 100644 index 000000000..cd4f37967 --- /dev/null +++ b/main/src/test/scala/sbt/coursierint/ResolutionProgressSpec.scala @@ -0,0 +1,98 @@ +/* + * 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.coursierint + +import verify.BasicTestSuite + +object ResolutionProgressSpec extends BasicTestSuite: + + test("a fresh per-command instance starts with no line") { + val p = new ResolutionProgress + assert(p.snapshot().isEmpty) + } + + test("aggregates distinct files and monotonic bytes while resolving") { + val p = new ResolutionProgress + val log = new ResolutionProgressLogger(p) + log.init(None) + log.init(None) // two resolutions in flight + log.downloadProgress("a.jar", 1000L) + log.downloadProgress("a.jar", 4000L) // monotonic increase, total 4000 + log.downloadProgress("a.jar", 2000L) // out-of-order, must be ignored + log.foundLocally("b.jar") + log.downloadedArtifact("a.jar", success = true) + log.downloadedArtifact("c.jar", success = false) // failed, must not count + val line = p.snapshot().map(_._1) + assert(line.isDefined, "expected a progress line while resolving") + assert(line.exists(_.contains("2 files")), line.toString) + log.stop() + log.stop() + assert(p.snapshot().isEmpty) + } + + test("per-configuration logger sessions do not inflate the file count") { + // coursier calls init/stop once per logger session — one per configuration resolution + // (compile, runtime, test, ...), plus retries — not once per module, and it re-checks the + // same urls in every session. Neither may inflate the count, and the line must not claim + // a module count it cannot know. + val p = new ResolutionProgress + val log = new ResolutionProgressLogger(p) + for (_ <- 1 to 3) { // e.g. compile, runtime, test sessions of one module's update + log.init(None) + log.foundLocally("x.pom") + log.foundLocally("x.jar") + log.stop() + } + log.init(None) + log.foundLocally("x.jar") // re-checked again in the artifacts run + val line = p.snapshot().map(_._1) + assert(line.exists(_.contains("2 files")), line.toString) // x.pom + x.jar, once each + assert(!line.exists(_.contains("module")), line.toString) // sessions are not modules + log.stop() + } + + test("checksum and signature companions are not counted as files") { + val p = new ResolutionProgress + val log = new ResolutionProgressLogger(p) + log.init(None) + log.foundLocally("a.jar") + log.foundLocally("a.jar.sha1") + log.downloadedArtifact("a.jar.md5", success = true) + log.downloadedArtifact("a.pom.asc", success = true) + val line = p.snapshot().map(_._1) + assert(line.exists(_.contains("1 file,")), line.toString) + log.stop() + } + + test("counts persist across the resolve and artifacts phases of one command") { + val p = new ResolutionProgress + val log = new ResolutionProgressLogger(p) + // resolve phase + log.init(None) + log.foundLocally("x.jar") + log.stop() + assert(p.snapshot().isEmpty) // idle between phases + // artifacts phase of the SAME command: counts accumulate, they do not reset + log.init(None) + log.downloadedArtifact("y.jar", success = true) + val line = p.snapshot().map(_._1) + assert(line.exists(_.contains("2 files")), line.toString) // x + y, not reset + log.stop() + } + + test("snapshot exposes a non-negative burst elapsed for the renderer") { + val p = new ResolutionProgress + val log = new ResolutionProgressLogger(p) + log.init(None) + val snap = p.snapshot() + assert(snap.exists(_._2 >= 0L), snap.toString) + log.stop() + } + +end ResolutionProgressSpec diff --git a/notes/2.0.0/parallel-resolution-supershell.md b/notes/2.0.0/parallel-resolution-supershell.md new file mode 100644 index 000000000..ba75eaa70 --- /dev/null +++ b/notes/2.0.0/parallel-resolution-supershell.md @@ -0,0 +1,20 @@ +### `update` resolves in parallel under the super shell + +Building on #9270 (parallel dependency resolution for non-interactive runs), `update` now also +resolves in parallel under the interactive super shell. Previously sbt let coursier draw its own +per-module progress bars there, and those bars cannot be rendered from more than one module at +once, so resolution was serialized one module at a time. sbt now suppresses coursier's bars and +renders a single aggregate progress line at the task level instead, counting distinct files +(metadata and artifacts) and bytes downloaded, e.g.: + +``` +downloading 240 files, 31.0 MiB 12s +``` + +so resolution can run concurrently across modules. Setting `csrLogger := Some(...)` opts out: your +logger is used instead, and coursier's behavior is unchanged. + +This is the first step of [#5627][i5627]. Per-module status lines (which would add a `status` +field to `ProgressItem`) remain a possible follow-up. + +[i5627]: https://github.com/sbt/sbt/issues/5627