IntegrationTester.prepEval and improved WatchTests (#5363)

While debugging com-lihaoyi/os-lib#398 I
encountered a lackluster developer experience when running `WatchTests`.

- It took ages for the tests to fail.
- When the tests failed, the amount of context was very low.

This PR improves on both of those areas:
- `WatchTests` timeout is now `15s` instead of `120s` when running not
on CI.
- If the test fails the `eval` context (things like working directory,
the command line for eval and environment variables) is printed out.

To achieve that, I introduced:
- `prepEval` - as `eval` but doesn't actually execute immediatelly.
- `withTestClues` - enhances `utest.AssertionError` thrown in the block
with the given `TestValues`

---------

Co-authored-by: autofix-ci[bot] <114827586+autofix-ci[bot]@users.noreply.github.com>

Author: arturaz

integration/invalidation/watch-source-input/src/WatchSourceInputTests.scala

@@ -21,9 +21,10 @@ import scala.concurrent.ExecutionContext.Implicits.global
  */
 trait WatchTests extends UtestIntegrationTestSuite {
 
-  val maxDuration = 120000
+  val maxDurationMillis: Int = if (sys.env.contains("CI")) 120000 else 15000
+
   def awaitCompletionMarker(tester: IntegrationTester, name: String): Unit = {
-    val maxTime = System.currentTimeMillis() + maxDuration
+    val maxTime = System.currentTimeMillis() + maxDurationMillis
     while (!os.exists(tester.workspacePath / "out" / name)) {
       if (System.currentTimeMillis() > maxTime) {
         sys.error(s"awaitCompletionMarker($name) timed out")
@@ -32,11 +33,11 @@ trait WatchTests extends UtestIntegrationTestSuite {
     }
   }
 
-  def testBase(show: Boolean)(f: (
-      mutable.Buffer[String],
-      mutable.Buffer[String],
-      mutable.Buffer[String]
-  ) => IntegrationTester.EvalResult): Unit = {
+  def testBase(preppedEval: IntegrationTester.PreparedEval, show: Boolean)(f: (
+      expectedOut: mutable.Buffer[String],
+      expectedErr: mutable.Buffer[String],
+      expectedShows: mutable.Buffer[String]
+  ) => IntegrationTester.EvalResult): Unit = withTestClues(preppedEval.clues*) {
     val expectedOut = mutable.Buffer.empty[String]
     // Most of these are normal `println`s, so they go to `stdout` by
     // default unless you use `show` in which case they go to `stderr`.
@@ -61,11 +62,13 @@ trait WatchTests extends UtestIntegrationTestSuite {
 
 object WatchSourceTests extends WatchTests {
   val tests: Tests = Tests {
-    def testWatchSource(tester: IntegrationTester, show: Boolean) =
-      testBase(show) { (expectedOut, expectedErr, expectedShows) =>
-        val showArgs = if (show) Seq("show") else Nil
-        import tester._
-        val evalResult = Future { eval(("--watch", showArgs, "qux"), timeout = maxDuration) }
+    def testWatchSource(tester: IntegrationTester, show: Boolean): Unit = {
+      import tester.*
+      val showArgs = if (show) Seq("show") else Nil
+      val preppedEval = prepEval(("--watch", showArgs, "qux"), timeout = maxDurationMillis)
+
+      testBase(preppedEval, show) { (expectedOut, expectedErr, expectedShows) =>
+        val evalResult = Future { preppedEval.run() }
 
         awaitCompletionMarker(tester, "initialized0")
         awaitCompletionMarker(tester, "quxRan0")
@@ -125,8 +128,10 @@ object WatchSourceTests extends WatchTests {
         awaitCompletionMarker(tester, "initialized2")
         expectedOut.append("Setting up build.mill")
 
-        Await.result(evalResult, Duration.apply(maxDuration, SECONDS))
+        Await.result(evalResult, Duration.apply(maxDurationMillis, SECONDS))
       }
+    }
+
     test("sources") {
 
       // Make sure we clean up the workspace between retries
@@ -151,11 +156,13 @@ object WatchSourceTests extends WatchTests {
 object WatchInputTests extends WatchTests {
   val tests: Tests = Tests {
 
-    def testWatchInput(tester: IntegrationTester, show: Boolean) =
-      testBase(show) { (expectedOut, expectedErr, expectedShows) =>
-        val showArgs = if (show) Seq("show") else Nil
-        import tester._
-        val evalResult = Future { eval(("--watch", showArgs, "lol"), timeout = maxDuration) }
+    def testWatchInput(tester: IntegrationTester, show: Boolean) = {
+      val showArgs = if (show) Seq("show") else Nil
+      import tester.*
+      val preppedEval = prepEval(("--watch", showArgs, "lol"), timeout = maxDurationMillis)
+
+      testBase(preppedEval, show) { (expectedOut, expectedErr, expectedShows) =>
+        val evalResult = Future { preppedEval.run() }
 
         awaitCompletionMarker(tester, "initialized0")
         awaitCompletionMarker(tester, "lolRan0")
@@ -181,8 +188,9 @@ object WatchInputTests extends WatchTests {
         if (show) expectedOut.append("{}")
         expectedOut.append("Setting up build.mill")
 
-        Await.result(evalResult, Duration.apply(maxDuration, SECONDS))
+        Await.result(evalResult, Duration.apply(maxDurationMillis, SECONDS))
       }
+    }
 
     test("input") {
 

testkit/src/mill/testkit/IntegrationTester.scala

@@ -6,6 +6,8 @@ import mill.define.Cached
 import mill.define.SelectMode
 import ujson.Value
 
+import scala.concurrent.duration.*
+
 /**
  * Helper meant for executing Mill integration tests, which runs Mill in a subprocess
  * against a folder with a `build.mill` and project files. Provides APIs such as [[eval]]
@@ -41,6 +43,32 @@ object IntegrationTester {
     def isSuccess = exitCode == 0
   }
 
+  /** An [[Impl.eval]] that is prepared for execution but haven't been executed yet. Run it with [[run]]. */
+  case class PreparedEval(
+      cmd: os.Shellable,
+      env: Map[String, String],
+      cwd: os.Path,
+      timeout: Duration,
+      check: Boolean,
+      propagateEnv: Boolean = true,
+      shutdownGracePeriod: Long = 100,
+      run: () => EvalResult
+  ) {
+
+    /** Clues to use for with [[withTestClues]]. */
+    def clues: Seq[utest.TestValue] = Seq(
+      // Copy-pastable shell command that you can run in bash/zsh/whatever
+      asTestValue("cmd", cmd.value.iterator.map(pprint.Util.literalize(_)).mkString(" ")),
+      asTestValue("cmd.shellable", cmd),
+      asTestValue(env),
+      asTestValue(cwd),
+      asTestValue(timeout),
+      asTestValue(check),
+      asTestValue(propagateEnv),
+      asTestValue(shutdownGracePeriod)
+    ).map(tv => tv.copy(name = "eval." + tv.name))
+  }
+
   trait Impl extends AutoCloseable with IntegrationTesterBase {
 
     def millExecutable: os.Path
@@ -51,12 +79,11 @@ object IntegrationTester {
     def debugLog = false
 
     /**
-     * Evaluates a Mill command. Essentially the same as `os.call`, except it
-     * provides the Mill executable and some test flags and environment variables
-     * for you, and wraps the output in a [[IntegrationTester.EvalResult]] for
-     * convenience.
+     * Prepares to evaluate a Mill command. Run it with [[IntegrationTester.PreparedEval.run]].
+     *
+     * Useful when you need the [[IntegrationTester.PreparedEval.clues]].
      */
-    def eval(
+    def prepEval(
         cmd: os.Shellable,
         env: Map[String, String] = Map.empty,
         cwd: os.Path = workspacePath,
@@ -68,17 +95,72 @@ object IntegrationTester {
         check: Boolean = false,
         propagateEnv: Boolean = true,
         timeoutGracePeriod: Long = 100
-    ): IntegrationTester.EvalResult = {
+    ): IntegrationTester.PreparedEval = {
       val serverArgs = Option.when(!daemonMode)("--no-daemon")
 
       val debugArgs = Option.when(debugLog)("--debug")
 
       val shellable: os.Shellable =
         (millExecutable, serverArgs, "--ticker", "false", debugArgs, cmd)
 
-      val res0 = os.call(
+      val callEnv = millTestSuiteEnv ++ env
+
+      def run() = {
+        val res0 = os.call(
+          cmd = shellable,
+          env = callEnv,
+          cwd = cwd,
+          stdin = stdin,
+          stdout = stdout,
+          stderr = stderr,
+          mergeErrIntoOut = mergeErrIntoOut,
+          timeout = timeout,
+          check = check,
+          propagateEnv = propagateEnv,
+          shutdownGracePeriod = timeoutGracePeriod
+        )
+
+        IntegrationTester.EvalResult(
+          res0.exitCode,
+          fansi.Str(res0.out.text(), errorMode = fansi.ErrorMode.Strip).plainText.trim,
+          fansi.Str(res0.err.text(), errorMode = fansi.ErrorMode.Strip).plainText.trim
+        )
+      }
+
+      PreparedEval(
         cmd = shellable,
-        env = millTestSuiteEnv ++ env,
+        env = callEnv,
+        cwd = cwd,
+        timeout = if (timeout == -1) Duration.Inf else timeout.millis,
+        check = check,
+        propagateEnv = propagateEnv,
+        shutdownGracePeriod = timeoutGracePeriod,
+        run = run
+      )
+    }
+
+    /**
+     * Evaluates a Mill command. Essentially the same as `os.call`, except it
+     * provides the Mill executable and some test flags and environment variables
+     * for you, and wraps the output in a [[IntegrationTester.EvalResult]] for
+     * convenience.
+     */
+    def eval(
+        cmd: os.Shellable,
+        env: Map[String, String] = Map.empty,
+        cwd: os.Path = workspacePath,
+        stdin: os.ProcessInput = os.Pipe,
+        stdout: os.ProcessOutput = os.Pipe,
+        stderr: os.ProcessOutput = os.Pipe,
+        mergeErrIntoOut: Boolean = false,
+        timeout: Long = -1,
+        check: Boolean = false,
+        propagateEnv: Boolean = true,
+        timeoutGracePeriod: Long = 100
+    ): IntegrationTester.EvalResult = {
+      prepEval(
+        cmd = cmd,
+        env = env,
         cwd = cwd,
         stdin = stdin,
         stdout = stdout,
@@ -87,14 +169,8 @@ object IntegrationTester {
         timeout = timeout,
         check = check,
         propagateEnv = propagateEnv,
-        shutdownGracePeriod = timeoutGracePeriod
-      )
-
-      IntegrationTester.EvalResult(
-        res0.exitCode,
-        fansi.Str(res0.out.text(), errorMode = fansi.ErrorMode.Strip).plainText.trim,
-        fansi.Str(res0.err.text(), errorMode = fansi.ErrorMode.Strip).plainText.trim
-      )
+        timeoutGracePeriod = timeoutGracePeriod
+      ).run()
     }
 
     /**

testkit/src/mill/testkit/UtestIntegrationTestSuite.scala

@@ -1,6 +1,8 @@
 package mill.testkit
 
 abstract class UtestIntegrationTestSuite extends utest.TestSuite with IntegrationTestSuite {
+  export mill.testkit.{asTestValue, withTestClues}
+
   protected def workspaceSourcePath: os.Path = os.Path(sys.env("MILL_TEST_RESOURCE_DIR"))
   protected def daemonMode: Boolean = sys.env("MILL_INTEGRATION_DAEMON_MODE").toBoolean
 

testkit/src/mill/testkit/helpers.scala

@@ -0,0 +1,21 @@
+package mill.testkit
+
+import pprint.{TPrint, TPrintColors}
+import utest.TestValue
+
+def asTestValue[A](a: sourcecode.Text[A])(using typeName: TPrint[A]): TestValue =
+  TestValue(a.source, typeName.render(using TPrintColors.BlackWhite).plainText, a.value)
+
+def asTestValue[A](name: String, a: A)(using typeName: TPrint[A]): TestValue =
+  TestValue(name, typeName.render(using TPrintColors.BlackWhite).plainText, a)
+
+/** Adds the provided clues to the thrown [[utest.AssertionError]]. */
+def withTestClues[A](clues: TestValue*)(f: => A): A = {
+  try f
+  catch {
+    case e: utest.AssertionError =>
+      val newException = e.copy(captured = clues ++ e.captured)
+      newException.setStackTrace(e.getStackTrace)
+      throw newException
+  }
+}