Scope PromptLogger to MillBuildBootstrap#evaluate call to make prom…

…pt more intuitive (#3632)

Now, if you use `-w`/`--watch` the prompt starts and ends after each
evaluation (which is bounded) rather than around the entire watch (which
may last forever). This is much more useful so you can see where each
run started and ended and how long it took, v.s. previously where it
just tells you how long you've been watching for overall which is
usually not something you care about

Also fixed a race condition where the `promptUpdaterThread` was still
running for one iteration even after `PromptLogger#close()`, causing
extra prompts to sometimes be displayed overlapping other logs

example/depth/tasks/7-forking-futures/build.mill

@@ -35,7 +35,6 @@ def taskSpawningFutures = Task {
 
 */
 
-
 // `T.fork.async` takes several parameters in addition to the code block to be run:
 //
 // - `dest` is a folder for which the async future is to be run, overriding `os.pwd`

main/util/src/mill/util/PromptLogger.scala

@@ -42,7 +42,7 @@ private[mill] class PromptLogger(
     infoColor
   )
 
-  private val streams = new Streams(
+  private val streamManager = new StreamManager(
     enableTicker,
     systemStreams0,
     () => state.currentPromptBytes,
@@ -62,8 +62,12 @@ private[mill] class PromptLogger(
 
       if (!paused) {
         synchronized {
-          readTerminalDims(terminfoPath).foreach(termDimensions = _)
-          refreshPrompt()
+          // Double check the lock so if this was closed during the
+          // `Thread.sleep`, we skip refreshing the prompt this loop
+          if (!stopped) {
+            readTerminalDims(terminfoPath).foreach(termDimensions = _)
+            refreshPrompt()
+          }
         }
       }
     }
@@ -111,7 +115,7 @@ private[mill] class PromptLogger(
     }
   }
 
-  def streamsAwaitPumperEmpty(): Unit = streams.awaitPumperEmpty()
+  def streamsAwaitPumperEmpty(): Unit = streamManager.awaitPumperEmpty()
   private val seenIdentifiers = collection.mutable.Map.empty[Seq[String], (String, String)]
   private val reportedIdentifiers = collection.mutable.Set.empty[Seq[String]]
   override def setPromptLine(key: Seq[String], verboseKeySuffix: String, message: String): Unit =
@@ -125,18 +129,23 @@ private[mill] class PromptLogger(
 
   override def rawOutputStream: PrintStream = systemStreams0.out
 
-  override def close(): Unit = synchronized {
-    if (enableTicker) state.refreshPrompt(ending = true)
-    streams.close()
-    stopped = true
+  override def close(): Unit = {
+    synchronized {
+      if (enableTicker) state.refreshPrompt(ending = true)
+      streamManager.close()
+      stopped = true
+    }
+    // Needs to be outside the lock so we don't deadlock with `promptUpdaterThread`
+    // trying to take the lock one last time before exiting
+    promptUpdaterThread.join()
   }
 
-  def systemStreams = streams.systemStreams
+  def systemStreams = streamManager.systemStreams
 }
 
 private[mill] object PromptLogger {
 
-  private class Streams(
+  private class StreamManager(
       enableTicker: Boolean,
       systemStreams0: SystemStreams,
       currentPromptBytes: () => Array[Byte],

runner/src/mill/runner/MillMain.scala

@@ -158,81 +158,79 @@ object MillMain {
             (false, RunnerState.empty)
 
           case Right(config) =>
-            val logger = getLogger(
-              streams,
-              config,
-              mainInteractive,
-              enableTicker =
-                config.ticker
-                  .orElse(config.enableTicker)
-                  .orElse(Option.when(config.disableTicker.value)(false)),
-              printLoggerState,
-              serverDir
-            )
-            try {
-              if (!config.silent.value) {
-                checkMillVersionFromFile(WorkspaceRoot.workspaceRoot, streams.err)
-              }
+            if (!config.silent.value) {
+              checkMillVersionFromFile(WorkspaceRoot.workspaceRoot, streams.err)
+            }
 
-              // special BSP mode, in which we spawn a server and register the current evaluator when-ever we start to eval a dedicated command
-              val bspMode = config.bsp.value && config.leftoverArgs.value.isEmpty
-              val maybeThreadCount =
-                parseThreadCount(config.threadCountRaw, Runtime.getRuntime.availableProcessors())
+            // special BSP mode, in which we spawn a server and register the current evaluator when-ever we start to eval a dedicated command
+            val bspMode = config.bsp.value && config.leftoverArgs.value.isEmpty
+            val maybeThreadCount =
+              parseThreadCount(config.threadCountRaw, Runtime.getRuntime.availableProcessors())
 
-              val (success, nextStateCache) = {
-                if (config.repl.value) {
-                  logger.error("The --repl mode is no longer supported.")
-                  (false, stateCache)
+            val (success, nextStateCache) = {
+              if (config.repl.value) {
+                streams.err.println("The --repl mode is no longer supported.")
+                (false, stateCache)
 
-                } else if (!bspMode && config.leftoverArgs.value.isEmpty) {
-                  println(MillCliConfigParser.shortUsageText)
+              } else if (!bspMode && config.leftoverArgs.value.isEmpty) {
+                println(MillCliConfigParser.shortUsageText)
 
-                  (true, stateCache)
+                (true, stateCache)
 
-                } else if (maybeThreadCount.isLeft) {
-                  logger.error(maybeThreadCount.swap.toOption.get)
-                  (false, stateCache)
+              } else if (maybeThreadCount.isLeft) {
+                streams.err.println(maybeThreadCount.swap.toOption.get)
+                (false, stateCache)
 
-                } else {
-                  val userSpecifiedProperties =
-                    userSpecifiedProperties0 ++ config.extraSystemProperties
+              } else {
+                val userSpecifiedProperties =
+                  userSpecifiedProperties0 ++ config.extraSystemProperties
 
-                  val threadCount = Some(maybeThreadCount.toOption.get)
+                val threadCount = Some(maybeThreadCount.toOption.get)
 
-                  if (mill.main.client.Util.isJava9OrAbove) {
-                    val rt = config.home / Export.rtJarName
-                    if (!os.exists(rt)) {
-                      logger.errorStream.println(
-                        s"Preparing Java ${System.getProperty("java.version")} runtime; this may take a minute or two ..."
-                      )
-                      Export.rtTo(rt.toIO, false)
-                    }
+                if (mill.main.client.Util.isJava9OrAbove) {
+                  val rt = config.home / Export.rtJarName
+                  if (!os.exists(rt)) {
+                    streams.err.println(
+                      s"Preparing Java ${System.getProperty("java.version")} runtime; this may take a minute or two ..."
+                    )
+                    Export.rtTo(rt.toIO, false)
                   }
+                }
 
-                  val bspContext =
-                    if (bspMode) Some(new BspContext(streams, bspLog, config.home)) else None
-
-                  val bspCmd = "mill.bsp.BSP/startSession"
-                  val targetsAndParams =
-                    bspContext
-                      .map(_ => Seq(bspCmd))
-                      .getOrElse(config.leftoverArgs.value.toList)
-
-                  var repeatForBsp = true
-                  var loopRes: (Boolean, RunnerState) = (false, RunnerState.empty)
-                  while (repeatForBsp) {
-                    repeatForBsp = false
-
-                    val (isSuccess, evalStateOpt) = Watching.watchLoop(
-                      logger = logger,
-                      ringBell = config.ringBell.value,
-                      watch = config.watch.value,
-                      streams = streams,
-                      setIdle = setIdle,
-                      evaluate = (prevState: Option[RunnerState]) => {
-                        adjustJvmProperties(userSpecifiedProperties, initialSystemProperties)
-
-                        new MillBuildBootstrap(
+                val bspContext =
+                  if (bspMode) Some(new BspContext(streams, bspLog, config.home)) else None
+
+                val bspCmd = "mill.bsp.BSP/startSession"
+                val targetsAndParams =
+                  bspContext
+                    .map(_ => Seq(bspCmd))
+                    .getOrElse(config.leftoverArgs.value.toList)
+
+                var repeatForBsp = true
+                var loopRes: (Boolean, RunnerState) = (false, RunnerState.empty)
+                while (repeatForBsp) {
+                  repeatForBsp = false
+
+                  val (isSuccess, evalStateOpt) = Watching.watchLoop(
+                    ringBell = config.ringBell.value,
+                    watch = config.watch.value,
+                    streams = streams,
+                    setIdle = setIdle,
+                    evaluate = (prevState: Option[RunnerState]) => {
+                      adjustJvmProperties(userSpecifiedProperties, initialSystemProperties)
+
+                      val logger = getLogger(
+                        streams,
+                        config,
+                        mainInteractive,
+                        enableTicker =
+                          config.ticker
+                            .orElse(config.enableTicker)
+                            .orElse(Option.when(config.disableTicker.value)(false)),
+                        printLoggerState,
+                        serverDir
+                      )
+                      try new MillBuildBootstrap(
                           projectRoot = WorkspaceRoot.workspaceRoot,
                           output = os.Path(OutFiles.out, WorkspaceRoot.workspaceRoot),
                           home = config.home,
@@ -249,41 +247,43 @@ object MillMain {
                           config.allowPositional.value,
                           systemExit = systemExit
                         ).evaluate()
+                      finally {
+                        logger.close()
                       }
-                    )
-                    bspContext.foreach { ctx =>
-                      repeatForBsp =
-                        BspContext.bspServerHandle.lastResult == Some(
-                          BspServerResult.ReloadWorkspace
-                        )
-                      logger.error(
-                        s"`$bspCmd` returned with ${BspContext.bspServerHandle.lastResult}"
-                      )
                     }
-                    loopRes = (isSuccess, evalStateOpt)
-                  } // while repeatForBsp
+                  )
                   bspContext.foreach { ctx =>
-                    logger.error(
-                      s"Exiting BSP runner loop. Stopping BSP server. Last result: ${BspContext.bspServerHandle.lastResult}"
+                    repeatForBsp =
+                      BspContext.bspServerHandle.lastResult == Some(
+                        BspServerResult.ReloadWorkspace
+                      )
+                    streams.err.println(
+                      s"`$bspCmd` returned with ${BspContext.bspServerHandle.lastResult}"
                     )
-                    BspContext.bspServerHandle.stop()
                   }
-
-                  // return with evaluation result
-                  loopRes
+                  loopRes = (isSuccess, evalStateOpt)
+                } // while repeatForBsp
+                bspContext.foreach { ctx =>
+                  streams.err.println(
+                    s"Exiting BSP runner loop. Stopping BSP server. Last result: ${BspContext.bspServerHandle.lastResult}"
+                  )
+                  BspContext.bspServerHandle.stop()
                 }
-              }
 
-              if (config.ringBell.value) {
-                if (success) println("\u0007")
-                else {
-                  println("\u0007")
-                  Thread.sleep(250)
-                  println("\u0007")
-                }
+                // return with evaluation result
+                loopRes
+              }
+            }
+
+            if (config.ringBell.value) {
+              if (success) println("\u0007")
+              else {
+                println("\u0007")
+                Thread.sleep(250)
+                println("\u0007")
               }
-              (success, nextStateCache)
-            } finally logger.close()
+            }
+            (success, nextStateCache)
         }
       }
     }

runner/src/mill/runner/Watching.scala

@@ -1,7 +1,7 @@
 package mill.runner
 
 import mill.api.internal
-import mill.util.{ColorLogger, Watchable}
+import mill.util.Watchable
 import mill.api.SystemStreams
 import java.io.InputStream
 import scala.annotation.tailrec
@@ -15,7 +15,6 @@ object Watching {
   case class Result[T](watched: Seq[Watchable], error: Option[String], result: T)
 
   def watchLoop[T](
-      logger: ColorLogger,
       ringBell: Boolean,
       watch: Boolean,
       streams: SystemStreams,
@@ -26,7 +25,7 @@ object Watching {
     while (true) {
       val Result(watchables, errorOpt, result) = evaluate(prevState)
       prevState = Some(result)
-      errorOpt.foreach(logger.error)
+      errorOpt.foreach(streams.err.println)
       if (ringBell) {
         if (errorOpt.isEmpty) println("\u0007")
         else {
@@ -42,14 +41,14 @@ object Watching {
 
       val alreadyStale = watchables.exists(!_.validate())
       if (!alreadyStale) {
-        Watching.watchAndWait(logger, setIdle, streams.in, watchables)
+        Watching.watchAndWait(streams, setIdle, streams.in, watchables)
       }
     }
     ???
   }
 
   def watchAndWait(
-      logger: ColorLogger,
+      streams: SystemStreams,
       setIdle: Boolean => Unit,
       stdin: InputStream,
       watched: Seq[Watchable]
@@ -60,7 +59,7 @@ object Watching {
 
     val watchedValueStr = if (watchedValues == 0) "" else s" and $watchedValues other values"
 
-    logger.info(
+    streams.err.println(
       s"Watching for changes to ${watchedPaths.size} paths$watchedValueStr... (Enter to re-run, Ctrl-C to exit)"
     )