diff --git a/.github/workflows/run-mill-action.yml b/.github/workflows/run-mill-action.yml index 9d667968e14..0cfc4435929 100644 --- a/.github/workflows/run-mill-action.yml +++ b/.github/workflows/run-mill-action.yml @@ -77,7 +77,7 @@ jobs: if: inputs.millargs != '' && startsWith(inputs.os, 'windows') - name: Run Mill (on Windows) Worker Cleanup - run: 'taskkill -f -im java* && rm -rf out/mill-worker-*' + run: 'taskkill -f -im java* && rm -rf out/mill-server/*' if: inputs.millargs != '' && startsWith(inputs.os, 'windows') shell: bash continue-on-error: true diff --git a/bsp/src/mill/bsp/BspContext.scala b/bsp/src/mill/bsp/BspContext.scala index b93ce2d187c..4075be10e89 100644 --- a/bsp/src/mill/bsp/BspContext.scala +++ b/bsp/src/mill/bsp/BspContext.scala @@ -55,6 +55,7 @@ private[mill] class BspContext( override def info(s: String): Unit = streams.err.println(s) override def error(s: String): Unit = streams.err.println(s) override def ticker(s: String): Unit = streams.err.println(s) + override def ticker(key: String, s: String): Unit = streams.err.println(s) override def debug(s: String): Unit = streams.err.println(s) override def debugEnabled: Boolean = true diff --git a/build.mill b/build.mill index 70ce3fab995..22df86ae66b 100644 --- a/build.mill +++ b/build.mill @@ -20,7 +20,7 @@ import mill.define.Cross import $meta._ import $file.ci.shared import $file.ci.upload - +//import $packages._ object Settings { val pomOrg = "com.lihaoyi" val githubOrg = "com-lihaoyi" diff --git a/docs/modules/ROOT/pages/Out_Dir.adoc b/docs/modules/ROOT/pages/Out_Dir.adoc index ec0903dc99e..0deb6330950 100644 --- a/docs/modules/ROOT/pages/Out_Dir.adoc +++ b/docs/modules/ROOT/pages/Out_Dir.adoc @@ -5,7 +5,7 @@ Mill puts all its output in the top-level `out/` folder. == Structure of the `out/` Directory The `out/` folder contains all the generated files & metadata for your build. -It holds some files needed to manage Mill's longer running server instances (`out/mill-worker-*`) as well as a directory and file structure resembling the project's module structure. +It holds some files needed to manage Mill's longer running server instances (`out/mill-server/*`) as well as a directory and file structure resembling the project's module structure. .Example of the `out/` directory after running `mill main.compile` [source,text] @@ -47,7 +47,7 @@ out/ │ ├── unmanagedClasspath.json │ └── upstreamCompileOutput.json ├── mill-profile.json -└── mill-worker-VpZubuAK6LQHHN+3ojh1LsTZqWY=-1/ +└── mill-server/VpZubuAK6LQHHN+3ojh1LsTZqWY=-1/ ---- <1> The `main` directory contains all files associated with target and submodules of the `main` module. @@ -109,5 +109,5 @@ This is very useful if Mill is being unexpectedly slow, and you want to find out `mill-chrome-profile.json`:: This file is only written if you run Mill in parallel mode, e.g. `mill --jobs 4`. This file can be opened in Google Chrome with the built-in `tracing:` protocol even while Mill is still running, so you get a nice chart of what's going on in parallel. -`mill-worker-*/`:: +`mill-server/*`:: Each Mill server instance needs to keep some temporary files in one of these directories. Deleting it will also terminate the associated server instance, if it is still running. diff --git a/example/depth/sandbox/1-task/build.mill b/example/depth/sandbox/1-task/build.mill index 92d08906d72..f5f133f36da 100644 --- a/example/depth/sandbox/1-task/build.mill +++ b/example/depth/sandbox/1-task/build.mill @@ -52,14 +52,14 @@ def osProcTask = Task { // // Lastly, there is the possibily of calling `os.pwd` outside of a task. When outside of // a task there is no `.dest/` folder associated, so instead Mill will redirect `os.pwd` -// towards an empty `sandbox/` folder in `out/mill-worker.../`: +// towards an empty `sandbox/` folder in `out/mill-server/...`: val externalPwd = os.pwd def externalPwdTask = Task { println(externalPwd.toString) } /** Usage > ./mill externalPwdTask -.../out/mill-worker-.../sandbox/sandbox +.../out/mill-server/.../sandbox */ diff --git a/integration/failure/missing-build-file/src/MissingBuildFileTests.scala b/integration/failure/missing-build-file/src/MissingBuildFileTests.scala index 2b6f625d991..892f5439a42 100644 --- a/integration/failure/missing-build-file/src/MissingBuildFileTests.scala +++ b/integration/failure/missing-build-file/src/MissingBuildFileTests.scala @@ -9,7 +9,7 @@ object MissingBuildFileTests extends UtestIntegrationTestSuite { test - integrationTest { tester => val res = tester.eval(("resolve", "_")) assert(!res.isSuccess) - val s"build.mill file not found in $msg. Are you in a Mill project folder?" = res.err + val s"${prefix}build.mill file not found in $msg. Are you in a Mill project folder?" = res.err } } } diff --git a/main/api/src/mill/api/Logger.scala b/main/api/src/mill/api/Logger.scala index 3c6967558e9..c0c11039244 100644 --- a/main/api/src/mill/api/Logger.scala +++ b/main/api/src/mill/api/Logger.scala @@ -44,6 +44,14 @@ trait Logger { def info(s: String): Unit def error(s: String): Unit def ticker(s: String): Unit + def ticker(key: String, s: String): Unit = ticker(s) + private[mill] def reportPrefix(s: String): Unit = () + private[mill] def promptLine(key: String, identSuffix: String, message: String): Unit = + ticker(s"$key $message") + private[mill] def globalTicker(s: String): Unit = () + private[mill] def clearAllTickers(): Unit = () + private[mill] def endTicker(key: String): Unit = () + def debug(s: String): Unit /** @@ -53,4 +61,12 @@ trait Logger { def debugEnabled: Boolean = false def close(): Unit = () + + /** + * Used to disable the terminal UI prompt without a certain block of code so you + * can run stuff like REPLs or other output-sensitive code in a clean terminal + */ + def withPromptPaused[T](t: => T) = t + + def enableTicker: Boolean = false } diff --git a/main/api/src/mill/api/SystemStreams.scala b/main/api/src/mill/api/SystemStreams.scala index 5b687d18191..29052c4c4af 100644 --- a/main/api/src/mill/api/SystemStreams.scala +++ b/main/api/src/mill/api/SystemStreams.scala @@ -3,6 +3,8 @@ package mill.api import java.io.{InputStream, OutputStream, PrintStream} import mill.main.client.InputPumper +import scala.util.DynamicVariable + /** * Represents a set of streams that look similar to those provided by the * operating system. These may internally be proxied/redirected/processed, but @@ -28,11 +30,12 @@ object SystemStreams { * stdout/stderr/stdin. */ def isOriginal(): Boolean = { - (System.out eq original.out) && - (System.err eq original.err) && - (System.in eq original.in) && - (Console.out eq original.out) && - (Console.err eq original.err) + (Console.out eq original.out) && (Console.err eq original.err) + // We do not check System.* for equality because they are always overridden by + // `ThreadLocalStreams` + // (System.out eq original.out) && + // (System.err eq original.err) && + // (System.in eq original.in) && // We do not check `Console.in` for equality, because `Console.withIn` always wraps // `Console.in` in a `new BufferedReader` each time, and so it is impossible to check @@ -62,30 +65,24 @@ object SystemStreams { Some(new InputPumper(() => processOut.wrapped, () => dest, false, () => true)) } def withStreams[T](systemStreams: SystemStreams)(t: => T): T = { - val in = System.in - val out = System.out - val err = System.err - try { - // If we are setting a stream back to its original value, make sure we reset - // `os.Inherit` to `os.InheritRaw` for that stream. This direct inheritance - // ensures that interactive applications involving console IO work, as the - // presence of a `PumpedProcess` would cause most interactive CLIs (e.g. - // scala console, REPL, etc.) to misbehave - val inheritIn = - if (systemStreams.in eq original.in) os.InheritRaw - else new PumpedProcessInput - - val inheritOut = - if (systemStreams.out eq original.out) os.InheritRaw - else new PumpedProcessOutput(systemStreams.out) - - val inheritErr = - if (systemStreams.err eq original.err) os.InheritRaw - else new PumpedProcessOutput(systemStreams.err) - - System.setIn(systemStreams.in) - System.setOut(systemStreams.out) - System.setErr(systemStreams.err) + // If we are setting a stream back to its original value, make sure we reset + // `os.Inherit` to `os.InheritRaw` for that stream. This direct inheritance + // ensures that interactive applications involving console IO work, as the + // presence of a `PumpedProcess` would cause most interactive CLIs (e.g. + // scala console, REPL, etc.) to misbehave + val inheritIn = + if (systemStreams.in eq original.in) os.InheritRaw + else new PumpedProcessInput + + val inheritOut = + if (systemStreams.out eq original.out) os.InheritRaw + else new PumpedProcessOutput(systemStreams.out) + + val inheritErr = + if (systemStreams.err eq original.err) os.InheritRaw + else new PumpedProcessOutput(systemStreams.err) + + ThreadLocalStreams.current.withValue(systemStreams) { Console.withIn(systemStreams.in) { Console.withOut(systemStreams.out) { Console.withErr(systemStreams.err) { @@ -99,10 +96,75 @@ object SystemStreams { } } } + } + } + + /** + * Manages the global override of `System.{in,out,err}`. Overrides of those streams are + * global, so we cannot just override them per-use-site in a multithreaded environment + * because different threads may interleave and stomp over each other's over-writes. + * Instead, we over-write them globally with a set of streams that does nothing but + * forward to the per-thread [[ThreadLocalStreams.current]] streams, allowing callers + * to each reach their own thread-local streams without clashing across multiple threads + */ + def withTopLevelSystemStreamProxy[T](t: => T): T = { + val in = System.in + val out = System.out + val err = System.err + + try { + setTopLevelSystemStreamProxy() + t } finally { System.setErr(err) System.setOut(out) System.setIn(in) } } + def setTopLevelSystemStreamProxy(): Unit = { + // Make sure to initialize `Console` to cache references to the original + // `System.{in,out,err}` streams before we redirect them + Console.out + Console.err + Console.in + System.setIn(ThreadLocalStreams.In) + System.setOut(ThreadLocalStreams.Out) + System.setErr(ThreadLocalStreams.Err) + } + + private[mill] object ThreadLocalStreams { + val current = new DynamicVariable(original) + + object Out extends PrintStream(new ProxyOutputStream { def delegate() = current.value.out }) + object Err extends PrintStream(new ProxyOutputStream { def delegate() = current.value.err }) + object In extends ProxyInputStream { def delegate() = current.value.in } + + abstract class ProxyOutputStream extends OutputStream { + def delegate(): OutputStream + override def write(b: Array[Byte], off: Int, len: Int): Unit = delegate().write(b, off, len) + override def write(b: Array[Byte]): Unit = delegate().write(b) + def write(b: Int): Unit = delegate().write(b) + override def flush(): Unit = delegate().flush() + override def close(): Unit = delegate().close() + } + abstract class ProxyInputStream extends InputStream { + def delegate(): InputStream + override def read(): Int = delegate().read() + override def read(b: Array[Byte], off: Int, len: Int): Int = delegate().read(b, off, len) + override def read(b: Array[Byte]): Int = delegate().read(b) + override def readNBytes(b: Array[Byte], off: Int, len: Int): Int = + delegate().readNBytes(b, off, len) + override def readNBytes(len: Int): Array[Byte] = delegate().readNBytes(len) + override def readAllBytes(): Array[Byte] = delegate().readAllBytes() + override def mark(readlimit: Int): Unit = delegate().mark(readlimit) + override def markSupported(): Boolean = delegate().markSupported() + override def available(): Int = delegate().available() + override def reset(): Unit = delegate().reset() + override def skip(n: Long): Long = delegate().skip(n) + // Not present in some versions of Java + // override def skipNBytes(n: Long): Unit = delegate().skipNBytes(n) + override def close(): Unit = delegate().close() + override def transferTo(out: OutputStream): Long = delegate().transferTo(out) + } + } } diff --git a/main/client/src/mill/main/client/DebugLog.java b/main/client/src/mill/main/client/DebugLog.java new file mode 100644 index 00000000000..2ee8473f570 --- /dev/null +++ b/main/client/src/mill/main/client/DebugLog.java @@ -0,0 +1,20 @@ +package mill.main.client; +import java.io.IOException; +import java.nio.file.*; + +/** + * Used to add `println`s in scenarios where you can't figure out where on earth + * your stdout/stderr/logs are going and so we just dump them in a file in your + * home folder so you can find them + */ +public class DebugLog{ + synchronized public static void println(String s){ + Path path = Paths.get(System.getProperty("user.home"), "mill-debug-log.txt"); + try { + if (!Files.exists(path)) Files.createFile(path); + Files.writeString(path, s + "\n", StandardOpenOption.APPEND); + }catch (IOException e){ + throw new RuntimeException(e); + } + } +} diff --git a/main/client/src/mill/main/client/OutFiles.java b/main/client/src/mill/main/client/OutFiles.java index 88fdfd28d44..ba7dce7bacf 100644 --- a/main/client/src/mill/main/client/OutFiles.java +++ b/main/client/src/mill/main/client/OutFiles.java @@ -41,11 +41,12 @@ public class OutFiles { * Subfolder of `out/` that contains the machinery necessary for a single Mill background * server: metadata files, pipes, logs, etc. */ - final public static String millWorker = "mill-worker-"; + final public static String millServer = "mill-server"; /** * Subfolder of `out/` used to contain the Mill subprocess when run in no-server mode */ final public static String millNoServer = "mill-no-server"; + } diff --git a/main/client/src/mill/main/client/ProxyStream.java b/main/client/src/mill/main/client/ProxyStream.java index d28e3b3b426..3f3655a0196 100644 --- a/main/client/src/mill/main/client/ProxyStream.java +++ b/main/client/src/mill/main/client/ProxyStream.java @@ -4,6 +4,8 @@ import java.io.IOException; import java.io.InputStream; import java.io.OutputStream; +import java.util.function.BiConsumer; +import java.util.function.Consumer; /** * Logic to capture a pair of streams (typically stdout and stderr), combining @@ -106,11 +108,16 @@ public Pumper(InputStream src, OutputStream destOut, OutputStream destErr){ this.destErr = destErr; } + public void preRead(InputStream src){} + + public void preWrite(){} + public void run() { byte[] buffer = new byte[1024]; while (true) { try { + this.preRead(src); int header = src.read(); // -1 means socket was closed, 0 means a ProxyStream.END was sent. Note // that only header values > 0 represent actual data to read: @@ -124,6 +131,7 @@ public void run() { int offset = 0; int delta = -1; while (offset < quantity) { + this.preRead(src); delta = src.read(buffer, offset, quantity - offset); if (delta == -1) { break; @@ -133,26 +141,25 @@ public void run() { } if (delta != -1) { + this.preWrite(); switch(stream){ case ProxyStream.OUT: destOut.write(buffer, 0, offset); break; case ProxyStream.ERR: destErr.write(buffer, 0, offset); break; } - - flush(); } } } catch (org.newsclub.net.unix.ConnectionResetSocketException e) { // This happens when you run mill shutdown and the server exits gracefully break; } catch (IOException e) { - e.printStackTrace(); - System.exit(1); + // This happens when the upstream pipe was closed + break; } } try { - destOut.close(); - destErr.close(); + destOut.flush(); + destErr.flush(); } catch(IOException e) {} } diff --git a/main/client/src/mill/main/client/ServerFiles.java b/main/client/src/mill/main/client/ServerFiles.java index 208237ae6e6..bd7ac1a289c 100644 --- a/main/client/src/mill/main/client/ServerFiles.java +++ b/main/client/src/mill/main/client/ServerFiles.java @@ -1,7 +1,7 @@ package mill.main.client; /** - * Central place containing all the files that live inside the `out/mill-worker-*` folder + * Central place containing all the files that live inside the `out/mill-server-*` folder * and documentation about what they do */ public class ServerFiles { @@ -9,14 +9,14 @@ public class ServerFiles { final public static String sandbox = "sandbox"; /** - * Ensures only a single client is manipulating each mill-worker folder at + * Ensures only a single client is manipulating each mill-server folder at * a time, either spawning the server or submitting a command. Also used by * the server to detect when a client disconnects, so it can terminate execution */ final public static String clientLock = "clientLock"; /** - * Lock file ensuring a single server is running in a particular mill-worker + * Lock file ensuring a single server is running in a particular mill-server * folder. If multiple servers are spawned in the same folder, only one takes * the lock and the others fail to do so and terminate immediately. */ @@ -67,4 +67,9 @@ public static String pipe(String base) { * Where the server's stderr is piped to */ final public static String stderr = "stderr"; + + /** + * Terminal information that we need to propagate from client to server + */ + final public static String terminfo = "terminfo"; } diff --git a/main/client/src/mill/main/client/ServerLauncher.java b/main/client/src/mill/main/client/ServerLauncher.java index 58fbb2ee1e2..ab162de1aee 100644 --- a/main/client/src/mill/main/client/ServerLauncher.java +++ b/main/client/src/mill/main/client/ServerLauncher.java @@ -14,6 +14,7 @@ import java.io.PrintStream; import java.net.Socket; import java.nio.file.Files; +import java.nio.file.Path; import java.nio.file.Paths; import java.util.Map; import java.util.function.BiConsumer; @@ -46,12 +47,12 @@ public abstract class ServerLauncher { public static class Result{ public int exitCode; - public String serverDir; + public Path serverDir; } final static int tailerRefreshIntervalMillis = 2; final int serverProcessesLimit = 5; final int serverInitWaitMillis = 10000; - public abstract void initServer(String serverDir, boolean b, Locks locks) throws Exception; + public abstract void initServer(Path serverDir, boolean b, Locks locks) throws Exception; InputStream stdin; PrintStream stdout; PrintStream stderr; @@ -92,12 +93,11 @@ public Result acquireLocksAndRun(String outDir) throws Exception { int serverIndex = 0; while (serverIndex < serverProcessesLimit) { // Try each possible server process (-1 to -5) serverIndex++; - final String serverDir = outDir + "/" + millWorker + versionAndJvmHomeEncoding + "-" + serverIndex; - java.io.File serverDirFile = new java.io.File(serverDir); - serverDirFile.mkdirs(); + final Path serverDir = Paths.get(outDir, millServer, versionAndJvmHomeEncoding + "-" + serverIndex); + Files.createDirectories(serverDir); try ( - Locks locks = memoryLocks != null ? memoryLocks[serverIndex-1] : Locks.files(serverDir); + Locks locks = memoryLocks != null ? memoryLocks[serverIndex-1] : Locks.files(serverDir.toString()); TryLocked clientLocked = locks.clientLock.tryLock() ) { if (clientLocked.isLocked()) { @@ -111,7 +111,7 @@ public Result acquireLocksAndRun(String outDir) throws Exception { throw new ServerCouldNotBeStarted("Reached max server processes limit: " + serverProcessesLimit); } - int run(String serverDir, boolean setJnaNoSys, Locks locks) throws Exception { + int run(Path serverDir, boolean setJnaNoSys, Locks locks) throws Exception { try( final FileToStreamTailer stdoutTailer = new FileToStreamTailer( new java.io.File(serverDir + "/" + ServerFiles.stdout), @@ -139,7 +139,7 @@ int run(String serverDir, boolean setJnaNoSys, Locks locks) throws Exception { while (locks.processLock.probe()) Thread.sleep(3); - String socketName = ServerFiles.pipe(serverDir); + String socketName = ServerFiles.pipe(serverDir.toString()); AFUNIXSocketAddress addr = AFUNIXSocketAddress.of(new File(socketName)); long retryStart = System.currentTimeMillis(); diff --git a/main/eval/src/mill/eval/EvaluatorCore.scala b/main/eval/src/mill/eval/EvaluatorCore.scala index 777640d7eba..8e556bf06a0 100644 --- a/main/eval/src/mill/eval/EvaluatorCore.scala +++ b/main/eval/src/mill/eval/EvaluatorCore.scala @@ -101,6 +101,16 @@ private[mill] trait EvaluatorCore extends GroupEvaluator { for (terminal <- terminals) { val deps = interGroupDeps(terminal) futures(terminal) = Future.sequence(deps.map(futures)).map { upstreamValues => + val paddedCount = count + .getAndIncrement() + .toString + .reverse + .padTo(terminals.size.toString.length, '0') + .reverse + val countMsg = s"[$paddedCount]" + + val counterMsg = s"[$paddedCount/${terminals0.size}]" + logger.globalTicker(counterMsg) if (failed.get()) None else { val upstreamResults = upstreamValues @@ -109,11 +119,10 @@ private[mill] trait EvaluatorCore extends GroupEvaluator { .toMap val startTime = System.nanoTime() / 1000 - val threadId = threadNumberer.getThreadId(Thread.currentThread()) - val counterMsg = s"${count.getAndIncrement()}/${terminals.size}" + val contextLogger = PrefixLogger( out = logger, - context = contextLoggerMsg(threadId), + context = if (logger.enableTicker) countMsg else "", tickerContext = GroupEvaluator.dynamicTickerPrefix.value ) @@ -121,7 +130,8 @@ private[mill] trait EvaluatorCore extends GroupEvaluator { terminal = terminal, group = sortedGroups.lookupKey(terminal), results = upstreamResults, - counterMsg = counterMsg, + counterMsg = countMsg, + identSuffix = counterMsg, zincProblemReporter = reporter, testReporter = testReporter, logger = contextLogger, @@ -186,6 +196,7 @@ private[mill] trait EvaluatorCore extends GroupEvaluator { )(ec) evaluateTerminals(leafCommands, _ => "")(ExecutionContexts.RunNow) + logger.clearAllTickers() val finishedOptsMap = terminals0 .map(t => (t, Await.result(futures(t), duration.Duration.Inf))) .toMap diff --git a/main/eval/src/mill/eval/GroupEvaluator.scala b/main/eval/src/mill/eval/GroupEvaluator.scala index b2566465007..156ab79f191 100644 --- a/main/eval/src/mill/eval/GroupEvaluator.scala +++ b/main/eval/src/mill/eval/GroupEvaluator.scala @@ -7,7 +7,6 @@ import mill.define._ import mill.eval.Evaluator.TaskResult import mill.util._ -import java.io.PrintStream import java.lang.reflect.Method import scala.collection.mutable import scala.reflect.NameTransformer.encode @@ -50,6 +49,7 @@ private[mill] trait GroupEvaluator { group: Agg[Task[_]], results: Map[Task[_], TaskResult[(Val, Int)]], counterMsg: String, + identSuffix: String, zincProblemReporter: Int => Option[CompileProblemReporter], testReporter: TestReporter, logger: ColorLogger, @@ -57,168 +57,192 @@ private[mill] trait GroupEvaluator { allTransitiveClassMethods: Map[Class[_], Map[String, Method]] ): GroupEvaluator.Results = { - val externalInputsHash = MurmurHash3.orderedHash( - group.items.flatMap(_.inputs).filter(!group.contains(_)) - .flatMap(results(_).result.asSuccess.map(_.value._2)) - ) + val targetLabel = terminal match { + case Terminal.Task(task) => None + case t: Terminal.Labelled[_] => Some(Terminal.printTerm(t)) + } + // should we log progress? + val logRun = targetLabel.isDefined && { + val inputResults = for { + target <- group.indexed.filterNot(results.contains) + item <- target.inputs.filterNot(group.contains) + } yield results(item).map(_._1) + inputResults.forall(_.result.isInstanceOf[Result.Success[_]]) + } - val sideHashes = MurmurHash3.orderedHash(group.iterator.map(_.sideHash)) - - val scriptsHash = - if (disableCallgraph) 0 - else group - .iterator - .collect { - case namedTask: NamedTask[_] => - val encodedTaskName = encode(namedTask.ctx.segment.pathSegments.head) - val methodOpt = for { - parentCls <- classToTransitiveClasses(namedTask.ctx.enclosingCls).iterator - m <- allTransitiveClassMethods(parentCls).get(encodedTaskName) - } yield m - - val methodClass = methodOpt - .nextOption() - .getOrElse(throw new MillException( - s"Could not detect the parent class of target ${namedTask}. " + - s"Please report this at ${BuildInfo.millReportNewIssueUrl} . " - )) - .getDeclaringClass.getName - - val name = namedTask.ctx.segment.pathSegments.last - val expectedName = methodClass + "#" + name + "()mill.define.Target" - - // We not only need to look up the code hash of the Target method being called, - // but also the code hash of the constructors required to instantiate the Module - // that the Target is being called on. This can be done by walking up the nested - // modules and looking at their constructors (they're `object`s and should each - // have only one) - val allEnclosingModules = Vector.unfold(namedTask.ctx) { - case null => None - case ctx => - ctx.enclosingModule match { - case null => None - case m: mill.define.Module => Some((m, m.millOuterCtx)) - case unknown => - throw new MillException(s"Unknown ctx of target ${namedTask}: $unknown") - } - } + val tickerPrefix = terminal.render.collect { + case targetLabel if logRun && logger.enableTicker => targetLabel + } - val constructorHashes = allEnclosingModules - .map(m => - constructorHashSignatures.get(m.getClass.getName) match { - case Some(Seq((singleMethod, hash))) => hash - case Some(multiple) => throw new MillException( - s"Multiple constructors found for module $m: ${multiple.mkString(",")}" - ) - case None => 0 - } - ) + def withTicker[T](s: Option[String])(t: => T): T = s match { + case None => t + case Some(s) => + logger.promptLine(counterMsg, identSuffix, s) + try t + finally logger.endTicker(counterMsg) + } - methodCodeHashSignatures.get(expectedName) ++ constructorHashes - } - .flatten - .sum - - val inputsHash = externalInputsHash + sideHashes + classLoaderSigHash + scriptsHash - - terminal match { - case Terminal.Task(task) => - val (newResults, newEvaluated) = evaluateGroup( - group, - results, - inputsHash, - paths = None, - maybeTargetLabel = None, - counterMsg = counterMsg, - zincProblemReporter, - testReporter, - logger, - terminal.task.asWorker.nonEmpty - ) - GroupEvaluator.Results(newResults, newEvaluated.toSeq, null, inputsHash, -1) + withTicker(Some(tickerPrefix)) { + val externalInputsHash = MurmurHash3.orderedHash( + group.items.flatMap(_.inputs).filter(!group.contains(_)) + .flatMap(results(_).result.asSuccess.map(_.value._2)) + ) - case labelled: Terminal.Labelled[_] => - val out = - if (!labelled.task.ctx.external) outPath - else externalOutPath + val sideHashes = MurmurHash3.orderedHash(group.iterator.map(_.sideHash)) + + val scriptsHash = + if (disableCallgraph) 0 + else group + .iterator + .collect { + case namedTask: NamedTask[_] => + val encodedTaskName = encode(namedTask.ctx.segment.pathSegments.head) + val methodOpt = for { + parentCls <- classToTransitiveClasses(namedTask.ctx.enclosingCls).iterator + m <- allTransitiveClassMethods(parentCls).get(encodedTaskName) + } yield m + + val methodClass = methodOpt + .nextOption() + .getOrElse(throw new MillException( + s"Could not detect the parent class of target ${namedTask}. " + + s"Please report this at ${BuildInfo.millReportNewIssueUrl} . " + )) + .getDeclaringClass.getName + + val name = namedTask.ctx.segment.pathSegments.last + val expectedName = methodClass + "#" + name + "()mill.define.Target" + + // We not only need to look up the code hash of the Target method being called, + // but also the code hash of the constructors required to instantiate the Module + // that the Target is being called on. This can be done by walking up the nested + // modules and looking at their constructors (they're `object`s and should each + // have only one) + val allEnclosingModules = Vector.unfold(namedTask.ctx) { + case null => None + case ctx => + ctx.enclosingModule match { + case null => None + case m: mill.define.Module => Some((m, m.millOuterCtx)) + case unknown => + throw new MillException(s"Unknown ctx of target ${namedTask}: $unknown") + } + } - val paths = EvaluatorPaths.resolveDestPaths( - out, - Terminal.destSegments(labelled) - ) + val constructorHashes = allEnclosingModules + .map(m => + constructorHashSignatures.get(m.getClass.getName) match { + case Some(Seq((singleMethod, hash))) => hash + case Some(multiple) => throw new MillException( + s"Multiple constructors found for module $m: ${multiple.mkString(",")}" + ) + case None => 0 + } + ) - val cached = loadCachedJson(logger, inputsHash, labelled, paths) + methodCodeHashSignatures.get(expectedName) ++ constructorHashes + } + .flatten + .sum + + val inputsHash = externalInputsHash + sideHashes + classLoaderSigHash + scriptsHash + + terminal match { + case Terminal.Task(task) => + val (newResults, newEvaluated) = evaluateGroup( + group, + results, + inputsHash, + paths = None, + maybeTargetLabel = None, + counterMsg = counterMsg, + identSuffix = identSuffix, + zincProblemReporter, + testReporter, + logger + ) + GroupEvaluator.Results(newResults, newEvaluated.toSeq, null, inputsHash, -1) - val upToDateWorker = loadUpToDateWorker( - logger, - inputsHash, - labelled, - forceDiscard = - // worker metadata file removed by user, let's recompute the worker - cached.isEmpty - ) + case labelled: Terminal.Labelled[_] => + val out = + if (!labelled.task.ctx.external) outPath + else externalOutPath - upToDateWorker.map((_, inputsHash)) orElse cached.flatMap(_._2) match { - case Some((v, hashCode)) => - val res = Result.Success((v, hashCode)) - val newResults: Map[Task[_], TaskResult[(Val, Int)]] = - Map(labelled.task -> TaskResult(res, () => res)) - - GroupEvaluator.Results( - newResults, - Nil, - cached = true, - inputsHash, - -1 - ) - - case _ => - // uncached - if (labelled.task.flushDest) os.remove.all(paths.dest) - - val targetLabel = Terminal.printTerm(terminal) - - val (newResults, newEvaluated) = - GroupEvaluator.dynamicTickerPrefix.withValue(s"[$counterMsg] $targetLabel > ") { - evaluateGroup( - group, - results, - inputsHash, - paths = Some(paths), - maybeTargetLabel = Some(targetLabel), - counterMsg = counterMsg, - zincProblemReporter, - testReporter, - logger, - terminal.task.asWorker.nonEmpty - ) - } + val paths = EvaluatorPaths.resolveDestPaths( + out, + Terminal.destSegments(labelled) + ) - newResults(labelled.task) match { - case TaskResult(Result.Failure(_, Some((v, _))), _) => - handleTaskResult(v, v.##, paths.meta, inputsHash, labelled) + val cached = loadCachedJson(logger, inputsHash, labelled, paths) - case TaskResult(Result.Success((v, _)), _) => - handleTaskResult(v, v.##, paths.meta, inputsHash, labelled) + val upToDateWorker = loadUpToDateWorker( + logger, + inputsHash, + labelled, + forceDiscard = + // worker metadata file removed by user, let's recompute the worker + cached.isEmpty + ) - case _ => - // Wipe out any cached meta.json file that exists, so - // a following run won't look at the cached metadata file and - // assume it's associated with the possibly-borked state of the - // destPath after an evaluation failure. - os.remove.all(paths.meta) - } + upToDateWorker.map((_, inputsHash)) orElse cached.flatMap(_._2) match { + case Some((v, hashCode)) => + val res = Result.Success((v, hashCode)) + val newResults: Map[Task[_], TaskResult[(Val, Int)]] = + Map(labelled.task -> TaskResult(res, () => res)) + + GroupEvaluator.Results( + newResults, + Nil, + cached = true, + inputsHash, + -1 + ) - GroupEvaluator.Results( - newResults, - newEvaluated.toSeq, - cached = if (labelled.task.isInstanceOf[InputImpl[_]]) null else false, - inputsHash, - cached.map(_._1).getOrElse(-1) - ) - } - } + case _ => + // uncached + if (labelled.task.flushDest) os.remove.all(paths.dest) + + val (newResults, newEvaluated) = + GroupEvaluator.dynamicTickerPrefix.withValue(s"[$counterMsg] $targetLabel > ") { + evaluateGroup( + group, + results, + inputsHash, + paths = Some(paths), + maybeTargetLabel = targetLabel, + counterMsg = counterMsg, + identSuffix = identSuffix, + zincProblemReporter, + testReporter, + logger + ) + } + + newResults(labelled.task) match { + case TaskResult(Result.Failure(_, Some((v, _))), _) => + handleTaskResult(v, v.##, paths.meta, inputsHash, labelled) + + case TaskResult(Result.Success((v, _)), _) => + handleTaskResult(v, v.##, paths.meta, inputsHash, labelled) + + case _ => + // Wipe out any cached meta.json file that exists, so + // a following run won't look at the cached metadata file and + // assume it's associated with the possibly-borked state of the + // destPath after an evaluation failure. + os.remove.all(paths.meta) + } + GroupEvaluator.Results( + newResults, + newEvaluated.toSeq, + cached = if (labelled.task.isInstanceOf[InputImpl[_]]) null else false, + inputsHash, + cached.map(_._1).getOrElse(-1) + ) + } + } + } } private def evaluateGroup( @@ -228,41 +252,19 @@ private[mill] trait GroupEvaluator { paths: Option[EvaluatorPaths], maybeTargetLabel: Option[String], counterMsg: String, + identSuffix: String, reporter: Int => Option[CompileProblemReporter], testReporter: TestReporter, - logger: mill.api.Logger, - isWorker: Boolean + logger: mill.api.Logger ): (Map[Task[_], TaskResult[(Val, Int)]], mutable.Buffer[Task[_]]) = { - def computeAll(enableTicker: Boolean) = { + def computeAll() = { val newEvaluated = mutable.Buffer.empty[Task[_]] val newResults = mutable.Map.empty[Task[_], Result[(Val, Int)]] val nonEvaluatedTargets = group.indexed.filterNot(results.contains) - // should we log progress? - val logRun = maybeTargetLabel.isDefined && { - val inputResults = for { - target <- nonEvaluatedTargets - item <- target.inputs.filterNot(group.contains) - } yield results(item).map(_._1) - inputResults.forall(_.result.isInstanceOf[Result.Success[_]]) - } - - val tickerPrefix = maybeTargetLabel.map { targetLabel => - val prefix = s"[$counterMsg] $targetLabel " - if (logRun && enableTicker) logger.ticker(prefix) - prefix + "| " - } - - val multiLogger = new ProxyLogger(resolveLogger(paths.map(_.log), logger)) { - override def ticker(s: String): Unit = { - if (enableTicker) super.ticker(tickerPrefix.getOrElse("") + s) - else () // do nothing - } - - override def rawOutputStream: PrintStream = logger.rawOutputStream - } + val multiLogger = resolveLogger(paths.map(_.log), logger) var usedDest = Option.empty[os.Path] for (task <- nonEvaluatedTargets) { @@ -328,7 +330,7 @@ private[mill] trait GroupEvaluator { (newResults, newEvaluated) } - val (newResults, newEvaluated) = computeAll(enableTicker = true) + val (newResults, newEvaluated) = computeAll() if (!failFast) maybeTargetLabel.foreach { targetLabel => val taskFailed = newResults.exists(task => !task._2.isInstanceOf[Success[_]]) @@ -340,7 +342,7 @@ private[mill] trait GroupEvaluator { ( newResults .map { case (k, v) => - val recalc = () => computeAll(enableTicker = false)._1.apply(k) + val recalc = () => computeAll()._1.apply(k) val taskResult = TaskResult(v, recalc) (k, taskResult) } diff --git a/main/package.mill b/main/package.mill index a2696ff9d48..7844a161a9a 100644 --- a/main/package.mill +++ b/main/package.mill @@ -171,13 +171,10 @@ object `package` extends RootModule with build.MillStableScalaModule with BuildI object client extends build.MillPublishJavaModule with BuildInfo { def buildInfoPackageName = "mill.main.client" def buildInfoMembers = Seq(BuildInfo.Value("millVersion", build.millVersion(), "Mill version.")) - def ivyDeps = Agg(build.Deps.junixsocket) + def ivyDeps = Agg(build.Deps.junixsocket, build.Deps.jline) object test extends JavaModuleTests with TestModule.Junit4 { - def ivyDeps = Agg( - build.Deps.junitInterface, - build.Deps.commonsIO - ) + def ivyDeps = Agg(build.Deps.junitInterface, build.Deps.commonsIO) } } diff --git a/main/server/test/src/mill/main/server/ClientServerTests.scala b/main/server/test/src/mill/main/server/ClientServerTests.scala index 31a316adb04..38980324b76 100644 --- a/main/server/test/src/mill/main/server/ClientServerTests.scala +++ b/main/server/test/src/mill/main/server/ClientServerTests.scala @@ -9,6 +9,8 @@ import mill.api.SystemStreams import scala.jdk.CollectionConverters._ import utest._ +import java.nio.file.Path + /** * Exercises the client-server logic in memory, using in-memory locks * and in-memory clients and servers @@ -94,7 +96,7 @@ object ClientServerTests extends TestSuite { memoryLocks, forceFailureForTestingMillisDelay ) { - def initServer(serverDir: String, b: Boolean, locks: Locks) = { + def initServer(serverDir: Path, b: Boolean, locks: Locks) = { val serverId = "server-" + nextServerId nextServerId += 1 new Thread(new EchoServer( diff --git a/main/src/mill/main/MainModule.scala b/main/src/mill/main/MainModule.scala index 109c37786d1..c84bc031705 100644 --- a/main/src/mill/main/MainModule.scala +++ b/main/src/mill/main/MainModule.scala @@ -49,7 +49,9 @@ object MainModule { case Right((watched, Right(res))) => val output = f(res) watched.foreach(watch0) - log.rawOutputStream.println(output.render(indent = 2)) + log.withPromptPaused { + println(output.render(indent = 2)) + } Result.Success(output) } } @@ -69,7 +71,9 @@ trait MainModule extends BaseModule0 { */ def version(): Command[String] = Target.command { val res = BuildInfo.millVersion - println(res) + Task.log.withPromptPaused { + println(res) + } res } @@ -87,7 +91,9 @@ trait MainModule extends BaseModule0 { case Left(err) => Result.Failure(err) case Right(resolvedSegmentsList) => val resolvedStrings = resolvedSegmentsList.map(_.render) - resolvedStrings.sorted.foreach(Target.log.outputStream.println) + Task.log.withPromptPaused { + resolvedStrings.sorted.foreach(println) + } Result.Success(resolvedStrings) } } @@ -101,7 +107,9 @@ trait MainModule extends BaseModule0 { case Left(err) => Result.Failure(err) case Right(success) => val renderedTasks = success.map(_.segments.render) - renderedTasks.foreach(Target.log.outputStream.println) + Task.log.withPromptPaused { + renderedTasks.foreach(println) + } Result.Success(renderedTasks) } } @@ -164,8 +172,9 @@ trait MainModule extends BaseModule0 { val labels = list .collect { case n: NamedTask[_] => n.ctx.segments.render } - labels.foreach(Target.log.outputStream.println(_)) - + Task.log.withPromptPaused { + labels.foreach(println) + } Result.Success(labels) } } @@ -284,7 +293,9 @@ trait MainModule extends BaseModule0 { for { str <- truncated ++ Iterator("\n") } sb.append(str) sb.toString() }).mkString("\n") - Target.log.outputStream.println(output) + Task.log.withPromptPaused { + println(output) + } fansi.Str(output).plainText } } @@ -439,7 +450,9 @@ trait MainModule extends BaseModule0 { in.put((rs, allRs, ctx.dest)) val res = out.take() res.map { v => - println(upickle.default.write(v.map(_.path.toString()), indent = 2)) + ctx.log.withPromptPaused { + println(upickle.default.write(v.map(_.path.toString()), indent = 2)) + } v } } diff --git a/main/test/src/mill/UTestFramework.scala b/main/test/src/mill/UTestFramework.scala index 7a5f7ad7fc7..491625df64b 100644 --- a/main/test/src/mill/UTestFramework.scala +++ b/main/test/src/mill/UTestFramework.scala @@ -1,10 +1,13 @@ package mill +import mill.api.SystemStreams + class UTestFramework extends utest.runner.Framework { override def exceptionStackFrameHighlighter(s: StackTraceElement): Boolean = { s.getClassName.startsWith("mill.") } override def setup(): Unit = { + SystemStreams.setTopLevelSystemStreamProxy() // force initialization os.remove.all(os.pwd / "target/workspace") } diff --git a/main/util/src/mill/util/AnsiNav.scala b/main/util/src/mill/util/AnsiNav.scala index a2b49ed5520..378ed57056f 100644 --- a/main/util/src/mill/util/AnsiNav.scala +++ b/main/util/src/mill/util/AnsiNav.scala @@ -2,28 +2,29 @@ package mill.util import java.io.Writer +// Reference https://gist.github.com/fnky/458719343aabd01cfb17a3a4f7296797 class AnsiNav(output: Writer) { - def control(n: Int, c: Char): Unit = output.write("\u001b[" + n + c) + def control(n: Int, c: Char): Unit = output.write(AnsiNav.control(n, c)) /** * Move up `n` squares */ - def up(n: Int): Any = if (n == 0) "" else control(n, 'A') + def up(n: Int): Any = if (n != 0) output.write(AnsiNav.up(n)) /** * Move down `n` squares */ - def down(n: Int): Any = if (n == 0) "" else control(n, 'B') + def down(n: Int): Any = if (n != 0) output.write(AnsiNav.down(n)) /** * Move right `n` squares */ - def right(n: Int): Any = if (n == 0) "" else control(n, 'C') + def right(n: Int): Any = if (n != 0) output.write(AnsiNav.right(n)) /** * Move left `n` squares */ - def left(n: Int): Any = if (n == 0) "" else control(n, 'D') + def left(n: Int): Any = if (n != 0) output.write(AnsiNav.left(n)) /** * Clear the screen @@ -32,7 +33,7 @@ class AnsiNav(output: Writer) { * n=1: clear from cursor to start of screen * n=2: clear entire screen */ - def clearScreen(n: Int): Unit = control(n, 'J') + def clearScreen(n: Int): Unit = output.write(AnsiNav.clearScreen(n)) /** * Clear the current line @@ -41,5 +42,15 @@ class AnsiNav(output: Writer) { * n=1: clear from cursor to start of line * n=2: clear entire line */ - def clearLine(n: Int): Unit = control(n, 'K') + def clearLine(n: Int): Unit = output.write(AnsiNav.clearLine(n)) +} + +object AnsiNav { + def control(n: Int, c: Char): String = "\u001b[" + n + c + def up(n: Int): String = if (n != 0) control(n, 'A') else "" + def down(n: Int): String = if (n != 0) control(n, 'B') else "" + def right(n: Int): String = if (n != 0) control(n, 'C') else "" + def left(n: Int): String = if (n != 0) control(n, 'D') else "" + def clearScreen(n: Int): String = control(n, 'J') + def clearLine(n: Int): String = control(n, 'K') } diff --git a/main/util/src/mill/util/DummyLogger.scala b/main/util/src/mill/util/DummyLogger.scala index 14685983ea5..082101ca5f2 100644 --- a/main/util/src/mill/util/DummyLogger.scala +++ b/main/util/src/mill/util/DummyLogger.scala @@ -19,4 +19,5 @@ object DummyLogger extends Logger { def ticker(s: String) = () def debug(s: String) = () override val debugEnabled: Boolean = false + } diff --git a/main/util/src/mill/util/FileLogger.scala b/main/util/src/mill/util/FileLogger.scala index b8ec7118205..e23d4ea03f2 100644 --- a/main/util/src/mill/util/FileLogger.scala +++ b/main/util/src/mill/util/FileLogger.scala @@ -11,6 +11,7 @@ class FileLogger( override val debugEnabled: Boolean, append: Boolean = false ) extends Logger { + override def toString: String = s"FileLogger($file)" private[this] var outputStreamUsed: Boolean = false lazy val fileStream: PrintStream = { @@ -52,6 +53,6 @@ class FileLogger( if (outputStreamUsed) outputStream.close() } - override def rawOutputStream: PrintStream = outputStream + } diff --git a/main/util/src/mill/util/LinePrefixOutputStream.scala b/main/util/src/mill/util/LinePrefixOutputStream.scala index 87a5a613190..3145b9ba28e 100644 --- a/main/util/src/mill/util/LinePrefixOutputStream.scala +++ b/main/util/src/mill/util/LinePrefixOutputStream.scala @@ -3,46 +3,77 @@ package mill.util import java.io.{ByteArrayOutputStream, FilterOutputStream, OutputStream} /** - * Prefixes the first and each new line with a dynamically provided prefix. + * Prefixes the first and each new line with a dynamically provided prefix, + * and buffers up each line in memory before writing to the [[out]] stream + * to prevent individual lines from being mixed together + * * @param linePrefix The function to provide the prefix. * @param out The underlying output stream. */ class LinePrefixOutputStream( linePrefix: String, - out: OutputStream + out: OutputStream, + reportPrefix: () => Unit ) extends FilterOutputStream(out) { - - private[this] var isFirst = true - + def this(linePrefix: String, out: OutputStream) = this(linePrefix, out, () => ()) + private[this] val linePrefixBytes = linePrefix.getBytes("UTF-8") + private[this] val linePrefixNonEmpty = linePrefixBytes.length != 0 + private[this] var isNewLine = true val buffer = new ByteArrayOutputStream() override def write(b: Array[Byte]): Unit = write(b, 0, b.length) - override def write(b: Array[Byte], off: Int, len: Int): Unit = { - var i = off - while (i < len) { - write(b(i)) - i += 1 + private[this] def writeLinePrefixIfNecessary(): Unit = { + if (isNewLine && linePrefixNonEmpty) { + isNewLine = false + buffer.write(linePrefixBytes) } } - override def write(b: Int): Unit = { - if (isFirst) { - isFirst = false - if (linePrefix != "") { - buffer.write(linePrefix.getBytes("UTF-8")) + def writeOutBuffer(): Unit = { + if (buffer.size() > 0) reportPrefix() + out.synchronized { buffer.writeTo(out) } + buffer.reset() + } + + override def write(b: Array[Byte], off: Int, len: Int): Unit = synchronized { + var start = off + var i = off + val max = off + len + while (i < max) { + writeLinePrefixIfNecessary() + if (b(i) == '\n') { + i += 1 // +1 to include the newline + buffer.write(b, start, i - start) + isNewLine = true + start = i + writeOutBuffer() } + i += 1 } + + if (math.min(i, max) - start > 0) { + writeLinePrefixIfNecessary() + buffer.write(b, start, math.min(i, max) - start) + if (b(max - 1) == '\n') writeOutBuffer() + } + + } + + override def write(b: Int): Unit = synchronized { + writeLinePrefixIfNecessary() buffer.write(b) if (b == '\n') { - flush() - isFirst = true + writeOutBuffer() + isNewLine = true } } - override def flush(): Unit = { - out.synchronized { - out.write(buffer.toByteArray) - } - buffer.reset() - super.flush() + override def flush(): Unit = synchronized { + writeOutBuffer() + out.flush() + } + + override def close(): Unit = { + flush() + out.close() } } diff --git a/main/util/src/mill/util/MultiLogger.scala b/main/util/src/mill/util/MultiLogger.scala index 850bcedba6d..4295cdf7b11 100644 --- a/main/util/src/mill/util/MultiLogger.scala +++ b/main/util/src/mill/util/MultiLogger.scala @@ -11,7 +11,7 @@ class MultiLogger( val inStream0: InputStream, override val debugEnabled: Boolean ) extends Logger { - + override def toString: String = s"MultiLogger($logger1, $logger2)" lazy val systemStreams = new SystemStreams( new MultiStream(logger1.systemStreams.out, logger2.systemStreams.out), new MultiStream(logger1.systemStreams.err, logger2.systemStreams.err), @@ -31,6 +31,20 @@ class MultiLogger( logger2.ticker(s) } + override def ticker(key: String, s: String): Unit = { + logger1.ticker(key, s) + logger2.ticker(key, s) + } + + private[mill] override def promptLine( + identifier: String, + identSuffix: String, + message: String + ): Unit = { + logger1.promptLine(identifier, identSuffix, message) + logger2.promptLine(identifier, identSuffix, message) + } + def debug(s: String): Unit = { logger1.debug(s) logger2.debug(s) @@ -40,8 +54,26 @@ class MultiLogger( logger1.close() logger2.close() } + private[mill] override def reportPrefix(s: String): Unit = { + logger1.reportPrefix(s) + logger2.reportPrefix(s) + } override def rawOutputStream: PrintStream = systemStreams.out + + private[mill] override def endTicker(key: String): Unit = { + logger1.endTicker(key) + logger2.endTicker(key) + } + private[mill] override def globalTicker(s: String): Unit = { + logger1.globalTicker(s) + logger2.globalTicker(s) + } + + override def withPromptPaused[T](t: => T): T = + logger1.withPromptPaused(logger2.withPromptPaused(t)) + + override def enableTicker: Boolean = logger1.enableTicker || logger2.enableTicker } class MultiStream(stream1: OutputStream, stream2: OutputStream) diff --git a/main/util/src/mill/util/PipeStreams.scala b/main/util/src/mill/util/PipeStreams.scala new file mode 100644 index 00000000000..c1f6b75d8e2 --- /dev/null +++ b/main/util/src/mill/util/PipeStreams.scala @@ -0,0 +1,176 @@ +package mill.util + +import java.io.{IOException, InputStream, OutputStream} + +/** + * Fork of `java.io.Piped{Input,Output}Stream` that allows writes to come from + * separate threads. Really the same logic just with the assertions on thread + * liveness removed, added some synchronization to ensure atomic writes, and + * somewhat cleaned up as a single object rather than two loose objects you have + * to connect together. + */ +class PipeStreams(val bufferSize: Int = 1024) { pipe => + + private var closedByWriter = false + @volatile private var closedByReader = false + private val buffer: Array[Byte] = new Array[Byte](bufferSize) + private var in: Int = -1 + private var out = 0 + + val input: InputStream = Input + private object Input extends InputStream { + + private[PipeStreams] def receive(b: Int): Unit = synchronized { + checkStateForReceive() + if (in == out) awaitSpace() + if (in < 0) { + in = 0 + out = 0 + } + buffer(in) = (b & 0xff).toByte + in += 1 + if (in >= buffer.length) in = 0 + notifyAll() + } + + private[PipeStreams] def receive(b: Array[Byte], off0: Int, len: Int): Unit = synchronized { + var off = off0 + checkStateForReceive() + var bytesToTransfer = len + while (bytesToTransfer > 0) { + if (in == out) awaitSpace() + var nextTransferAmount = 0 + if (out < in) nextTransferAmount = buffer.length - in + else if (in < out) { + if (in == -1) { + in = 0 + out = 0 + nextTransferAmount = buffer.length - in + } else { + nextTransferAmount = out - in + } + } + if (nextTransferAmount > bytesToTransfer) nextTransferAmount = bytesToTransfer + assert(nextTransferAmount > 0) + System.arraycopy(b, off, buffer, in, nextTransferAmount) + bytesToTransfer -= nextTransferAmount + off += nextTransferAmount + in += nextTransferAmount + if (in >= buffer.length) in = 0 + } + notifyAll() + } + + private def checkStateForReceive(): Unit = { + if (closedByWriter || closedByReader) throw new IOException("Pipe closed") + } + + private def awaitSpace(): Unit = { + while (in == out) { + checkStateForReceive() + /* full: kick any waiting readers */ + notifyWaitCatch() + } + } + + private[util] def receivedLast(): Unit = synchronized { + closedByWriter = true + notifyAll() + } + + private def notifyWaitCatch() = { + notifyAll() + try wait(1000) + catch { + case ex: InterruptedException => + throw new java.io.InterruptedIOException + } + } + + override def read(): Int = synchronized { + if (closedByReader) throw new IOException("Pipe closed") + while (in < 0) { + if (closedByWriter) return -1 /* closed by writer, return EOF */ + + /* might be a writer waiting */ + notifyWaitCatch() + } + + val ret = buffer(out) & 0xff + out += 1 + if (out >= buffer.length) out = 0 + if (in == out) in = -1 /* now empty */ + + ret + } + + override def read(b: Array[Byte], off: Int, len0: Int): Int = synchronized { + var len = len0 + if (b == null) throw new NullPointerException + else if (off < 0 || len < 0 || len > b.length - off) throw new IndexOutOfBoundsException + else if (len == 0) return 0 + /* possibly wait on the first character */ + val c = read + if (c < 0) return -1 + b(off) = c.toByte + var rlen = 1 + while ((in >= 0) && (len > 1)) { + var available = 0 + if (in > out) available = Math.min(buffer.length - out, in - out) + else available = buffer.length - out + // A byte is read beforehand outside the loop + + if (available > (len - 1)) available = len - 1 + System.arraycopy(buffer, out, b, off + rlen, available) + + out += available + rlen += available + len -= available + if (out >= buffer.length) out = 0 + if (in == out) in = -1 /* now empty */ + + } + rlen + } + + override def available(): Int = synchronized { + if (in < 0) 0 + else if (in == out) buffer.length + else if (in > out) in - out + else in + buffer.length - out + } + + override def close(): Unit = { + closedByReader = true + synchronized { + in = -1 + } + } + + override def readNBytes(b: Array[Byte], off: Int, len: Int): Int = + synchronized { super.readNBytes(b, off, len) } + + override def readNBytes(len: Int): Array[Byte] = synchronized { super.readNBytes(len) } + + override def readAllBytes(): Array[Byte] = synchronized { super.readAllBytes() } + + override def transferTo(out: OutputStream): Long = synchronized { super.transferTo(out) } + } + + val output: OutputStream = Output + private object Output extends OutputStream { + override def write(b: Int): Unit = synchronized { Input.receive(b) } + override def write(b: Array[Byte]): Unit = synchronized { super.write(b) } + override def write(b: Array[Byte], off: Int, len: Int): Unit = synchronized { + if (b == null) throw new NullPointerException + else if ( + (off < 0) || (off > b.length) || (len < 0) || ((off + len) > b.length) || ((off + len) < 0) + ) { + throw new IndexOutOfBoundsException + } else if (len != 0) Input.receive(b, off, len) + } + + override def flush(): Unit = () + override def close(): Unit = Input.receivedLast() + } +} diff --git a/main/util/src/mill/util/PrefixLogger.scala b/main/util/src/mill/util/PrefixLogger.scala index a9aa641515e..e5cf813075b 100644 --- a/main/util/src/mill/util/PrefixLogger.scala +++ b/main/util/src/mill/util/PrefixLogger.scala @@ -1,17 +1,20 @@ package mill.util import mill.api.SystemStreams +import pprint.Util.literalize import java.io.PrintStream class PrefixLogger( val logger0: ColorLogger, - context: String, + context0: String, tickerContext: String = "", outStream0: Option[PrintStream] = None, errStream0: Option[PrintStream] = None ) extends ColorLogger { - + val context: String = if (context0 == "") "" else context0 + " " + override def toString: String = + s"PrefixLogger($logger0, ${literalize(context)}, ${literalize(tickerContext)})" def this(logger0: ColorLogger, context: String, tickerContext: String) = this(logger0, context, tickerContext, None, None) @@ -24,13 +27,15 @@ class PrefixLogger( out = outStream0.getOrElse( new PrintStream(new LinePrefixOutputStream( infoColor(context).render, - logger0.systemStreams.out + logger0.systemStreams.out, + () => reportPrefix(context0) )) ), err = errStream0.getOrElse( new PrintStream(new LinePrefixOutputStream( infoColor(context).render, - logger0.systemStreams.err + logger0.systemStreams.err, + () => reportPrefix(context0) )) ), logger0.systemStreams.in @@ -38,19 +43,42 @@ class PrefixLogger( override def rawOutputStream = logger0.rawOutputStream - override def info(s: String): Unit = logger0.info(context + s) - override def error(s: String): Unit = logger0.error(context + s) - override def ticker(s: String): Unit = logger0.ticker(context + tickerContext + s) - override def debug(s: String): Unit = logger0.debug(context + s) + override def info(s: String): Unit = { + reportPrefix(context0) + logger0.info(infoColor(context) + s) + } + override def error(s: String): Unit = { + reportPrefix(context0) + logger0.error(infoColor(context) + s) + } + override def ticker(s: String): Unit = ticker(context0, s) + override def ticker(key: String, s: String): Unit = logger0.ticker(key, s) + + private[mill] override def promptLine(key: String, identSuffix: String, message: String): Unit = + logger0.promptLine(key, identSuffix, message) + + override def debug(s: String): Unit = { + if (debugEnabled) reportPrefix(context0) + logger0.debug(infoColor(context) + s) + } override def debugEnabled: Boolean = logger0.debugEnabled override def withOutStream(outStream: PrintStream): PrefixLogger = new PrefixLogger( logger0.withOutStream(outStream), - context, - tickerContext, + infoColor(context).toString(), + infoColor(tickerContext).toString(), outStream0 = Some(outStream), errStream0 = Some(systemStreams.err) ) + private[mill] override def reportPrefix(s: String): Unit = { + logger0.reportPrefix(s) + } + private[mill] override def endTicker(key: String): Unit = logger0.endTicker(key) + private[mill] override def globalTicker(s: String): Unit = logger0.globalTicker(s) + + override def withPromptPaused[T](t: => T): T = logger0.withPromptPaused(t) + + override def enableTicker = logger0.enableTicker } object PrefixLogger { diff --git a/main/util/src/mill/util/PrintLogger.scala b/main/util/src/mill/util/PrintLogger.scala index f59f65d66cd..510e605e9f9 100644 --- a/main/util/src/mill/util/PrintLogger.scala +++ b/main/util/src/mill/util/PrintLogger.scala @@ -5,7 +5,7 @@ import mill.api.SystemStreams class PrintLogger( override val colored: Boolean, - val enableTicker: Boolean, + override val enableTicker: Boolean, override val infoColor: fansi.Attrs, override val errorColor: fansi.Attrs, val systemStreams: SystemStreams, @@ -13,7 +13,7 @@ class PrintLogger( val context: String, printLoggerState: PrintLogger.State ) extends ColorLogger { - + override def toString: String = s"PrintLogger($colored, $enableTicker)" def info(s: String): Unit = synchronized { printLoggerState.value = PrintLogger.State.Newline systemStreams.err.println(infoColor(context + s)) @@ -24,6 +24,7 @@ class PrintLogger( systemStreams.err.println((infoColor(context) ++ errorColor(s)).render) } + override def ticker(key: String, s: String): Unit = synchronized { ticker(s) } def ticker(s: String): Unit = synchronized { if (enableTicker) { printLoggerState.value match { diff --git a/main/util/src/mill/util/PromptLogger.scala b/main/util/src/mill/util/PromptLogger.scala new file mode 100644 index 00000000000..39fa747bff4 --- /dev/null +++ b/main/util/src/mill/util/PromptLogger.scala @@ -0,0 +1,317 @@ +package mill.util + +import mill.api.SystemStreams +import mill.main.client.ProxyStream +import mill.util.PromptLoggerUtil.{ + Status, + clearScreenToEndBytes, + defaultTermHeight, + defaultTermWidth, + renderPrompt +} +import pprint.Util.literalize + +import java.io._ +import PromptLoggerUtil._ + +private[mill] class PromptLogger( + override val colored: Boolean, + override val enableTicker: Boolean, + override val infoColor: fansi.Attrs, + override val errorColor: fansi.Attrs, + systemStreams0: SystemStreams, + override val debugEnabled: Boolean, + titleText: String, + terminfoPath: os.Path, + currentTimeMillis: () => Long, + autoUpdate: Boolean = true +) extends ColorLogger with AutoCloseable { + override def toString: String = s"MultilinePromptLogger(${literalize(titleText)}" + import PromptLogger._ + + private var termDimensions: (Option[Int], Option[Int]) = (None, None) + + readTerminalDims(terminfoPath).foreach(termDimensions = _) + + private val state = new State( + titleText, + systemStreams0, + currentTimeMillis(), + () => termDimensions, + currentTimeMillis, + infoColor + ) + + private val streams = new Streams( + enableTicker, + systemStreams0, + () => state.currentPromptBytes, + interactive = () => termDimensions._1.nonEmpty + ) + + @volatile var stopped = false + @volatile var paused = false + + val promptUpdaterThread = new Thread(() => + while (!stopped) { + val promptUpdateInterval = + if (termDimensions._1.isDefined) promptUpdateIntervalMillis + else nonInteractivePromptUpdateIntervalMillis + + Thread.sleep(promptUpdateInterval) + + if (!paused) { + synchronized { + readTerminalDims(terminfoPath).foreach(termDimensions = _) + refreshPrompt() + } + } + } + ) + + def refreshPrompt(): Unit = state.refreshPrompt() + if (enableTicker && autoUpdate) promptUpdaterThread.start() + + override def withPromptPaused[T](t: => T): T = { + paused = true + + try { + // Clear the prompt so the code in `t` has a blank terminal to work with + outputStream.flush() + errorStream.flush() + rawOutputStream.write(AnsiNav.clearScreen(0).getBytes) + SystemStreams.withStreams(systemStreams0) { + t + } + } finally paused = false + } + + def info(s: String): Unit = synchronized { systemStreams.err.println(s) } + + def error(s: String): Unit = synchronized { systemStreams.err.println(s) } + + override def globalTicker(s: String): Unit = synchronized { state.updateGlobal(s) } + override def clearAllTickers(): Unit = synchronized { state.clearStatuses() } + override def endTicker(key: String): Unit = synchronized { state.updateCurrent(key, None) } + + def ticker(s: String): Unit = () + override def ticker(key: String, s: String): Unit = { + state.updateDetail(key, s) + } + + override def reportPrefix(s: String): Unit = synchronized { + if (!reportedIdentifiers(s)) { + reportedIdentifiers.add(s) + for ((identSuffix, message) <- seenIdentifiers.get(s)) { + systemStreams.err.println(infoColor(s"$identSuffix $message")) + } + } + } + + def streamsAwaitPumperEmpty(): Unit = streams.awaitPumperEmpty() + private val seenIdentifiers = collection.mutable.Map.empty[String, (String, String)] + private val reportedIdentifiers = collection.mutable.Set.empty[String] + override def promptLine(key: String, identSuffix: String, message: String): Unit = + synchronized { + state.updateCurrent(key, Some(s"$key $message")) + seenIdentifiers(key) = (identSuffix, message) + super.promptLine(infoColor(key).toString(), identSuffix, message) + + } + def debug(s: String): Unit = synchronized { if (debugEnabled) systemStreams.err.println(s) } + + override def rawOutputStream: PrintStream = systemStreams0.out + + override def close(): Unit = synchronized { + if (enableTicker) state.refreshPrompt(ending = true) + streams.close() + stopped = true + } + + def systemStreams = streams.systemStreams +} + +private[mill] object PromptLogger { + + private class Streams( + enableTicker: Boolean, + systemStreams0: SystemStreams, + currentPromptBytes: () => Array[Byte], + interactive: () => Boolean + ) { + + // We force both stdout and stderr streams into a single `Piped*Stream` pair via + // `ProxyStream`, as we need to preserve the ordering of writes to each individual + // stream, and also need to know when *both* streams are quiescent so that we can + // print the prompt at the bottom + val pipe = new PipeStreams() + val proxyOut = new ProxyStream.Output(pipe.output, ProxyStream.OUT) + val proxyErr: ProxyStream.Output = new ProxyStream.Output(pipe.output, ProxyStream.ERR) + val systemStreams = new SystemStreams( + new PrintStream(proxyOut), + new PrintStream(proxyErr), + systemStreams0.in + ) + + def awaitPumperEmpty(): Unit = { + while (pipe.input.available() != 0) Thread.sleep(10) + } + object pumper extends ProxyStream.Pumper(pipe.input, systemStreams0.out, systemStreams0.err) { + object PumperState extends Enumeration { + val init, prompt, cleared = Value + } + var pumperState = PumperState.init + override def preRead(src: InputStream): Unit = { + // Only bother printing the propmt after the streams have become quiescent + // and there is no more stuff to print. This helps us printing the prompt on + // every small write when most such prompts will get immediately over-written + // by subsequent writes + if (enableTicker && src.available() == 0) { + if (interactive()) { + systemStreams0.err.write(currentPromptBytes()) + } + pumperState = PumperState.prompt + } + } + + override def preWrite(): Unit = { + // Before any write, make sure we clear the terminal of any prompt that was + // written earlier and not yet cleared, so the following output can be written + // to a clean section of the terminal + if (interactive() && pumperState != PumperState.cleared) + systemStreams0.err.write(clearScreenToEndBytes) + pumperState = PumperState.cleared + } + } + + val pumperThread = new Thread(pumper) + pumperThread.start() + + def close(): Unit = { + // Close the write side of the pipe first but do not close the read side, so + // the `pumperThread` can continue reading remaining text in the pipe buffer + // before terminating on its own + ProxyStream.sendEnd(pipe.output) + pipe.output.close() + pumperThread.join() + } + } + private class State( + titleText: String, + systemStreams0: SystemStreams, + startTimeMillis: Long, + consoleDims: () => (Option[Int], Option[Int]), + currentTimeMillis: () => Long, + infoColor: fansi.Attrs + ) { + private var lastRenderedPromptHash = 0 + private val statuses = collection.mutable.SortedMap.empty[String, Status] + + private var headerPrefix = "" + // Pre-compute the prelude and current prompt as byte arrays so that + // writing them out is fast, since they get written out very frequently + + @volatile var currentPromptBytes: Array[Byte] = Array[Byte]() + + private def updatePromptBytes(ending: Boolean = false) = { + val now = currentTimeMillis() + for (k <- statuses.keySet) { + val removedTime = statuses(k).beginTransitionTime + if (statuses(k).next.isEmpty && (now - removedTime > statusRemovalRemoveDelayMillis)) { + statuses.remove(k) + } + } + + // For the ending prompt, make sure we clear out all + // the statuses to only show the header alone + if (ending) statuses.clear() + + val (termWidth0, termHeight0) = consoleDims() + // don't show prompt for non-interactive terminal + val currentPromptLines = renderPrompt( + termWidth0.getOrElse(defaultTermWidth), + termHeight0.getOrElse(defaultTermHeight), + now, + startTimeMillis, + headerPrefix, + titleText, + statuses, + interactive = consoleDims()._1.nonEmpty, + infoColor = infoColor, + ending = ending + ) + + val currentPromptStr = + if (termWidth0.isEmpty) currentPromptLines.mkString("\n") + "\n" + else { + // For the ending prompt, leave the cursor at the bottom on a new line rather than + // scrolling back left/up. We do not want further output to overwrite the header as + // it will no longer re-render + val backUp = + if (ending) "\n" + else AnsiNav.left(9999) + AnsiNav.up(currentPromptLines.length - 1) + + AnsiNav.clearScreen(0) + + currentPromptLines.mkString("\n") + + backUp + } + + currentPromptBytes = currentPromptStr.getBytes + + } + + def clearStatuses(): Unit = synchronized { statuses.clear() } + def updateGlobal(s: String): Unit = synchronized { headerPrefix = s } + + def updateDetail(key: String, detail: String): Unit = synchronized { + statuses.updateWith(key)(_.map(se => se.copy(next = se.next.map(_.copy(detail = detail))))) + } + + def updateCurrent(key: String, sOpt: Option[String]): Unit = synchronized { + + val now = currentTimeMillis() + def stillTransitioning(status: Status) = { + status.beginTransitionTime + statusRemovalHideDelayMillis > now + } + val sOptEntry = sOpt.map(StatusEntry(_, now, "")) + statuses.updateWith(key) { + case None => + statuses.find { case (k, v) => v.next.isEmpty && stillTransitioning(v) } match { + case Some((reusableKey, reusableValue)) => + statuses.remove(reusableKey) + Some(reusableValue.copy(next = sOptEntry)) + case None => Some(Status(sOptEntry, now, None)) + } + + case Some(existing) => + Some( + // If still performing a transition, do not update the `prevTransitionTime` + // since we do not want to delay the transition that is already in progress + if (stillTransitioning(existing)) existing.copy(next = sOptEntry) + else { + existing.copy( + next = sOptEntry, + beginTransitionTime = now, + prev = existing.next + ) + } + ) + } + } + + def refreshPrompt(ending: Boolean = false): Unit = synchronized { + + // For non-interactive jobs, we only want to print the new prompt if the contents + // differs from the previous prompt, since the prompts do not overwrite each other + // in log files and printing large numbers of identical prompts is spammy and useless + + lazy val statusesHashCode = statuses.hashCode + if (consoleDims()._1.nonEmpty || statusesHashCode != lastRenderedPromptHash) { + lastRenderedPromptHash = statusesHashCode + updatePromptBytes(ending) + systemStreams0.err.write(currentPromptBytes) + } + } + } + +} diff --git a/main/util/src/mill/util/PromptLoggerUtil.scala b/main/util/src/mill/util/PromptLoggerUtil.scala new file mode 100644 index 00000000000..319932a4086 --- /dev/null +++ b/main/util/src/mill/util/PromptLoggerUtil.scala @@ -0,0 +1,204 @@ +package mill.util + +private object PromptLoggerUtil { + + private[mill] val defaultTermWidth = 119 + private[mill] val defaultTermHeight = 50 + + /** + * How often to update the multiline status prompt on the terminal. + * Too frequent is bad because it causes a lot of visual noise, + * but too infrequent results in latency. 10 times per second seems reasonable + */ + private[mill] val promptUpdateIntervalMillis = 100 + + /** + * How often to update the multiline status prompt in noninteractive scenarios, + * e.g. background job logs or piped to a log file. Much less frequent than the + * interactive scenario because we cannot rely on ANSI codes to over-write the + * previous prompt, so we have to be a lot more conservative to avoid spamming + * the logs, but we still want to print it occasionally so people can debug stuck + * background or CI jobs and see what tasks it is running when stuck + */ + private[mill] val nonInteractivePromptUpdateIntervalMillis = 60000 + + /** + * Add some extra latency delay to the process of removing an entry from the status + * prompt entirely, because removing an entry changes the height of the prompt, which + * is even more distracting than changing the contents of a line, so we want to minimize + * those occurrences even further. + */ + val statusRemovalHideDelayMillis = 250 + + /** + * How long to wait before actually removing the blank line left by a removed status + * and reducing the height of the prompt. Having the prompt change height is even more + * distracting than having entries in the prompt disappear, so give it a longer timeout + * so it happens less. + */ + val statusRemovalRemoveDelayMillis = 2000 + + private[mill] case class StatusEntry(text: String, startTimeMillis: Long, detail: String = "") + + /** + * Represents a line in the prompt. Stores up to two separate [[StatusEntry]]s, because + * we want to buffer up status transitions to debounce them. Which status entry is currently + * shown depends on the [[beginTransitionTime]] and other heuristics + */ + private[mill] case class Status( + next: Option[StatusEntry], + beginTransitionTime: Long, + prev: Option[StatusEntry] + ) + + private[mill] val clearScreenToEndBytes: Array[Byte] = AnsiNav.clearScreen(0).getBytes + + private def renderSecondsSuffix(millis: Long) = (millis / 1000).toInt match { + case 0 => "" + case n => s" ${n}s" + } + + def readTerminalDims(terminfoPath: os.Path): Option[(Option[Int], Option[Int])] = { + try { + val s"$termWidth0 $termHeight0" = os.read(terminfoPath) + Some( + Tuple2( + termWidth0.toInt match { + case -1 | 0 => None + case n => Some(n) + }, + termHeight0.toInt match { + case -1 | 0 => None + case n => Some(n) + } + ) + ) + } catch { case e => None } + } + + def renderPrompt( + consoleWidth: Int, + consoleHeight: Int, + now: Long, + startTimeMillis: Long, + headerPrefix: String, + titleText: String, + statuses: collection.SortedMap[String, Status], + interactive: Boolean, + infoColor: fansi.Attrs, + ending: Boolean = false + ): List[String] = { + // -1 to leave a bit of buffer + val maxWidth = consoleWidth - 1 + // -1 to account for header + val maxHeight = math.max(1, consoleHeight / 3 - 1) + val headerSuffix = renderSecondsSuffix(now - startTimeMillis) + + val header = renderHeader(headerPrefix, titleText, headerSuffix, maxWidth, ending, interactive) + + val body0 = statuses + .flatMap { + case (threadId, status) => + // For statuses that have completed transitioning from Some to None, continue + // rendering them as an empty line for `statusRemovalRemoveDelayMillis` to try + // and maintain prompt height and stop it from bouncing up and down + if ( + status.prev.nonEmpty && + status.next.isEmpty && + status.beginTransitionTime + statusRemovalHideDelayMillis < now && + status.beginTransitionTime > now - statusRemovalRemoveDelayMillis + ) { + Some("") + } else { + val textOpt = if (status.beginTransitionTime + statusRemovalHideDelayMillis < now) + status.next + else status.prev + textOpt.map { t => + val seconds = renderSecondsSuffix(now - t.startTimeMillis) + val mainText = splitShorten(t.text + seconds, maxWidth) + + val detail = + if (t.detail == "") "" + else splitShorten(" " + t.detail, maxWidth - mainText.length) + + mainText + infoColor(detail) + } + } + } + // For non-interactive jobs, we do not need to preserve the height of the prompt + // between renderings, since consecutive prompts do not appear at the same place + // in the log file. Thus we can aggressively remove all blank spacer lines + .filter(_.nonEmpty || interactive) + .toList + // Sort alphabetically because the `#nn` prefix is part of the string, and then + // put all empty strings last since those are less important and can be ignored + .sortBy(x => (x.isEmpty, x)) + + val nonEmptyBodyCount = body0.count(_.nonEmpty) + val body = + if (nonEmptyBodyCount <= maxHeight) body0.take(maxHeight) + else body0.take(maxHeight - 1) ++ Seq( + s"... and ${nonEmptyBodyCount - maxHeight + 1} more threads" + ) + + // For non-interactive jobs, the prompt won't be at the bottom of the terminal but + // will instead be in the middle of a big log file with logs above and below, so we + // need some kind of footer to tell the reader when the prompt ends and logs begin + val footer = Option.when(!interactive)("=" * maxWidth).toList + + header :: body ::: footer + } + + def renderHeader( + headerPrefix0: String, + titleText0: String, + headerSuffix0: String, + maxWidth: Int, + ending: Boolean = false, + interactive: Boolean = true + ): String = { + val headerPrefixStr = if (!interactive || ending) s"$headerPrefix0 " else s" $headerPrefix0 " + val headerSuffixStr = headerSuffix0 + val titleText = s" $titleText0 " + // -12 just to ensure we always have some ==== divider on each side of the title + val maxTitleLength = + maxWidth - math.max(headerPrefixStr.length, headerSuffixStr.length) * 2 - 12 + val shortenedTitle = splitShorten(titleText, maxTitleLength) + + // +2 to offset the title a bit to the right so it looks centered, as the `headerPrefixStr` + // is usually longer than `headerSuffixStr`. We use a fixed offset rather than dynamically + // offsetting by `headerPrefixStr.length` to prevent the title from shifting left and right + // as the `headerPrefixStr` changes, even at the expense of it not being perfectly centered. + val leftDivider = "=" * ((maxWidth / 2) - (titleText.length / 2) - headerPrefixStr.length + 2) + val rightDivider = + "=" * (maxWidth - headerPrefixStr.length - leftDivider.length - shortenedTitle.length - headerSuffixStr.length) + val headerString = + headerPrefixStr + leftDivider + shortenedTitle + rightDivider + headerSuffixStr + assert( + headerString.length == maxWidth, + s"${pprint.apply(headerString)} is length ${headerString.length}, requires $maxWidth" + ) + headerString + } + + def splitShorten(s: String, maxLength: Int): String = { + if (s.length <= maxLength) s + else { + val ellipses = "..." + val nonEllipsesLength = maxLength - ellipses.length + val halfWidth = nonEllipsesLength / 2 + val halfWidth2 = nonEllipsesLength - halfWidth + s.take(halfWidth2) + ellipses.take(maxLength) + s.takeRight(halfWidth) + } + } + + def lastIndexOfNewline(b: Array[Byte], off: Int, len: Int): Int = { + var index = off + len - 1 + while (true) { + if (index < off) return -1 + else if (b(index) == '\n') return index + else index -= 1 + } + ??? + } +} diff --git a/main/util/src/mill/util/ProxyLogger.scala b/main/util/src/mill/util/ProxyLogger.scala index b7448ae6f04..e76b437e19a 100644 --- a/main/util/src/mill/util/ProxyLogger.scala +++ b/main/util/src/mill/util/ProxyLogger.scala @@ -9,6 +9,7 @@ import java.io.PrintStream * used as a base class for wrappers that modify logging behavior. */ class ProxyLogger(logger: Logger) extends Logger { + override def toString: String = s"ProxyLogger($logger)" def colored = logger.colored lazy val systemStreams = logger.systemStreams @@ -16,11 +17,20 @@ class ProxyLogger(logger: Logger) extends Logger { def info(s: String): Unit = logger.info(s) def error(s: String): Unit = logger.error(s) def ticker(s: String): Unit = logger.ticker(s) + override def ticker(key: String, s: String): Unit = logger.ticker(key, s) + private[mill] override def promptLine(key: String, identSuffix: String, message: String): Unit = + logger.promptLine(key, identSuffix, message) def debug(s: String): Unit = logger.debug(s) override def debugEnabled: Boolean = logger.debugEnabled override def close(): Unit = logger.close() + private[mill] override def reportPrefix(s: String): Unit = logger.reportPrefix(s) override def rawOutputStream: PrintStream = logger.rawOutputStream + private[mill] override def endTicker(key: String): Unit = logger.endTicker(key) + private[mill] override def globalTicker(s: String): Unit = logger.globalTicker(s) + override def withPromptPaused[T](t: => T): T = logger.withPromptPaused(t) + + override def enableTicker = logger.enableTicker } diff --git a/main/util/test/src/mill/util/LinePrefixOutputStreamTests.scala b/main/util/test/src/mill/util/LinePrefixOutputStreamTests.scala new file mode 100644 index 00000000000..ca114de48dd --- /dev/null +++ b/main/util/test/src/mill/util/LinePrefixOutputStreamTests.scala @@ -0,0 +1,66 @@ +package mill.util + +import utest._ + +import java.io.ByteArrayOutputStream + +object LinePrefixOutputStreamTests extends TestSuite { + val tests = Tests { + test("charByChar") { + val baos = new ByteArrayOutputStream() + val lpos = new LinePrefixOutputStream("PREFIX", baos) + for (b <- "hello\nworld\n!".getBytes()) lpos.write(b) + lpos.flush() + assert(baos.toString == "PREFIXhello\nPREFIXworld\nPREFIX!") + } + + test("charByCharTrailingNewline") { + val baos = new ByteArrayOutputStream() + val lpos = new LinePrefixOutputStream("PREFIX", baos) + for (b <- "hello\nworld\n".getBytes()) lpos.write(b) + lpos.flush() + assert(baos.toString == "PREFIXhello\nPREFIXworld\n") + } + + test("allAtOnce") { + val baos = new ByteArrayOutputStream() + val lpos = new LinePrefixOutputStream("PREFIX", baos) + val arr = "hello\nworld\n!".getBytes() + lpos.write(arr) + lpos.flush() + + assert(baos.toString == "PREFIXhello\nPREFIXworld\nPREFIX!") + } + + test("allAtOnceTrailingNewline") { + val baos = new ByteArrayOutputStream() + val lpos = new LinePrefixOutputStream("PREFIX", baos) + val arr = "hello\nworld\n".getBytes() + lpos.write(arr) + lpos.flush() + + assert(baos.toString == "PREFIXhello\nPREFIXworld\n") + } + + test("ranges") { + for (str <- Seq("hello\nworld\n")) { + val arr = str.getBytes() + for (i1 <- Range(0, arr.length)) { + for (i2 <- Range(i1, arr.length)) { + for (i3 <- Range(i2, arr.length)) { + val baos = new ByteArrayOutputStream() + val lpos = new LinePrefixOutputStream("PREFIX", baos) + lpos.write(arr, 0, i1) + lpos.write(arr, i1, i2 - i1) + lpos.write(arr, i2, i3 - i2) + lpos.write(arr, i3, arr.length - i3) + lpos.flush() + assert(baos.toString == "PREFIXhello\nPREFIXworld\n") + } + } + } + } + + } + } +} diff --git a/main/util/test/src/mill/util/PipeStreamsTests.scala b/main/util/test/src/mill/util/PipeStreamsTests.scala new file mode 100644 index 00000000000..ab009adcc1e --- /dev/null +++ b/main/util/test/src/mill/util/PipeStreamsTests.scala @@ -0,0 +1,130 @@ +package mill.util + +import utest._ + +import java.util.concurrent.Executors +import scala.concurrent._ +import scala.concurrent.ExecutionContext.Implicits._ +import scala.concurrent.duration.Duration._ + +object PipeStreamsTests extends TestSuite { + val tests = Tests { + test("hello") { // Single write and read works + val pipe = new PipeStreams() + val data = Array[Byte](1, 2, 3, 4, 5, 0, 3) + assert(data.length < pipe.bufferSize) + + pipe.output.write(data) + + val out = new Array[Byte](7) + pipe.input.read(out) + out ==> data + } + + test("multiple") { // Single sequential write and read works + val pipe = new PipeStreams() + val chunkSize = 10 + val chunkCount = 100 + for (i <- Range(0, chunkCount)) { + pipe.output.write(Array.fill(chunkSize)(i.toByte)) + } + + for (i <- Range(0, chunkCount)) { + pipe.input.readNBytes(chunkSize) ==> Array.fill(chunkSize)(i.toByte) + } + } + test("concurrentWriteRead") { // Single sequential write and read works + val pipe = new PipeStreams(bufferSize = 13) + val chunkSize = 20 + val chunkCount = 100 + assert(pipe.bufferSize < chunkSize * chunkCount) // ensure it gets filled + val writer = Future { + for (i <- Range(0, chunkCount)) { + pipe.output.write(Array.fill(chunkSize)(i.toByte)) + } + } + + Thread.sleep(100) // Give it time for pipe to fill up + + val reader = Future { + for (i <- Range(0, chunkCount)) yield { + pipe.input.readNBytes(chunkSize).toSeq + } + } + + val result = Await.result(reader, Inf) + val expected = Seq.tabulate(chunkCount)(i => Array.fill(chunkSize)(i.toByte).toSeq) + result ==> expected + } + test("multiThreadWrite") { // multiple writes across different threads followed by read + val chunkSize = 10 + val chunkCount = 100 + val pipe = new PipeStreams() + assert(chunkSize * chunkCount < pipe.bufferSize) + val writerPool = ExecutionContext.fromExecutorService(Executors.newFixedThreadPool(40)) + val writeFutures = + for (i <- Range(0, chunkCount)) yield Future { + pipe.output.write(Array.fill(chunkSize)(i.toByte)) + }(writerPool) + + Await.ready(Future.sequence(writeFutures), Inf) + + val out = pipe.input.readNBytes(chunkSize * chunkCount) + + val expectedLists = + for (i <- Range(0, chunkCount)) + yield Array.fill(chunkSize)(i.toByte).toSeq + + val sortedGroups = out.toSeq.grouped(chunkSize).toSeq.sortBy(_.head).toVector + + sortedGroups ==> expectedLists + } + test("multiThreadWriteConcurrentRead") { // multiple writes across different threads interleaved by reads + val chunkSize = 20 + val chunkCount = 100 + val pipe = new PipeStreams(bufferSize = 113) + assert(chunkSize * chunkCount > pipe.bufferSize) + val writerPool = ExecutionContext.fromExecutorService(Executors.newFixedThreadPool(40)) + for (i <- Range(0, chunkCount)) yield Future { + pipe.output.write(Array.fill(chunkSize)(i.toByte)) + }(writerPool) + + val out = pipe.input.readNBytes(chunkSize * chunkCount) + + val expectedLists = + for (i <- Range(0, chunkCount)) + yield Array.fill(chunkSize)(i.toByte).toSeq + + val sortedGroups = out.toSeq.grouped(chunkSize).toSeq.sortBy(_.head).toVector + + sortedGroups ==> expectedLists + } + // Not sure why this use case doesn't work yet + // test("multiThreadWriteMultiThreadRead"){ // multiple writes across different threads interleaved by reads + // val chunkSize = 20 + // val chunkCount = 100 + // val pipe = new PipeStreams(bufferSize = 137) + // val writerPool = ExecutionContext.fromExecutorService(Executors.newFixedThreadPool(100)) + // val readerPool = ExecutionContext.fromExecutorService(Executors.newFixedThreadPool(100)) + // for(i <- Range(0, chunkCount)) yield Future{ + // pipe.output.write(Array.fill(chunkSize)(i.toByte)) + // }(writerPool) + // + // val reader = for (i <- Range(0, chunkCount)) yield Future { + // pipe.input.readNBytes(chunkSize).toSeq + // }(readerPool) + // + // + // val out = Await.result(Future.sequence(reader), Inf) + // val expectedLists = + // for(i <- Range(0, chunkCount)) + // yield Array.fill(chunkSize)(i.toByte).toSeq + // + // val sortedGroups = out.sortBy(_.head).toVector + // + // pprint.log(sortedGroups) + // pprint.log(expectedLists) + // sortedGroups ==> expectedLists + // } + } +} diff --git a/main/util/test/src/mill/util/PromptLoggerTests.scala b/main/util/test/src/mill/util/PromptLoggerTests.scala new file mode 100644 index 00000000000..a1d9600ac09 --- /dev/null +++ b/main/util/test/src/mill/util/PromptLoggerTests.scala @@ -0,0 +1,358 @@ +package mill.util + +import mill.api.SystemStreams +import mill.main.client.ProxyStream +import utest._ + +import java.io.{ByteArrayInputStream, ByteArrayOutputStream, PrintStream} +object PromptLoggerTests extends TestSuite { + + def setup(now: () => Long, terminfoPath: os.Path) = { + val baos = new ByteArrayOutputStream() + val baosOut = new PrintStream(new ProxyStream.Output(baos, ProxyStream.OUT)) + val baosErr = new PrintStream(new ProxyStream.Output(baos, ProxyStream.ERR)) + val promptLogger = new PromptLogger( + colored = false, + enableTicker = true, + infoColor = fansi.Attrs.Empty, + errorColor = fansi.Attrs.Empty, + systemStreams0 = new SystemStreams(baosOut, baosErr, System.in), + debugEnabled = false, + titleText = "TITLE", + terminfoPath = terminfoPath, + currentTimeMillis = now, + autoUpdate = false + ) { + // For testing purposes, wait till the system is quiescent before re-printing + // the prompt, to try and keep the test executions deterministics + override def refreshPrompt(): Unit = { + streamsAwaitPumperEmpty() + super.refreshPrompt() + } + } + val prefixLogger = new PrefixLogger(promptLogger, "[1]") + (baos, promptLogger, prefixLogger) + } + + def check( + promptLogger: PromptLogger, + baos: ByteArrayOutputStream, + width: Int = 80 + )(expected: String*) = { + promptLogger.streamsAwaitPumperEmpty() + val finalBaos = new ByteArrayOutputStream() + val pumper = + new ProxyStream.Pumper(new ByteArrayInputStream(baos.toByteArray), finalBaos, finalBaos) + pumper.run() + val term = new TestTerminal(width) + term.writeAll(finalBaos.toString) + val lines = term.grid + + assert(lines == expected) + } + + val tests = Tests { + test("nonInteractive") { + // These tests seem flaky on windows but not sure why + if (!Util.windowsPlatform) { + var now = 0L + + val (baos, promptLogger, prefixLogger) = setup(() => now, os.temp()) + + promptLogger.globalTicker("123/456") + promptLogger.promptLine("[1]", "[1/456]", "my-task") + + now += 10000 + + prefixLogger.outputStream.println("HELLO") + + promptLogger.refreshPrompt() + + prefixLogger.outputStream.println("WORLD") + + promptLogger.endTicker("[1]") + + now += 10000 + promptLogger.refreshPrompt() + now += 10000 + promptLogger.close() + + check(promptLogger, baos, width = 999 /*log file has no line wrapping*/ )( + // Make sure that the first time a prefix is reported, + // we print the verbose prefix along with the ticker string + "[1/456] my-task", + // Further `println`s come with the prefix + "[1] HELLO", + // Calling `refreshPrompt()` prints the header with the given `globalTicker` without + // the double space prefix (since it's non-interactive and we don't need space for a cursor), + // the time elapsed, the reported title and ticker, the list of active tickers, followed by the + // footer + "123/456 ================================================== TITLE ================================================= 10s", + "[1] my-task 10s", + "======================================================================================================================", + "[1] WORLD", + // Calling `refreshPrompt()` after closing the ticker shows the prompt without + // the ticker in the list, with an updated time elapsed + "123/456 ================================================== TITLE ================================================= 20s", + "======================================================================================================================", + // Closing the prompt prints the prompt one last time with an updated time elapsed + "123/456 ================================================== TITLE ================================================= 30s", + "======================================================================================================================", + "" + ) + } + } + + test("interactive") { + if (!Util.windowsPlatform) { + var now = 0L + val (baos, promptLogger, prefixLogger) = setup(() => now, os.temp("80 40")) + + promptLogger.globalTicker("123/456") + promptLogger.refreshPrompt() + check(promptLogger, baos)( + " 123/456 ============================ TITLE ==================================" + ) + promptLogger.promptLine("[1]", "[1/456]", "my-task") + + now += 10000 + + prefixLogger.outputStream.println("HELLO") + + promptLogger.refreshPrompt() // Need to call `refreshPrompt()` for prompt to change + // First time we log with the prefix `[1]`, make sure we print out the title line + // `[1/456] my-task` so the viewer knows what `[1]` refers to + check(promptLogger, baos)( + "[1/456] my-task", + "[1] HELLO", + " 123/456 ============================ TITLE ============================== 10s", + "[1] my-task 10s" + ) + + prefixLogger.outputStream.println("WORLD") + // Prompt doesn't change, no need to call `refreshPrompt()` for it to be + // re-rendered below the latest prefixed output. Subsequent log line with `[1]` + // prefix does not re-render title line `[1/456] ...` + check(promptLogger, baos)( + "[1/456] my-task", + "[1] HELLO", + "[1] WORLD", + " 123/456 ============================ TITLE ============================== 10s", + "[1] my-task 10s" + ) + + // Adding new ticker entries doesn't appear immediately, + // Only after some time has passed do we start displaying the new ticker entry, + // to ensure it is meaningful to read and not just something that will flash and disappear + val newPrefixLogger2 = new PrefixLogger(promptLogger, "[2]") + newPrefixLogger2.promptLine("[2]", "[2/456]", "my-task-new") + newPrefixLogger2.errorStream.println("I AM COW") + newPrefixLogger2.errorStream.println("HEAR ME MOO") + + // For short-lived ticker entries that are removed quickly, they never + // appear in the prompt at all even though they can run and generate logs + val newPrefixLogger3 = new PrefixLogger(promptLogger, "[3]") + newPrefixLogger3.promptLine("[3]", "[3/456]", "my-task-short-lived") + newPrefixLogger3.errorStream.println("hello short lived") + newPrefixLogger3.errorStream.println("goodbye short lived") + + // my-task-new does not appear yet because it is too new + promptLogger.refreshPrompt() + check(promptLogger, baos)( + "[1/456] my-task", + "[1] HELLO", + "[1] WORLD", + "[2/456] my-task-new", + "[2] I AM COW", + "[2] HEAR ME MOO", + "[3/456] my-task-short-lived", + "[3] hello short lived", + "[3] goodbye short lived", + " 123/456 ============================ TITLE ============================== 10s", + "[1] my-task 10s" + ) + + newPrefixLogger3.endTicker("[3]") + + now += 1000 + + // my-task-new appears by now, but my-task-short-lived has already ended and never appears + promptLogger.refreshPrompt() + check(promptLogger, baos)( + "[1/456] my-task", + "[1] HELLO", + "[1] WORLD", + "[2/456] my-task-new", + "[2] I AM COW", + "[2] HEAR ME MOO", + "[3/456] my-task-short-lived", + "[3] hello short lived", + "[3] goodbye short lived", + " 123/456 ============================ TITLE ============================== 11s", + "[1] my-task 11s", + "[2] my-task-new 1s" + ) + + promptLogger.endTicker("[1]") + + now += 10 + + // Even after ending my-task, it remains on the ticker for a moment before being removed + promptLogger.refreshPrompt() + check(promptLogger, baos)( + "[1/456] my-task", + "[1] HELLO", + "[1] WORLD", + "[2/456] my-task-new", + "[2] I AM COW", + "[2] HEAR ME MOO", + "[3/456] my-task-short-lived", + "[3] hello short lived", + "[3] goodbye short lived", + " 123/456 ============================ TITLE ============================== 11s", + "[1] my-task 11s", + "[2] my-task-new 1s" + ) + + now += 1000 + + // When my-task disappears from the ticker, it leaves a blank line for a + // moment to preserve the height of the prompt + promptLogger.refreshPrompt() + check(promptLogger, baos)( + "[1/456] my-task", + "[1] HELLO", + "[1] WORLD", + "[2/456] my-task-new", + "[2] I AM COW", + "[2] HEAR ME MOO", + "[3/456] my-task-short-lived", + "[3] hello short lived", + "[3] goodbye short lived", + " 123/456 ============================ TITLE ============================== 12s", + "[2] my-task-new 2s", + "" + ) + + now += 10000 + + // Only after more time does the prompt shrink back + promptLogger.refreshPrompt() + check(promptLogger, baos)( + "[1/456] my-task", + "[1] HELLO", + "[1] WORLD", + "[2/456] my-task-new", + "[2] I AM COW", + "[2] HEAR ME MOO", + "[3/456] my-task-short-lived", + "[3] hello short lived", + "[3] goodbye short lived", + " 123/456 ============================ TITLE ============================== 22s", + "[2] my-task-new 12s" + ) + now += 10000 + promptLogger.close() + check(promptLogger, baos)( + "[1/456] my-task", + "[1] HELLO", + "[1] WORLD", + "[2/456] my-task-new", + "[2] I AM COW", + "[2] HEAR ME MOO", + "[3/456] my-task-short-lived", + "[3] hello short lived", + "[3] goodbye short lived", + "123/456 ============================== TITLE ============================== 32s", + "" + ) + } + } + + test("sequentialShortLived") { + if (!Util.windowsPlatform) { + // Make sure that when we have multiple sequential tasks being run on different threads, + // we still end up showing some kind of task in progress in the ticker, even though the + // tasks on each thread are short-lived enough they would not normally get shown if run + // alone. + @volatile var now = 0L + val (baos, promptLogger, prefixLogger) = setup(() => now, os.temp("80 40")) + + promptLogger.globalTicker("123/456") + promptLogger.refreshPrompt() + check(promptLogger, baos)( + " 123/456 ============================ TITLE ==================================" + ) + promptLogger.promptLine("[1]", "[1/456]", "my-task") + + now += 100 + + promptLogger.refreshPrompt() + check(promptLogger, baos)( + " 123/456 ============================ TITLE ==================================" + ) + + promptLogger.endTicker("[1]") + + val newTaskThread = new Thread(() => { + promptLogger.promptLine("[2]", "[2/456]", "my-task-new") + now += 100 + promptLogger.endTicker("[2]") + }) + newTaskThread.start() + newTaskThread.join() + + promptLogger.refreshPrompt() + check(promptLogger, baos)( + " 123/456 ============================ TITLE ==================================" + ) + + val newTaskThread2 = new Thread(() => { + promptLogger.promptLine("[2]", "[2/456]", "my-task-new") + now += 100 + }) + newTaskThread2.start() + newTaskThread2.join() + promptLogger.refreshPrompt() + check(promptLogger, baos)( + " 123/456 ============================ TITLE ==================================", + "[2] my-task-new" + ) + } + } + test("detail") { + if (!Util.windowsPlatform) { + // Make sure that when we have multiple sequential tasks being run on different threads, + // we still end up showing some kind of task in progress in the ticker, even though the + // tasks on each thread are short-lived enough they would not normally get shown if run + // alone. + @volatile var now = 0L + val (baos, promptLogger, prefixLogger) = setup(() => now, os.temp("80 40")) + + promptLogger.globalTicker("123/456") + promptLogger.refreshPrompt() + + promptLogger.promptLine("[1]", "[1/456]", "my-task") + prefixLogger.ticker("detail") + now += 1000 + promptLogger.refreshPrompt() + check(promptLogger, baos)( + " 123/456 ============================ TITLE =============================== 1s", + "[1] my-task 1s detail" + ) + prefixLogger.ticker("detail-too-long-gets-truncated-abcdefghijklmnopqrstuvwxyz1234567890") + promptLogger.refreshPrompt() + check(promptLogger, baos)( + " 123/456 ============================ TITLE =============================== 1s", + "[1] my-task 1s detail-too-long-gets-truncated...fghijklmnopqrstuvwxyz1234567890" + ) + promptLogger.endTicker("[1]") + now += 10000 + promptLogger.refreshPrompt() + check(promptLogger, baos)( + " 123/456 ============================ TITLE ============================== 11s" + ) + } + } + } +} diff --git a/main/util/test/src/mill/util/PromptLoggerUtilTests.scala b/main/util/test/src/mill/util/PromptLoggerUtilTests.scala new file mode 100644 index 00000000000..35c88e3b758 --- /dev/null +++ b/main/util/test/src/mill/util/PromptLoggerUtilTests.scala @@ -0,0 +1,423 @@ +package mill.util + +import utest._ + +import scala.collection.immutable.SortedMap +import PromptLoggerUtil._ +object PromptLoggerUtilTests extends TestSuite { + + val tests = Tests { + test("splitShorten") { + splitShorten("hello world", 12) ==> "hello world" + splitShorten("hello world", 11) ==> "hello world" + splitShorten("hello world", 10) ==> "hell...rld" + splitShorten("hello world", 9) ==> "hel...rld" + splitShorten("hello world", 8) ==> "hel...ld" + splitShorten("hello world", 7) ==> "he...ld" + splitShorten("hello world", 6) ==> "he...d" + splitShorten("hello world", 5) ==> "h...d" + splitShorten("hello world", 4) ==> "h..." + splitShorten("hello world", 3) ==> "..." + splitShorten("hello world", 2) ==> ".." + splitShorten("hello world", 1) ==> "." + splitShorten("hello world", 0) ==> "" + } + test("lastIndexOfNewline") { + // Fuzz test to make sure our custom fast `lastIndexOfNewline` logic behaves + // the same as a slower generic implementation using `.slice.lastIndexOf` + val allSampleByteArrays = Seq[Array[Byte]]( + Array(1), + Array('\n'), + Array(1, 1), + Array(1, '\n'), + Array('\n', 1), + Array('\n', '\n'), + Array(1, 1, 1), + Array(1, 1, '\n'), + Array(1, '\n', 1), + Array('\n', 1, 1), + Array(1, '\n', '\n'), + Array('\n', 1, '\n'), + Array('\n', '\n', 1), + Array('\n', '\n', '\n'), + Array(1, 1, 1, 1), + Array(1, 1, 1, '\n'), + Array(1, 1, '\n', 1), + Array(1, '\n', 1, 1), + Array('\n', 1, 1, 1), + Array(1, 1, '\n', '\n'), + Array(1, '\n', '\n', 1), + Array('\n', '\n', 1, 1), + Array(1, '\n', 1, '\n'), + Array('\n', 1, '\n', 1), + Array('\n', 1, 1, '\n'), + Array('\n', '\n', '\n', 1), + Array('\n', '\n', 1, '\n'), + Array('\n', 1, '\n', '\n'), + Array(1, '\n', '\n', '\n'), + Array('\n', '\n', '\n', '\n') + ) + + for (sample <- allSampleByteArrays) { + for (start <- Range(0, sample.length)) { + for (len <- Range(0, sample.length - start)) { + val found = lastIndexOfNewline(sample, start, len) + val expected0 = sample.slice(start, start + len).lastIndexOf('\n') + val expected = expected0 + start + def assertMsg = + s"found:$found, expected$expected, sample:${sample.toSeq}, start:$start, len:$len" + if (expected0 == -1) Predef.assert(found == -1, assertMsg) + else Predef.assert(found == expected, assertMsg) + } + } + } + } + test("renderHeader") { + + def check(prefix: String, title: String, suffix: String, maxWidth: Int, expected: String) = { + val rendered = renderHeader(prefix, title, suffix, maxWidth) + // leave two spaces open on the left so there's somewhere to park the cursor + assert(expected == rendered) + assert(rendered.length == maxWidth) + rendered + } + test("simple") - check( + "PREFIX", + "TITLE", + " SUFFIX", + 60, + expected = " PREFIX ==================== TITLE ================= SUFFIX" + ) + + test("short") - check( + "PREFIX", + "TITLE", + " SUFFIX", + 40, + expected = " PREFIX ========== TITLE ======= SUFFIX" + ) + + test("shorter") - check( + "PREFIX", + "TITLE", + " SUFFIX", + 25, + expected = " PREFIX ========= SUFFIX" + ) + + test("truncateTitle") - check( + "PREFIX", + "TITLE_ABCDEFGHIJKLMNOPQRSTUVWXYZ", + " SUFFIX", + 60, + expected = " PREFIX ====== TITLE_ABCDEFG...OPQRSTUVWXYZ ======== SUFFIX" + ) + + test("asymmetricTruncateTitle") - check( + "PREFIX_LONG", + "TITLE_ABCDEFGHIJKLMNOPQRSTUVWXYZ", + " SUFFIX", + 60, + expected = " PREFIX_LONG = TITLE_AB...TUVWXYZ ================== SUFFIX" + ) + } + + test("renderPrompt") { + val now = System.currentTimeMillis() + def renderPromptTest( + interactive: Boolean, + titleText: String = "__.compile" + )(statuses: (Int, Status)*) = { + renderPrompt( + consoleWidth = 60, + consoleHeight = 20, + now = now, + startTimeMillis = now - 1337000, + headerPrefix = "123/456", + titleText = titleText, + statuses = SortedMap(statuses.map { case (k, v) => (k.toString, v) }: _*), + interactive = interactive, + infoColor = fansi.Attrs.Empty + ) + + } + test("simple") { + val rendered = renderPromptTest(interactive = true)( + 0 -> Status(Some(StatusEntry("hello", now - 1000)), 0, None), + 1 -> Status(Some(StatusEntry("world", now - 2000)), 0, None) + ) + val expected = List( + " 123/456 =============== __.compile ================ 1337s", + "hello 1s", + "world 2s" + ) + assert(rendered == expected) + } + + test("maxWithoutTruncation") { + val rendered = + renderPromptTest(interactive = true, titleText = "__.compile.abcdefghijklmn")( + 0 -> Status( + Some(StatusEntry( + "#1 hello1234567890abcefghijklmnopqrstuvwxyz1234567890123", + now - 1000 + )), + 0, + None + ), + 1 -> Status(Some(StatusEntry("#2 world", now - 2000)), 0, None), + 2 -> Status(Some(StatusEntry("#3 i am cow", now - 3000)), 0, None), + 3 -> Status(Some(StatusEntry("#4 hear me moo", now - 4000)), 0, None), + 4 -> Status(Some(StatusEntry("#5 i weigh twice as much as you", now - 5000)), 0, None) + ) + + val expected = List( + " 123/456 ======== __.compile.abcdefghijklmn ======== 1337s", + "#1 hello1234567890abcefghijklmnopqrstuvwxyz1234567890123 1s", + "#2 world 2s", + "#3 i am cow 3s", + "#4 hear me moo 4s", + "#5 i weigh twice as much as you 5s" + ) + assert(rendered == expected) + } + test("minAfterTruncation") { + val rendered = + renderPromptTest(interactive = true, titleText = "__.compile.abcdefghijklmno")( + 0 -> Status( + Some(StatusEntry( + "#1 hello1234567890abcefghijklmnopqrstuvwxyz12345678901234", + now - 1000 + )), + 0, + None + ), + 1 -> Status(Some(StatusEntry("#2 world", now - 2000)), 0, None), + 2 -> Status(Some(StatusEntry("#3 i am cow", now - 3000)), 0, None), + 3 -> Status(Some(StatusEntry("#4 hear me moo", now - 4000)), 0, None), + 4 -> Status(Some(StatusEntry("#5 i weigh twice as much as you", now - 5000)), 0, None), + 5 -> Status( + Some(StatusEntry("#6 and I look good on the barbecue", now - 6000)), + 0, + None + ) + ) + + val expected = List( + " 123/456 ======= __.compile....efghijklmno ========= 1337s", + "#1 hello1234567890abcefghijk...pqrstuvwxyz12345678901234 1s", + "#2 world 2s", + "#3 i am cow 3s", + "#4 hear me moo 4s", + "... and 2 more threads" + ) + assert(rendered == expected) + } + + test("truncated") { + val rendered = renderPromptTest( + interactive = true, + titleText = "__.compile.abcdefghijklmnopqrstuvwxyz1234567890" + )( + 0 -> Status( + Some(StatusEntry("#1 hello1234567890abcefghijklmnopqrstuvwxyz" * 3, now - 1000)), + 0, + None + ), + 1 -> Status(Some(StatusEntry("#2 world", now - 2000)), 0, None), + 2 -> Status(Some(StatusEntry("#3 i am cow", now - 3000)), 0, None), + 3 -> Status(Some(StatusEntry("#4 hear me moo", now - 4000)), 0, None), + 4 -> Status(Some(StatusEntry("#5 i weigh twice as much as you", now - 5000)), 0, None), + 5 -> Status(Some(StatusEntry("#6 and i look good on the barbecue", now - 6000)), 0, None), + 6 -> Status( + Some(StatusEntry("#7 yoghurt curds cream cheese and butter", now - 7000)), + 0, + None + ) + ) + val expected = List( + " 123/456 __.compile....z1234567890 ================ 1337s", + "#1 hello1234567890abcefghijk...abcefghijklmnopqrstuvwxyz 1s", + "#2 world 2s", + "#3 i am cow 3s", + "#4 hear me moo 4s", + "... and 3 more threads" + ) + assert(rendered == expected) + } + test("detail") { + val rendered = renderPromptTest(interactive = true)( + 0 -> Status(Some(StatusEntry("1 hello", now - 1000, "")), 0, None), + 1 -> Status(Some(StatusEntry("2 world", now - 2000, "HELLO")), 0, None), + 2 -> Status( + Some(StatusEntry( + "3 truncated-detail", + now - 3000, + "HELLO WORLD abcdefghijklmnopqrstuvwxyz1234567890" + )), + 0, + None + ), + 3 -> Status( + Some(StatusEntry( + "4 long-status-eliminated-detail-abcdefghijklmnopqrstuvwxyz1234567890", + now - 4000, + "HELLO" + )), + 0, + None + ) + ) + val expected = List( + " 123/456 =============== __.compile ================ 1337s", + "1 hello 1s", // no detail + "2 world 2s HELLO", // simple detail + "3 truncated-detail 3s HELLO WORLD abcde...tuvwxyz1234567890", // truncated detail + "4 long-status-eliminated-det...lmnopqrstuvwxyz1234567890 4s" + ) + assert(rendered == expected) + } + + test("removalDelay") { + val rendered = renderPromptTest( + interactive = true, + titleText = "__.compile.abcdefghijklmnopqrstuvwxyz1234567890" + )( + // Not yet removed, should be shown + 0 -> Status( + Some(StatusEntry("#1 hello1234567890abcefghijklmnopqrstuvwxyz" * 3, now - 1000)), + 0, + None + ), + // This is removed but are still within the transition window, so still shown + 2 -> Status( + None, + now - statusRemovalHideDelayMillis + 1, + Some(StatusEntry("#3 i am cow", now - 3000)) + ), + // Removed but already outside the `statusRemovalDelayMillis` window, not shown, but not + // yet removed, so rendered as blank lines to prevent terminal jumping around too much + 3 -> Status( + None, + now - statusRemovalRemoveDelayMillis + 1, + Some(StatusEntry("#4 hear me moo", now - 4000)) + ), + 4 -> Status( + None, + now - statusRemovalRemoveDelayMillis + 1, + Some(StatusEntry("#5 i weigh twice", now - 5000)) + ), + 5 -> Status( + None, + now - statusRemovalRemoveDelayMillis + 1, + Some(StatusEntry("#6 as much as you", now - 6000)) + ), + // This one would be rendered as a blank line, but because of the max prompt height + // controlled by the `consoleHeight` it ends up being silently truncated + 6 -> Status( + None, + now - statusRemovalRemoveDelayMillis + 1, + Some(StatusEntry("#7 and I look good on the barbecue", now - 7000)) + ) + ) + + val expected = List( + " 123/456 __.compile....z1234567890 ================ 1337s", + "#1 hello1234567890abcefghijk...abcefghijklmnopqrstuvwxyz 1s", + "#3 i am cow 3s", + "", + "", + "" + ) + + assert(rendered == expected) + } + test("removalFinal") { + val rendered = renderPromptTest( + interactive = true, + titleText = "__.compile.abcdefghijklmnopqrstuvwxyz1234567890" + )( + // Not yet removed, should be shown + 0 -> Status( + Some(StatusEntry("#1 hello1234567890abcefghijklmnopqrstuvwxyz" * 3, now - 1000)), + 0, + None + ), + // This is removed a long time ago, so it is totally removed + 1 -> Status( + None, + now - statusRemovalRemoveDelayMillis - 1, + Some(StatusEntry("#2 world", now - 2000)) + ), + // This is removed but are still within the transition window, so still shown + 2 -> Status( + None, + now - statusRemovalHideDelayMillis + 1, + Some(StatusEntry("#3 i am cow", now - 3000)) + ) + ) + + val expected = List( + " 123/456 __.compile....z1234567890 ================ 1337s", + "#1 hello1234567890abcefghijk...abcefghijklmnopqrstuvwxyz 1s", + "#3 i am cow 3s" + ) + + assert(rendered == expected) + } + + test("nonInteractive") { + val rendered = renderPromptTest( + interactive = false, + titleText = "__.compile.abcdefghijklmnopqrstuvwxyz1234567890" + )( + // Not yet removed, should be shown + 0 -> Status( + Some(StatusEntry("#1 hello1234567890abcefghijklmnopqrstuvwxyz" * 3, now - 1000)), + 0, + None + ), + // These are removed but are still within the `statusRemovalDelayMillis` window, so still shown + 1 -> Status( + None, + now - statusRemovalHideDelayMillis + 1, + Some(StatusEntry("#2 world", now - 2000)) + ), + 2 -> Status( + None, + now - statusRemovalHideDelayMillis + 1, + Some(StatusEntry("#3 i am cow", now - 3000)) + ), + // Removed but already outside the `statusRemovalDelayMillis` window, not shown, but not + // yet removed, so rendered as blank lines to prevent terminal jumping around too much + 3 -> Status( + None, + now - statusRemovalRemoveDelayMillis - 1, + Some(StatusEntry("#4 hear me moo", now - 4000)) + ), + 4 -> Status( + None, + now - statusRemovalRemoveDelayMillis - 1, + Some(StatusEntry("#5 i weigh twice", now - 5000)) + ), + 5 -> Status( + None, + now - statusRemovalRemoveDelayMillis - 1, + Some(StatusEntry("#6 as much as you", now - 6000)) + ) + ) + + // Make sure the non-interactive prompt does not show the blank lines, + // and it contains a footer line to mark the end of the prompt in logs + val expected = List( + "123/456 __.compile.ab...xyz1234567890 ============== 1337s", + "#1 hello1234567890abcefghijk...abcefghijklmnopqrstuvwxyz 1s", + "#2 world 2s", + "#3 i am cow 3s", + "===========================================================" + ) + assert(rendered == expected) + } + } + } +} diff --git a/main/util/test/src/mill/util/TestTerminalTests.scala b/main/util/test/src/mill/util/TestTerminalTests.scala new file mode 100644 index 00000000000..667ac1096d2 --- /dev/null +++ b/main/util/test/src/mill/util/TestTerminalTests.scala @@ -0,0 +1,165 @@ +package mill.util + +import utest._ + +/** + * Minimal implementation of a terminal emulator that handles ANSI navigation + * codes, so we can feed in terminal strings and assert that the terminal looks + * like what it should look like including cleared lines/screens and overridden text + */ +class TestTerminal(width: Int) { + var grid = collection.mutable.Buffer("") + var cursorX = 0 + var cursorY = 0 + + def writeAll(data0: String): Unit = { + + def rec(data: String): Unit = data match { // pprint.log((grid, cursorX, cursorY, data.head)) + case "" => // end + case s"\u001b[$rest0" => + val num0 = rest0.takeWhile(_.isDigit) + val n = num0.toInt + val char = rest0(num0.length) + val rest = rest0.drop(num0.length + 1) + char match { + case 'A' => // up + cursorY = math.max(cursorY - n.toInt, 0) + rec(rest) + case 'B' => // down + cursorY = math.min(cursorY + n.toInt, grid.size) + rec(rest) + case 'C' => // right + cursorX = math.min(cursorX + n.toInt, width) + rec(rest) + case 'D' => // left + cursorX = math.max(cursorX - n.toInt, 0) + rec(rest) + case 'J' => // clearscreen + n match { + case 0 => + if (cursorY < grid.length) grid(cursorY) = grid(cursorY).take(cursorX) + grid = grid.take(cursorY + 1) + rec(rest) + } + case 'K' => // clearline + n match { + case 0 => + grid(cursorY) = grid(cursorY).take(cursorX) + rec(rest) + } + } + + case normal => // normal text + if (normal.head == '\n') { + cursorX = 0 + cursorY += 1 + if (cursorY >= grid.length) grid.append("") + } else { + if (cursorX == width) { + cursorX = 0 + cursorY += 1 + } + if (cursorY >= grid.length) grid.append("") + grid(cursorY) = grid(cursorY).patch(cursorX, Seq(normal.head), 1) + if (cursorX < width) { + cursorX += 1 + } else { + cursorX = 0 + cursorY += 1 + } + + } + rec(normal.tail) + } + rec(data0) + } +} + +object TestTerminalTests extends TestSuite { + + val tests = Tests { + test("wrap") { + val t = new TestTerminal(width = 10) + t.writeAll("1234567890abcdef") + t.grid ==> Seq( + "1234567890", + "abcdef" + ) + } + test("newline") { + val t = new TestTerminal(width = 10) + t.writeAll("12345\n67890") + t.grid ==> Seq( + "12345", + "67890" + ) + } + test("trailingNewline") { + val t = new TestTerminal(width = 10) + t.writeAll("12345\n") + t.grid ==> Seq( + "12345", + "" + ) + } + test("wrapNewline") { + val t = new TestTerminal(width = 10) + t.writeAll("1234567890\nabcdef") + t.grid ==> Seq( + "1234567890", + "abcdef" + ) + } + test("wrapNewline2") { + val t = new TestTerminal(width = 10) + t.writeAll("1234567890\n\nabcdef") + t.grid ==> Seq( + "1234567890", + "", + "abcdef" + ) + } + test("up") { + val t = new TestTerminal(width = 15) + t.writeAll(s"1234567890\nabcdef${AnsiNav.up(1)}X") + t.grid ==> Seq( + "123456X890", + "abcdef" + ) + } + test("left") { + val t = new TestTerminal(width = 15) + t.writeAll(s"1234567890\nabcdef${AnsiNav.left(3)}X") + t.grid ==> Seq( + "1234567890", + "abcXef" + ) + } + test("upLeftClearLine") { + val t = new TestTerminal(width = 15) + t.writeAll(s"1234567890\nabcdef${AnsiNav.up(1)}${AnsiNav.left(3)}X${AnsiNav.clearLine(0)}") + t.grid ==> Seq( + "123X", + "abcdef" + ) + } + test("upLeftClearScreen") { + val t = new TestTerminal(width = 15) + t.writeAll(s"1234567890\nabcdef${AnsiNav.up(1)}${AnsiNav.left(3)}X${AnsiNav.clearScreen(0)}") + t.grid ==> Seq("123X") + } + test("wrapUpClearLine") { + val t = new TestTerminal(width = 10) + t.writeAll(s"1234567890abcdef${AnsiNav.up(1)}${AnsiNav.left(3)}X${AnsiNav.clearLine(0)}") + t.grid ==> Seq( + "123X", + "abcdef" + ) + } + test("wrapUpClearScreen") { + val t = new TestTerminal(width = 10) + t.writeAll(s"1234567890abcdef${AnsiNav.up(1)}${AnsiNav.left(3)}X${AnsiNav.clearScreen(0)}") + t.grid ==> Seq("123X") + } + } +} diff --git a/readme.adoc b/readme.adoc index 82ee50ed328..0c759295161 100644 --- a/readme.adoc +++ b/readme.adoc @@ -87,6 +87,14 @@ The following table contains the main ways you can test the code in | Bootstrapping: Building Mill with your current checkout of Mill | | `installLocal` | `test-mill-bootstrap.sh` |=== +In general, `println` or `pprint.log` should work in most places and be sufficient for +instrumenting and debugging the Mill codebase. In the occasional spot where `println` +doesn't work you can use `mill.main.client.DebugLog.println` which writes to a file +`~/mill-debug-log.txt` in your home folder. `DebugLog` is useful for scenarios like +debugging Mill's terminal UI (where `println` would mess things up) or subprocesses +(where stdout/stderr may get captured or used and cannot be used to display your own +debug statements). + === In-Process Tests In-process tests live in the `.test` sub-modules of the various Mill modules. @@ -145,7 +153,7 @@ You can reproduce any of the tests manually using `dist.run`, e.g. [source,bash] ---- -./mill dist.launcher && (cd example/basic/1-simple && ../../../out/dist/launcher.dest/run run --text hello) +./mill dist.launcher && (cd example/javalib/basic/1-simple && ../../../../out/dist/launcher.dest/run run --text hello) ---- === Sub-Process Tests *with* Packaging/Publishing diff --git a/runner/client/src/mill/runner/client/MillClientMain.java b/runner/client/src/mill/runner/client/MillClientMain.java index d22b87a1274..0e6b6fffbf6 100644 --- a/runner/client/src/mill/runner/client/MillClientMain.java +++ b/runner/client/src/mill/runner/client/MillClientMain.java @@ -1,9 +1,9 @@ package mill.runner.client; +import java.nio.file.Path; +import java.nio.file.Paths; import java.util.Arrays; -import java.util.function.BiConsumer; import mill.main.client.ServerLauncher; -import mill.main.client.ServerFiles; import mill.main.client.Util; import mill.main.client.lock.Locks; import mill.main.client.OutFiles; @@ -37,7 +37,7 @@ public static void main(String[] args) throws Exception { } else try { // start in client-server mode ServerLauncher launcher = new ServerLauncher(System.in, System.out, System.err, System.getenv(), args, null, -1){ - public void initServer(String serverDir, boolean setJnaNoSys, Locks locks) throws Exception{ + public void initServer(Path serverDir, boolean setJnaNoSys, Locks locks) throws Exception{ MillProcessLauncher.launchMillServer(serverDir, setJnaNoSys); } }; diff --git a/runner/client/src/mill/runner/client/MillProcessLauncher.java b/runner/client/src/mill/runner/client/MillProcessLauncher.java index f15139cc769..d4459898385 100644 --- a/runner/client/src/mill/runner/client/MillProcessLauncher.java +++ b/runner/client/src/mill/runner/client/MillProcessLauncher.java @@ -6,9 +6,13 @@ import java.io.FileInputStream; import java.io.IOException; import java.nio.file.Files; +import java.nio.file.Path; import java.nio.file.Paths; import java.util.*; +import org.jline.terminal.TerminalBuilder; +import org.jline.terminal.Terminal; + import mill.main.client.Util; import mill.main.client.ServerFiles; import mill.main.client.EnvVars; @@ -17,22 +21,23 @@ public class MillProcessLauncher { static int launchMillNoServer(String[] args) throws Exception { final boolean setJnaNoSys = System.getProperty("jna.nosys") == null; + final String sig = String.format("%08x", UUID.randomUUID().hashCode()); + final Path processDir = Paths.get(".").resolve(out).resolve(millNoServer).resolve(sig); final List l = new ArrayList<>(); l.addAll(millLaunchJvmCommand(setJnaNoSys)); l.add("mill.runner.MillMain"); + l.add(processDir.toAbsolutePath().toString()); l.addAll(Arrays.asList(args)); final ProcessBuilder builder = new ProcessBuilder() .command(l) .inheritIO(); - final String sig = String.format("%08x", UUID.randomUUID().hashCode()); - boolean interrupted = false; - final String sandbox = out + "/" + millNoServer + "-" + sig; + try { - return configureRunMillProcess(builder, sandbox).waitFor(); + return configureRunMillProcess(builder, processDir).waitFor(); } catch (InterruptedException e) { interrupted = true; @@ -40,7 +45,7 @@ static int launchMillNoServer(String[] args) throws Exception { } finally { if (!interrupted) { // cleanup if process terminated for sure - Files.walk(Paths.get(sandbox)) + Files.walk(processDir) // depth-first .sorted(Comparator.reverseOrder()) .forEach(p -> p.toFile().delete()); @@ -48,31 +53,51 @@ static int launchMillNoServer(String[] args) throws Exception { } } - static void launchMillServer(String serverDir, boolean setJnaNoSys) throws Exception { + static void launchMillServer(Path serverDir, boolean setJnaNoSys) throws Exception { List l = new ArrayList<>(); l.addAll(millLaunchJvmCommand(setJnaNoSys)); l.add("mill.runner.MillServerMain"); - l.add(new File(serverDir).getCanonicalPath()); - - File stdout = new java.io.File(serverDir + "/" + ServerFiles.stdout); - File stderr = new java.io.File(serverDir + "/" + ServerFiles.stderr); + l.add(serverDir.toFile().getCanonicalPath()); ProcessBuilder builder = new ProcessBuilder() .command(l) - .redirectOutput(stdout) - .redirectError(stderr); + .redirectOutput(serverDir.resolve(ServerFiles.stdout).toFile()) + .redirectError(serverDir.resolve(ServerFiles.stderr).toFile()); - configureRunMillProcess(builder, serverDir + "/" + ServerFiles.sandbox); + configureRunMillProcess(builder, serverDir); } static Process configureRunMillProcess( ProcessBuilder builder, - String serverDir + Path serverDir ) throws Exception { + Terminal term = TerminalBuilder.builder().dumb(true).build(); + Path sandbox = serverDir.resolve(ServerFiles.sandbox); + Files.createDirectories(sandbox); + Files.write( + serverDir.resolve(ServerFiles.terminfo), + (term.getWidth() + " " + term.getHeight()).getBytes() + ); + Thread termInfoPropagatorThread = new Thread( + () -> { + try { + + while(true){ + Files.write( + serverDir.resolve(ServerFiles.terminfo), + (term.getWidth() + " " + term.getHeight()).getBytes() + ); + + Thread.sleep(100); + } + }catch (Exception e){} + }, + "TermInfoPropagatorThread" + ); + termInfoPropagatorThread.start(); builder.environment().put(EnvVars.MILL_WORKSPACE_ROOT, new File("").getCanonicalPath()); - File sandbox = new java.io.File(serverDir + "/" + ServerFiles.sandbox); - sandbox.mkdirs(); - builder.directory(sandbox); + + builder.directory(sandbox.toFile()); return builder.start(); } diff --git a/runner/src/mill/runner/CodeGen.scala b/runner/src/mill/runner/CodeGen.scala index 57ae17d81f6..8baf0736799 100644 --- a/runner/src/mill/runner/CodeGen.scala +++ b/runner/src/mill/runner/CodeGen.scala @@ -164,6 +164,7 @@ object CodeGen { |$newScriptCode |object $wrapperObjectName extends $wrapperObjectName { | $childAliases + | @_root_.scala.annotation.nowarn | override lazy val millDiscover: _root_.mill.define.Discover = _root_.mill.define.Discover[this.type] |}""".stripMargin case None => @@ -217,6 +218,7 @@ object CodeGen { // object initialization due to https://github.com/scala/scala3/issues/21444 s"""object $wrapperObjectName extends $wrapperObjectName{ | $childAliases + | @_root_.scala.annotation.nowarn | override lazy val millDiscover: _root_.mill.define.Discover = _root_.mill.define.Discover[this.type] |} |abstract class $wrapperObjectName $extendsClause {""".stripMargin diff --git a/runner/src/mill/runner/MillCliConfig.scala b/runner/src/mill/runner/MillCliConfig.scala index 0c23cc8cca3..61d1ef9fac4 100644 --- a/runner/src/mill/runner/MillCliConfig.scala +++ b/runner/src/mill/runner/MillCliConfig.scala @@ -123,7 +123,14 @@ case class MillCliConfig( ) metaLevel: Option[Int] = None, @arg(doc = "Allows command args to be passed positionally without `--arg` by default") - allowPositional: Flag = Flag() + allowPositional: Flag = Flag(), + @arg( + doc = """ + Disables the new multi-line status prompt used for showing thread + status at the command line and falls back to the legacy ticker + """ + ) + disablePrompt: Flag = Flag() ) import mainargs.ParserForClass diff --git a/runner/src/mill/runner/MillMain.scala b/runner/src/mill/runner/MillMain.scala index d026eac3e04..e9b2097ec85 100644 --- a/runner/src/mill/runner/MillMain.scala +++ b/runner/src/mill/runner/MillMain.scala @@ -8,7 +8,8 @@ import mill.java9rtexport.Export import mill.api.{MillException, SystemStreams, WorkspaceRoot, internal} import mill.bsp.{BspContext, BspServerResult} import mill.main.BuildInfo -import mill.util.PrintLogger +import mill.main.client.ServerFiles +import mill.util.{PromptLogger, PrintLogger} import java.lang.reflect.InvocationTargetException import scala.util.control.NonFatal @@ -33,8 +34,8 @@ object MillMain { (false, onError) } - def main(args: Array[String]): Unit = { - val initialSystemStreams = new SystemStreams(System.out, System.err, System.in) + def main(args: Array[String]): Unit = SystemStreams.withTopLevelSystemStreamProxy { + val initialSystemStreams = SystemStreams.original // setup streams val (runnerStreams, cleanupStreams, bspLog) = if (args.headOption == Option("--bsp")) { @@ -67,7 +68,7 @@ object MillMain { val (result, _) = try main0( - args = args, + args = args.tail, stateCache = RunnerState.empty, mainInteractive = mill.util.Util.isInteractive(), streams0 = runnerStreams, @@ -76,7 +77,8 @@ object MillMain { setIdle = b => (), userSpecifiedProperties0 = Map(), initialSystemProperties = sys.props.toMap, - systemExit = i => sys.exit(i) + systemExit = i => sys.exit(i), + serverDir = os.Path(args.head) ) catch handleMillException(runnerStreams.err, ()) finally { @@ -95,10 +97,11 @@ object MillMain { setIdle: Boolean => Unit, userSpecifiedProperties0: Map[String, String], initialSystemProperties: Map[String, String], - systemExit: Int => Nothing + systemExit: Int => Nothing, + serverDir: os.Path ): (Boolean, RunnerState) = { val printLoggerState = new PrintLogger.State() - val streams = PrintLogger.wrapSystemStreams(streams0, printLoggerState) + val streams = streams0 SystemStreams.withStreams(streams) { os.SubProcess.env.withValue(env) { MillCliConfigParser.parse(args) match { @@ -112,20 +115,19 @@ object MillMain { (true, RunnerState.empty) case Right(config) if config.showVersion.value => - def p(k: String, d: String = "") = System.getProperty(k, d) + def prop(k: String) = System.getProperty(k, s"") + val javaVersion = prop("java.version") + val javaVendor = prop("java.vendor") + val javaHome = prop("java.home") + val fileEncoding = prop("file.encoding") + val osName = prop("os.name") + val osVersion = prop("os.version") + val osArch = prop("os.arch") streams.out.println( s"""Mill Build Tool version ${BuildInfo.millVersion} - |Java version: ${p("java.version", "" - )} - |OS name: "${p("os.name")}", version: ${p("os.version")}, arch: ${p( - "os.arch" - )}""".stripMargin + |Java version: $javaVersion, vendor: $javaVendor, runtime: $javaHome + |Default locale: ${Locale.getDefault()}, platform encoding: $fileEncoding + |OS name: "$osName", version: $osVersion, arch: $osArch""".stripMargin ) (true, RunnerState.empty) @@ -164,118 +166,123 @@ object MillMain { config.ticker .orElse(config.enableTicker) .orElse(Option.when(config.disableTicker.value)(false)), - printLoggerState + printLoggerState, + serverDir ) - if (!config.silent.value) { - checkMillVersionFromFile(WorkspaceRoot.workspaceRoot, streams.err) - } + try { + 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) { + logger.error("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) { + logger.error(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)) { + logger.errorStream.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( - projectRoot = WorkspaceRoot.workspaceRoot, - home = config.home, - keepGoing = config.keepGoing.value, - imports = config.imports, - env = env, - threadCount = threadCount, - targetsAndParams = targetsAndParams, - prevRunnerState = prevState.getOrElse(stateCache), - logger = logger, - disableCallgraph = config.disableCallgraph.value, - needBuildSc = needBuildSc(config), - requestedMetaLevel = config.metaLevel, - config.allowPositional.value, - systemExit = systemExit - ).evaluate() + 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( + projectRoot = WorkspaceRoot.workspaceRoot, + home = config.home, + keepGoing = config.keepGoing.value, + imports = config.imports, + env = env, + threadCount = threadCount, + targetsAndParams = targetsAndParams, + prevRunnerState = prevState.getOrElse(stateCache), + logger = logger, + disableCallgraph = config.disableCallgraph.value, + needBuildSc = needBuildSc(config), + requestedMetaLevel = config.metaLevel, + config.allowPositional.value, + systemExit = systemExit + ).evaluate() + } + ) + 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 => - repeatForBsp = - BspContext.bspServerHandle.lastResult == Some(BspServerResult.ReloadWorkspace) logger.error( - s"`$bspCmd` returned with ${BspContext.bspServerHandle.lastResult}" + s"Exiting BSP runner loop. Stopping BSP server. Last result: ${BspContext.bspServerHandle.lastResult}" ) + BspContext.bspServerHandle.stop() } - loopRes = (isSuccess, evalStateOpt) - } // while repeatForBsp - bspContext.foreach { ctx => - logger.error( - s"Exiting BSP runner loop. Stopping BSP server. Last result: ${BspContext.bspServerHandle.lastResult}" - ) - BspContext.bspServerHandle.stop() - } - // return with evaluation result - loopRes + // return with evaluation result + loopRes + } } - } - if (config.ringBell.value) { - if (success) println("\u0007") - else { - println("\u0007") - Thread.sleep(250) - println("\u0007") + + if (config.ringBell.value) { + if (success) println("\u0007") + else { + println("\u0007") + Thread.sleep(250) + println("\u0007") + } } - } - (success, nextStateCache) + (success, nextStateCache) + } finally logger.close() } } } @@ -306,21 +313,37 @@ object MillMain { config: MillCliConfig, mainInteractive: Boolean, enableTicker: Option[Boolean], - printLoggerState: PrintLogger.State - ): PrintLogger = { + printLoggerState: PrintLogger.State, + serverDir: os.Path + ): mill.util.ColorLogger = { val colored = config.color.getOrElse(mainInteractive) val colors = if (colored) mill.util.Colors.Default else mill.util.Colors.BlackWhite - val logger = new mill.util.PrintLogger( - colored = colored, - enableTicker = enableTicker.getOrElse(mainInteractive), - infoColor = colors.info, - errorColor = colors.error, - systemStreams = streams, - debugEnabled = config.debugLog.value, - context = "", - printLoggerState - ) + val logger = if (config.disablePrompt.value) { + new mill.util.PrintLogger( + colored = colored, + enableTicker = enableTicker.getOrElse(mainInteractive), + infoColor = colors.info, + errorColor = colors.error, + systemStreams = streams, + debugEnabled = config.debugLog.value, + context = "", + printLoggerState + ) + } else { + new PromptLogger( + colored = colored, + enableTicker = enableTicker.getOrElse(true), + infoColor = colors.info, + errorColor = colors.error, + systemStreams0 = streams, + debugEnabled = config.debugLog.value, + titleText = config.leftoverArgs.value.mkString(" "), + terminfoPath = serverDir / ServerFiles.terminfo, + currentTimeMillis = () => System.currentTimeMillis() + ) + } + logger } diff --git a/runner/src/mill/runner/MillServerMain.scala b/runner/src/mill/runner/MillServerMain.scala index 996e4df80a2..917a2f3b619 100644 --- a/runner/src/mill/runner/MillServerMain.scala +++ b/runner/src/mill/runner/MillServerMain.scala @@ -8,7 +8,7 @@ import mill.main.client.lock.Locks import scala.util.Try object MillServerMain { - def main(args0: Array[String]): Unit = { + def main(args0: Array[String]): Unit = SystemStreams.withTopLevelSystemStreamProxy { // Disable SIGINT interrupt signal in the Mill server. // // This gets passed through from the client to server whenever the user @@ -69,7 +69,8 @@ class MillServerMain( setIdle = setIdle, userSpecifiedProperties0 = userSpecifiedProperties, initialSystemProperties = initialSystemProperties, - systemExit = systemExit + systemExit = systemExit, + serverDir = serverDir ) catch MillMain.handleMillException(streams.err, stateCache) } diff --git a/scalalib/src/mill/scalalib/ScalaModule.scala b/scalalib/src/mill/scalalib/ScalaModule.scala index 6a68ead8537..53003161dbb 100644 --- a/scalalib/src/mill/scalalib/ScalaModule.scala +++ b/scalalib/src/mill/scalalib/ScalaModule.scala @@ -437,21 +437,23 @@ trait ScalaModule extends JavaModule with TestModule.ScalaModuleBase { outer => Result.Failure("console needs to be run with the -i/--interactive flag") } else { val useJavaCp = "-usejavacp" - SystemStreams.withStreams(SystemStreams.original) { - Jvm.runSubprocess( - mainClass = - if (ZincWorkerUtil.isDottyOrScala3(scalaVersion())) - "dotty.tools.repl.Main" - else - "scala.tools.nsc.MainGenericRunner", - classPath = runClasspath().map(_.path) ++ scalaCompilerClasspath().map( - _.path - ), - jvmArgs = forkArgs(), - envArgs = forkEnv(), - mainArgs = Seq(useJavaCp) ++ consoleScalacOptions().filterNot(Set(useJavaCp)), - workingDir = forkWorkingDir() - ) + T.log.withPromptPaused { + SystemStreams.withStreams(SystemStreams.original) { + Jvm.runSubprocess( + mainClass = + if (ZincWorkerUtil.isDottyOrScala3(scalaVersion())) + "dotty.tools.repl.Main" + else + "scala.tools.nsc.MainGenericRunner", + classPath = runClasspath().map(_.path) ++ scalaCompilerClasspath().map( + _.path + ), + jvmArgs = forkArgs(), + envArgs = forkEnv(), + mainArgs = Seq(useJavaCp) ++ consoleScalacOptions().filterNot(Set(useJavaCp)), + workingDir = forkWorkingDir() + ) + } } Result.Success(()) } diff --git a/testkit/src/mill/testkit/ExampleTester.scala b/testkit/src/mill/testkit/ExampleTester.scala index 656d0bce69f..65fbafd3b1e 100644 --- a/testkit/src/mill/testkit/ExampleTester.scala +++ b/testkit/src/mill/testkit/ExampleTester.scala @@ -101,7 +101,8 @@ class ExampleTester( check: Boolean = true ): Unit = { val commandStr = commandStr0 match { - case s"mill $rest" => s"./mill $rest" + case s"mill $rest" => s"./mill --disable-ticker $rest" + case s"./mill $rest" => s"./mill --disable-ticker $rest" case s"curl $rest" => s"curl --retry 5 --retry-all-errors $rest" case s => s } diff --git a/testkit/src/mill/testkit/IntegrationTester.scala b/testkit/src/mill/testkit/IntegrationTester.scala index 0a4c4651a61..309f2b957ac 100644 --- a/testkit/src/mill/testkit/IntegrationTester.scala +++ b/testkit/src/mill/testkit/IntegrationTester.scala @@ -69,7 +69,7 @@ object IntegrationTester { val debugArgs = Option.when(debugLog)("--debug") - val shellable: os.Shellable = (millExecutable, serverArgs, debugArgs, cmd) + val shellable: os.Shellable = (millExecutable, serverArgs, "--disable-ticker", debugArgs, cmd) val res0 = os.call( cmd = shellable, env = env, diff --git a/testkit/src/mill/testkit/IntegrationTesterBase.scala b/testkit/src/mill/testkit/IntegrationTesterBase.scala index e3c25c641b6..589728cc2f7 100644 --- a/testkit/src/mill/testkit/IntegrationTesterBase.scala +++ b/testkit/src/mill/testkit/IntegrationTesterBase.scala @@ -1,6 +1,6 @@ package mill.testkit import mill.api.Retry -import mill.main.client.OutFiles.{millWorker, out} +import mill.main.client.OutFiles.{millServer, out} import mill.main.client.ServerFiles.serverId trait IntegrationTesterBase { @@ -49,7 +49,7 @@ trait IntegrationTesterBase { if (os.exists(workspacePath / out)) { val serverIdFiles = for { outPath <- os.list.stream(workspacePath / out) - if outPath.last.startsWith(millWorker) + if outPath.last.startsWith(millServer) } yield outPath / serverId serverIdFiles.foreach(os.remove(_)) diff --git a/testkit/src/mill/testkit/UnitTester.scala b/testkit/src/mill/testkit/UnitTester.scala index 1d921c67477..92da0995beb 100644 --- a/testkit/src/mill/testkit/UnitTester.scala +++ b/testkit/src/mill/testkit/UnitTester.scala @@ -18,8 +18,8 @@ object UnitTester { sourceRoot: os.Path, failFast: Boolean = false, threads: Option[Int] = Some(1), - outStream: PrintStream = System.out, - errStream: PrintStream = System.err, + outStream: PrintStream = Console.out, + errStream: PrintStream = Console.err, inStream: InputStream = DummyInputStream, debugEnabled: Boolean = false, env: Map[String, String] = Evaluator.defaultEnv,