Avoid unnecessary dependency downloading by providing fetches per cache policy (#494)

* Avoid unnecessary dependency downloading by providing fetches per cache policy; add ticker logging when they are downloading

* Fix GenIdeaTests by making the Log context Option[]al

* Add some comments

* Rebase and resolve

3 files changed, 101 insertions, 8 deletions

diff --git a/main/core/src/eval/Evaluator.scala b/main/core/src/eval/Evaluator.scala
index dbaf9433..71fe85a9 100644
--- a/main/core/src/eval/Evaluator.scala
+++ b/main/core/src/eval/Evaluator.scala
@@ -251,7 +251,7 @@ case class Evaluator(home: os.Path,
 
     val nonEvaluatedTargets = group.indexed.filterNot(results.contains)
 
-    maybeTargetLabel.foreach { targetLabel =>
+    val tickerPrefix = maybeTargetLabel.map { targetLabel =>
       val inputResults = for {
         target <- nonEvaluatedTargets
         item <- target.inputs.filterNot(group.contains)
@@ -259,10 +259,16 @@ case class Evaluator(home: os.Path,
 
       val logRun = inputResults.forall(_.isInstanceOf[Result.Success[_]])
 
-      if(logRun) { log.ticker(s"[$counterMsg] $targetLabel ") }
+      val prefix = s"[$counterMsg] $targetLabel "
+      if(logRun) log.ticker(prefix)
+      prefix + "| "
     }
 
-    val multiLogger = resolveLogger(paths.map(_.log))
+    val multiLogger = new ProxyLogger(resolveLogger(paths.map(_.log))) {
+      override def ticker(s: String): Unit = {
+        super.ticker(tickerPrefix.getOrElse("")+s)
+      }
+    }
     var usedDest = Option.empty[(Task[_], Array[StackTraceElement])]
     for (task <- nonEvaluatedTargets) {
       newEvaluated.append(task)
diff --git a/main/core/src/util/Loggers.scala b/main/core/src/util/Loggers.scala
index aab1a324..4771d782 100644
--- a/main/core/src/util/Loggers.scala
+++ b/main/core/src/util/Loggers.scala
@@ -188,3 +188,21 @@ case class MultiLogger(colored: Boolean, logger1: Logger, logger2: Logger) exten
     logger2.close()
   }
 }
+
+/**
+  * A Logger that forwards all logging to another Logger.  Intended to be
+  * used as a base class for wrappers that modify logging behavior.
+  */
+case class ProxyLogger(logger: Logger) extends Logger {
+  def colored = logger.colored
+
+  lazy val outputStream = logger.outputStream
+  lazy val errorStream = logger.errorStream
+  lazy val inStream = logger.inStream
+
+  def info(s: String) = logger.info(s)
+  def error(s: String) = logger.error(s)
+  def ticker(s: String) = logger.ticker(s)
+  def debug(s: String) = logger.debug(s)
+  override def close() = logger.close()
+}
diff --git a/main/src/modules/Jvm.scala b/main/src/modules/Jvm.scala
index e17631e3..020de4b1 100644
--- a/main/src/modules/Jvm.scala
+++ b/main/src/modules/Jvm.scala
@@ -8,7 +8,7 @@ import java.nio.file.attribute.PosixFilePermission
 import java.util.Collections
 import java.util.jar.{JarEntry, JarFile, JarOutputStream}
 
-import coursier.{Cache, Dependency, Fetch, Repository, Resolution}
+import coursier.{Cache, Dependency, Fetch, Repository, Resolution, CachePolicy}
 import coursier.util.{Gather, Task}
 import geny.Generator
 import mill.main.client.InputPumper
@@ -402,10 +402,11 @@ object Jvm {
                           deps: TraversableOnce[coursier.Dependency],
                           force: TraversableOnce[coursier.Dependency],
                           sources: Boolean = false,
-                          mapDependencies: Option[Dependency => Dependency] = None): Result[Agg[PathRef]] = {
+                          mapDependencies: Option[Dependency => Dependency] = None,
+                          ctx: Option[mill.util.Ctx.Log] = None): Result[Agg[PathRef]] = {
 
     val (_, resolution) = resolveDependenciesMetadata(
-      repositories, deps, force, mapDependencies
+      repositories, deps, force, mapDependencies, ctx
     )
     val errs = resolution.metadataErrors
     if(errs.nonEmpty) {
@@ -459,7 +460,10 @@ object Jvm {
   def resolveDependenciesMetadata(repositories: Seq[Repository],
                                   deps: TraversableOnce[coursier.Dependency],
                                   force: TraversableOnce[coursier.Dependency],
-                                  mapDependencies: Option[Dependency => Dependency] = None) = {
+                                  mapDependencies: Option[Dependency => Dependency] = None,
+                                  ctx: Option[mill.util.Ctx.Log] = None) = {
+
+    val cachePolicies = CachePolicy.default
 
     val forceVersions = force
       .map(mapDependencies.getOrElse(identity[Dependency](_)))
@@ -472,10 +476,75 @@ object Jvm {
       mapDependencies = mapDependencies
     )
 
-    val fetch = Fetch.from(repositories, Cache.fetch[Task]())
+    val resolutionLogger = ctx.map(c => new TickerResolutionLogger(c))
+    val fetches = cachePolicies.map { p =>
+      Cache.fetch[Task](
+        logger = resolutionLogger,
+        cachePolicy = p
+      )
+    }
+
+    val fetch = Fetch.from(repositories, fetches.head, fetches.tail: _*)
 
     import scala.concurrent.ExecutionContext.Implicits.global
     val resolution = start.process.run(fetch).unsafeRun()
     (deps.toSeq, resolution)
   }
+
+  /**
+    * A Coursier Cache.Logger implementation that updates the ticker with the count and
+    * overall byte size of artifacts being downloaded.
+    *
+    * In practice, this ticket output gets prefixed with the current target for which
+    * dependencies are being resolved, using a ProxyLogger subclass.
+    */
+  class TickerResolutionLogger(ctx: mill.util.Ctx.Log) extends Cache.Logger {
+    case class DownloadState(var current: Long, var total: Long)
+    var downloads = new mutable.TreeMap[String,DownloadState]()
+    var totalDownloadCount = 0
+    var finishedCount = 0
+    var finishedState = DownloadState(0,0)
+
+    def updateTicker(): Unit = {
+      val sums = downloads.values
+        .fold(DownloadState(0,0)) {
+          (s1, s2) => DownloadState(
+            s1.current + s2.current,
+            Math.max(s1.current,s1.total) + Math.max(s2.current,s2.total)
+          )
+        }
+      sums.current += finishedState.current
+      sums.total += finishedState.total
+      ctx.log.ticker(s"Downloading [${downloads.size + finishedCount}/$totalDownloadCount] artifacts (~${sums.current}/${sums.total} bytes)")
+    }
+
+    override def downloadingArtifact(url: String, file: File): Unit = synchronized {
+      totalDownloadCount += 1
+      downloads += url -> DownloadState(0,0)
+      updateTicker()
+    }
+
+    override def downloadLength(url: String, totalLength: Long, alreadyDownloaded: Long, watching: Boolean): Unit = synchronized {
+      val state = downloads(url)
+      state.current = alreadyDownloaded
+      state.total = totalLength
+      updateTicker()
+    }
+
+    override def downloadProgress(url: String, downloaded: Long): Unit = synchronized {
+      val state = downloads(url)
+      state.current = downloaded
+      updateTicker()
+    }
+
+    override def downloadedArtifact(url: String, success: Boolean): Unit = synchronized {
+      val state = downloads(url)
+      finishedState.current += state.current
+      finishedState.total += Math.max(state.current, state.total)
+      finishedCount += 1
+      downloads -= url
+      updateTicker()
+    }
+  }
+
 }