From 3ec0739e6324d41be20c6aad77b76d4faabe85fa Mon Sep 17 00:00:00 2001
From: Peter Burns <rictic@google.com>
Date: Fri, 1 Sep 2023 11:29:06 -0500
Subject: [PATCH] Improve ci output (#850)

* Use wireit v0.11.0 in wireit.

* Add the `quiet-ci` logger option

* Address review comments.
---
 CHANGELOG.md                        |   6 +
 README.md                           |  16 +--
 package.json                        |  13 ++
 src/cli-options.ts                  |   5 +-
 src/logging/quiet-logger.ts         |  32 +++--
 src/logging/quiet/run-tracker.ts    |  24 ++--
 src/logging/quiet/writeover-line.ts | 181 +++++++++++++++++-----------
 src/test/quiet-logger.test.ts       | 114 ++++++++++++++++++
 8 files changed, 293 insertions(+), 98 deletions(-)
 create mode 100644 src/test/quiet-logger.test.ts

diff --git a/CHANGELOG.md b/CHANGELOG.md
index 12248a138..e042485c8 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -8,6 +8,12 @@ Versioning](https://semver.org/spec/v2.0.0.html).
 
 <!-- ## [Unreleased] -->
 
+## [Unreleased]
+
+## Added
+
+- Added a `quiet-ci` logger with output optimized for non-interactive environemnts, like a continuous integration builder (e.g. GitHub Actions). Writes less often, doesn't show a spinner, doesn't use \r to try to writeover previous output, and only prints a new status line if there's been a change.
+
 ## [0.11.0] - 2023-08-30
 
 ## Added
diff --git a/README.md b/README.md
index 805645a7f..cceaad153 100644
--- a/README.md
+++ b/README.md
@@ -847,14 +847,14 @@ The following syntaxes can be used in the `wireit.<script>.dependencies` array:
 
 The following environment variables affect the behavior of Wireit:
 
-| Variable                | Description                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                             |
-| ----------------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- |
-| `WIREIT_FAILURES`       | [How to handle script failures](#failures-and-errors).<br><br>Options:<br><ul><li>[`no-new`](#failures-and-errors) (default): Allow running scripts to finish, but don't start new ones.</li><li>[`continue`](#continue): Allow running scripts to continue, and start new ones unless any of their dependencies failed.</li><li>[`kill`](#kill): Immediately kill running scripts, and don't start new ones.</li></ul>                                                                                                                                 |
-| `WIREIT_PARALLEL`       | [Maximum number of scripts to run at one time](#parallelism).<br><br>Defaults to 2×logical CPU cores.<br><br>Must be a positive integer or `infinity`.                                                                                                                                                                                                                                                                                                                                                                                                  |
-| `WIREIT_CACHE`          | [Caching mode](#caching).<br><br>Defaults to `local` unless `CI` is `true`, in which case defaults to `none`.<br><br>Automatically set to `github` by the [`google/wireit@setup-github-actions-caching/v1`](#github-actions-caching) action.<br><br>Options:<ul><li>[`local`](#local-caching): Cache to local disk.</li><li>[`github`](#github-actions-caching): Cache to GitHub Actions.</li><li>`none`: Disable caching.</li></ul>                                                                                                                    |
-| `CI`                    | Affects the default value of `WIREIT_CACHE`.<br><br>Automatically set to `true` by [GitHub Actions](https://docs.github.com/en/actions/learn-github-actions/environment-variables#default-environment-variables) and most other CI (continuous integration) services.<br><br>Must be exactly `true`. If unset or any other value, interpreted as `false`.                                                                                                                                                                                               |
-| `WIREIT_MAX_OPEN_FILES` | Limits the number of file descriptors Wireit will have open concurrently. Prevents resource exhaustion when checking large numbers of cached files. Set to a lower number if you hit file descriptor limits.                                                                                                                                                                                                                                                                                                                                            |
-| `WIREIT_LOGGER`         | How to present progress and results on the command line.<br><br>Options:<br><ul><li>`quiet`: writes a single dynamically updating line summarizing progress. Only passes along stdout and stderr from commands if there's a failure, or if the command is a service. The planned new default, please try it out.</li><li>`simple` (default): A verbose logger that presents clear information about the work that Wireit is doing.</li><li>`metrics`: Like `simple`, but also presents a summary table of results once a command is finished.</li></ul> |
+| Variable                | Description                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                           |
+| ----------------------- | --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- |
+| `WIREIT_FAILURES`       | [How to handle script failures](#failures-and-errors).<br><br>Options:<br><ul><li>[`no-new`](#failures-and-errors) (default): Allow running scripts to finish, but don't start new ones.</li><li>[`continue`](#continue): Allow running scripts to continue, and start new ones unless any of their dependencies failed.</li><li>[`kill`](#kill): Immediately kill running scripts, and don't start new ones.</li></ul>                                                                                                                                                                                                                                               |
+| `WIREIT_PARALLEL`       | [Maximum number of scripts to run at one time](#parallelism).<br><br>Defaults to 2×logical CPU cores.<br><br>Must be a positive integer or `infinity`.                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                |
+| `WIREIT_CACHE`          | [Caching mode](#caching).<br><br>Defaults to `local` unless `CI` is `true`, in which case defaults to `none`.<br><br>Automatically set to `github` by the [`google/wireit@setup-github-actions-caching/v1`](#github-actions-caching) action.<br><br>Options:<ul><li>[`local`](#local-caching): Cache to local disk.</li><li>[`github`](#github-actions-caching): Cache to GitHub Actions.</li><li>`none`: Disable caching.</li></ul>                                                                                                                                                                                                                                  |
+| `CI`                    | Affects the default value of `WIREIT_CACHE`.<br><br>Automatically set to `true` by [GitHub Actions](https://docs.github.com/en/actions/learn-github-actions/environment-variables#default-environment-variables) and most other CI (continuous integration) services.<br><br>Must be exactly `true`. If unset or any other value, interpreted as `false`.                                                                                                                                                                                                                                                                                                             |
+| `WIREIT_MAX_OPEN_FILES` | Limits the number of file descriptors Wireit will have open concurrently. Prevents resource exhaustion when checking large numbers of cached files. Set to a lower number if you hit file descriptor limits.                                                                                                                                                                                                                                                                                                                                                                                                                                                          |
+| `WIREIT_LOGGER`         | How to present progress and results on the command line.<br><br>Options:<br><ul><li>`quiet`: writes a single dynamically updating line summarizing progress. Only passes along stdout and stderr from commands if there's a failure, or if the command is a service. The planned new default, please try it out.</li><li>`simple` (default): A verbose logger that presents clear information about the work that Wireit is doing.</li><li>`metrics`: Like `simple`, but also presents a summary table of results once a command is finished.</li><li>`quiet-ci`: like `quiet` but optimized for non-interactive environments, like GitHub Actions runners.</li></ul> |
 
 ### Glob patterns
 
diff --git a/package.json b/package.json
index f714a9348..dcf1012aa 100644
--- a/package.json
+++ b/package.json
@@ -53,6 +53,7 @@
     "test:metrics": "wireit",
     "test:optimize-mkdirs": "wireit",
     "test:parallelism": "wireit",
+    "test:quiet": "wireit",
     "test:service": "wireit",
     "test:watch": "wireit"
   },
@@ -105,6 +106,7 @@
         "test:metrics",
         "test:optimize-mkdirs",
         "test:parallelism",
+        "test:quiet",
         "test:service",
         "test:watch"
       ]
@@ -357,6 +359,17 @@
       "files": [],
       "output": []
     },
+    "test:quiet": {
+      "command": "uvu lib/test \"^quiet-logger\\.test\\.js$\"",
+      "env": {
+        "NODE_OPTIONS": "--enable-source-maps"
+      },
+      "dependencies": [
+        "build"
+      ],
+      "files": [],
+      "output": []
+    },
     "test:service": {
       "command": "uvu lib/test \"^service\\.test\\.js$\"",
       "env": {
diff --git a/src/cli-options.ts b/src/cli-options.ts
index 7d30a9557..f465a89d3 100644
--- a/src/cli-options.ts
+++ b/src/cli-options.ts
@@ -13,7 +13,7 @@ import {ScriptReference} from './config.js';
 import {FailureMode} from './executor.js';
 import {unreachable} from './util/unreachable.js';
 import {Logger} from './logging/logger.js';
-import {QuietLogger} from './logging/quiet-logger.js';
+import {QuietCiLogger, QuietLogger} from './logging/quiet-logger.js';
 import {DefaultLogger} from './logging/default-logger.js';
 
 export const packageDir = await (async (): Promise<string | undefined> => {
@@ -194,6 +194,9 @@ export const getOptions = (): Result<Options> => {
     if (str === 'quiet') {
       return {ok: true, value: new QuietLogger(packageRoot)};
     }
+    if (str === 'quiet-ci') {
+      return {ok: true, value: new QuietCiLogger(packageRoot)};
+    }
     if (str === 'simple') {
       return {ok: true, value: new DefaultLogger(packageRoot)};
     }
diff --git a/src/logging/quiet-logger.ts b/src/logging/quiet-logger.ts
index 6efe8c5b8..3e87ad0a8 100644
--- a/src/logging/quiet-logger.ts
+++ b/src/logging/quiet-logger.ts
@@ -6,7 +6,11 @@
 
 import {Event} from '../event.js';
 import {Logger} from './logger.js';
-import {WriteoverLine} from './quiet/writeover-line.js';
+import {
+  CiWriter,
+  StatusLineWriter,
+  WriteoverLine,
+} from './quiet/writeover-line.js';
 import {QuietRunLogger, noChange, nothing} from './quiet/run-tracker.js';
 
 /**
@@ -21,18 +25,19 @@ import {QuietRunLogger, noChange, nothing} from './quiet/run-tracker.js';
 export class QuietLogger implements Logger {
   private runTracker;
   private readonly _rootPackage: string;
-  private readonly _writeoverLine = new WriteoverLine();
+  private readonly _statusLineWriter: StatusLineWriter;
 
-  constructor(rootPackage: string) {
+  constructor(rootPackage: string, statusLineWriter?: StatusLineWriter) {
     this._rootPackage = rootPackage;
+    this._statusLineWriter = statusLineWriter ?? new WriteoverLine();
     this.runTracker = new QuietRunLogger(
       this._rootPackage,
-      this._writeoverLine,
+      this._statusLineWriter,
     );
   }
 
   printMetrics() {
-    this._writeoverLine.clearAndStopSpinner();
+    this._statusLineWriter.clearAndStopRendering();
     this.runTracker.printSummary();
   }
 
@@ -44,9 +49,9 @@ export class QuietLogger implements Logger {
     if (line === noChange) {
       // nothing to do
     } else if (line === nothing) {
-      this._writeoverLine.clearAndStopSpinner();
+      this._statusLineWriter.clearAndStopRendering();
     } else {
-      this._writeoverLine.writeLine(line);
+      this._statusLineWriter.updateStatusLine(line);
     }
     if (event.type === 'info' && event.detail === 'watch-run-end') {
       this.printMetrics();
@@ -60,3 +65,16 @@ export class QuietLogger implements Logger {
     return this;
   }
 }
+
+/**
+ * A QuietLogger that is intended to be used in CI environments and other
+ * non-interactive environments.
+ *
+ * Doesn't use a spinner, updates less often, and doesn't use '/r' to writeover
+ * the previous line.
+ */
+export class QuietCiLogger extends QuietLogger {
+  constructor(rootPackage: string) {
+    super(rootPackage, new CiWriter());
+  }
+}
diff --git a/src/logging/quiet/run-tracker.ts b/src/logging/quiet/run-tracker.ts
index 3ca1992af..c3c830ca9 100644
--- a/src/logging/quiet/run-tracker.ts
+++ b/src/logging/quiet/run-tracker.ts
@@ -14,7 +14,7 @@ import {
 import {Failure, Info, Success, Output, Event} from '../../event.js';
 import {DefaultLogger, labelForScript} from '../default-logger.js';
 import {DEBUG} from '../logger.js';
-import {WriteoverLine} from './writeover-line.js';
+import {StatusLineWriter} from './writeover-line.js';
 import {StackMap} from './stack-map.js';
 
 interface SimpleOutput {
@@ -156,7 +156,7 @@ export class QuietRunLogger {
   private readonly _startTime = Date.now();
   private readonly _rootPackage: string;
   private readonly _defaultLogger: DefaultLogger;
-  private readonly _writeoverLine;
+  private readonly _statusLineWriter;
   /**
    * Sometimes a script will fail multiple times, but we only want to report
    * about the first failure for it that we find. Sometimes a script will
@@ -169,11 +169,11 @@ export class QuietRunLogger {
 
   constructor(
     rootPackage: string,
-    writeoverLine: WriteoverLine,
+    statusLineWriter: StatusLineWriter,
     defaultLogger?: DefaultLogger,
   ) {
     this._rootPackage = rootPackage;
-    this._writeoverLine = writeoverLine;
+    this._statusLineWriter = statusLineWriter;
     this._defaultLogger = defaultLogger ?? new DefaultLogger(rootPackage);
   }
 
@@ -185,7 +185,7 @@ export class QuietRunLogger {
     // Reuse the default logger, a minor savings.
     const instance = new QuietRunLogger(
       this._rootPackage,
-      this._writeoverLine,
+      this._statusLineWriter,
       this._defaultLogger,
     );
     // Persistent services stay running between runs, so pass along what we
@@ -330,10 +330,8 @@ export class QuietRunLogger {
     const peekResult = this._running.peek()?.[1];
     let mostRecentScript = '';
     if (peekResult !== undefined) {
-      mostRecentScript = labelForScript(
-        this._rootPackage,
-        peekResult.scriptReference,
-      );
+      mostRecentScript =
+        ' ' + labelForScript(this._rootPackage, peekResult.scriptReference);
     }
     const done = this._finishedScriptsWithCommands.size;
     const total = analysisInfo.scriptsWithCommands.size;
@@ -351,7 +349,7 @@ export class QuietRunLogger {
     }
     return `${percentDone} [${done.toLocaleString()} / ${total}] [${
       this._running.size
-    } running]${servicesInfo}${failureInfo} ${mostRecentScript}`;
+    } running]${servicesInfo}${failureInfo}${mostRecentScript}`;
   }
 
   private _markScriptAsFinished(script: ScriptReference) {
@@ -511,7 +509,7 @@ export class QuietRunLogger {
     this._encounteredFailures = true;
     {
       // eslint-disable-next-line @typescript-eslint/no-unused-vars
-      using _pause = this._writeoverLine.clearUntilDisposed();
+      using _pause = this._statusLineWriter.clearUntilDisposed();
       this._reportFailure(event);
     }
     return noChange;
@@ -615,7 +613,7 @@ export class QuietRunLogger {
       // Pause the status line while we print this real quick, but then resume
       // it.
       // eslint-disable-next-line @typescript-eslint/no-unused-vars
-      using _pause = this._writeoverLine.clearUntilDisposed();
+      using _pause = this._statusLineWriter.clearUntilDisposed();
       if (event.stream === 'stdout') {
         process.stdout.write(event.data);
       } else {
@@ -628,7 +626,7 @@ export class QuietRunLogger {
       // Unlike for a service, this is a terminal state, instead of pausing the
       // status line, we stop it completely, because for the rest of the run
       // we're just going to be  printing the root script's output.
-      this._writeoverLine.clearAndStopSpinner();
+      this._statusLineWriter.clearAndStopRendering();
       if (event.stream === 'stdout') {
         process.stdout.write(event.data);
       } else {
diff --git a/src/logging/quiet/writeover-line.ts b/src/logging/quiet/writeover-line.ts
index 5128170c6..09cb00e56 100644
--- a/src/logging/quiet/writeover-line.ts
+++ b/src/logging/quiet/writeover-line.ts
@@ -13,78 +13,63 @@ import {DEBUG} from '../logger.js';
     Symbol.dispose ?? Symbol('dispose');
 }
 
-/**
- * Handles displaying a single line of status text, overwriting the previously
- * written line, and displaying a spinner to indicate liveness.
- */
-export class WriteoverLine {
-  private _previousLineLength = 0;
-  private _line = '';
-  private _spinnerInterval: NodeJS.Timeout | undefined;
-  private _spinner = new Spinner();
+export interface StatusLineWriter {
+  clearAndStopRendering(): void;
+  updateStatusLine(line: string): void;
+  clearUntilDisposed(): Disposable | undefined;
+}
 
+abstract class BaseWriteoverLine implements StatusLineWriter {
+  private _updateInterval: NodeJS.Timeout | undefined;
+  protected _line = '';
+  protected _targetFps = 60;
+  /**
+   * If true, we write over the previous line with a \r carriage return,
+   * otherwise we write a new line.
+   */
+  protected _writeOver = !DEBUG;
   constructor() {
     // If the user does a ctrl-c then we stop the spinner.
     process.on('SIGINT', () => {
       console.log('Got a SIGINT in Writeover line');
-      this.clearAndStopSpinner();
+      this.clearAndStopRendering();
     });
   }
 
-  clearAndStopSpinner() {
+  /**
+   * Called periodically, so that the status line can be updated if needed.
+   */
+  protected abstract _update(): void;
+
+  clearAndStopRendering() {
     // Writeover the previous line and cancel the spinner interval.
-    if (this._spinnerInterval !== undefined) {
-      clearInterval(this._spinnerInterval);
-      this._spinnerInterval = undefined;
+    if (this._updateInterval !== undefined) {
+      clearInterval(this._updateInterval);
+      this._updateInterval = undefined;
     }
     if (this._line !== '') {
       this._line = '';
-      this._writeLineAndScrubPrevious('');
+      this._writeLine('');
     }
   }
 
-  writeLine(line: string) {
-    if (DEBUG) {
-      if (this._line !== line) {
-        // Ensure that every line is written immediately in debug mode
-        process.stderr.write(`  ${line}\n`);
-      }
-    }
-    this._line = line;
-    if (line === '') {
-      // Writeover the previous line and cancel the spinner interval.
-      if (this._spinnerInterval !== undefined) {
-        clearInterval(this._spinnerInterval);
-        this._spinnerInterval = undefined;
+  private _previousLineLength = 0;
+  protected _writeLine(line: string) {
+    if (!this._writeOver) {
+      if (line === '') {
+        return;
       }
-      this._writeLineAndScrubPrevious('');
-      return;
-    }
-    if (this._spinnerInterval !== undefined) {
-      // will render on next frame
+      process.stderr.write(line);
+      process.stderr.write('\n');
       return;
     }
-    // render now, and then schedule future renders.
-    if (!DEBUG) {
-      this._writeLatestLineWithSpinner();
-    }
-    // a smooth sixty
-    let targetFps = 60;
-    // Don't flood the CI log system with spinner frames.
-    if (process.env.CI) {
-      targetFps = 1 / 5;
+    process.stderr.write(line);
+    const overflow = this._previousLineLength - line.length;
+    if (overflow > 0) {
+      process.stderr.write(' '.repeat(overflow));
     }
-    // schedule future renders so the spinner stays going
-    this._spinnerInterval = setInterval(() => {
-      if (DEBUG) {
-        // We want to schedule an interval even in debug mode, so that tests
-        // will still fail if we don't clean it up properly, but we don't want
-        // to actually render anything here, since we render any new line
-        // the moment it comes in.
-        return;
-      }
-      this._writeLatestLineWithSpinner();
-    }, 1000 / targetFps);
+    process.stderr.write('\r');
+    this._previousLineLength = line.length;
   }
 
   /**
@@ -109,20 +94,66 @@ export class WriteoverLine {
    */
   clearUntilDisposed(): Disposable | undefined {
     // already cleared, nothing to do
-    if (this._spinnerInterval === undefined) {
+    if (this._updateInterval === undefined) {
       return undefined;
     }
     const line = this._line;
-    this.clearAndStopSpinner();
+    this.clearAndStopRendering();
     return {
       [Symbol.dispose]: () => {
-        this.writeLine(line);
+        this.updateStatusLine(line);
       },
     };
   }
 
+  updateStatusLine(line: string) {
+    if (DEBUG) {
+      if (this._line !== line) {
+        // Ensure that every line is written immediately in debug mode
+        process.stderr.write(`  ${line}\n`);
+      }
+    }
+    this._line = line;
+    if (line === '') {
+      // Writeover the previous line and cancel the spinner interval.
+      if (this._updateInterval !== undefined) {
+        clearInterval(this._updateInterval);
+        this._updateInterval = undefined;
+      }
+      this._writeLine('');
+      return;
+    }
+    if (this._updateInterval !== undefined) {
+      // will render on next frame
+      return;
+    }
+    // render now, and then schedule future renders.
+    if (!DEBUG) {
+      this._update();
+    }
+    // schedule future renders so the spinner stays going
+    this._updateInterval = setInterval(() => {
+      if (DEBUG) {
+        // We want to schedule an interval even in debug mode, so that tests
+        // will still fail if we don't clean it up properly, but we don't want
+        // to actually render anything here, since we render any new line
+        // the moment it comes in.
+        return;
+      }
+      this._update();
+    }, 1000 / this._targetFps);
+  }
+}
+
+/**
+ * Handles displaying a single line of status text, overwriting the previously
+ * written line, and displaying a spinner to indicate liveness.
+ */
+export class WriteoverLine extends BaseWriteoverLine {
+  private _spinner = new Spinner();
+
   private _previouslyWrittenLine: string | undefined = undefined;
-  private _writeLatestLineWithSpinner() {
+  protected override _update() {
     if (this._line === this._previouslyWrittenLine) {
       // just write over the spinner
       process.stderr.write(this._spinner.nextFrame);
@@ -130,21 +161,33 @@ export class WriteoverLine {
       return;
     }
     this._previouslyWrittenLine = this._line;
-    this._writeLineAndScrubPrevious(`${this._spinner.nextFrame} ${this._line}`);
+    this._writeLine(`${this._spinner.nextFrame} ${this._line}`);
   }
+}
 
-  private _writeLineAndScrubPrevious(line: string) {
-    process.stderr.write(line);
-    const overflow = this._previousLineLength - line.length;
-    if (overflow > 0) {
-      process.stderr.write(' '.repeat(overflow));
-    }
-    if (DEBUG) {
-      process.stderr.write('\n');
-    } else {
-      process.stderr.write('\r');
+/**
+ * Like WriteoverLine, but it updates much less frequently, just prints lines
+ * rather doing fancy writeover, doesn't draw a spinner, and stays silent
+ * if the status line line hasn't changed.
+ */
+export class CiWriter extends BaseWriteoverLine {
+  constructor() {
+    super();
+    // Don't write too much, no need to flood the CI logs.
+    this._targetFps = 1;
+    // GitHub seems to handle \r carraige returns the same as \n, but
+    // we don't want to rely on that. Just print status lines on new lines.
+    this._writeOver = false;
+  }
+
+  protected previousLine = '';
+  protected override _update() {
+    if (this._line === this.previousLine) {
+      // nothing new to log
+      return;
     }
-    this._previousLineLength = line.length;
+    this.previousLine = this._line;
+    this._writeLine(this._line);
   }
 }
 
diff --git a/src/test/quiet-logger.test.ts b/src/test/quiet-logger.test.ts
new file mode 100644
index 000000000..10bc7329f
--- /dev/null
+++ b/src/test/quiet-logger.test.ts
@@ -0,0 +1,114 @@
+/**
+ * @license
+ * Copyright 2023 Google LLC
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+import {suite} from 'uvu';
+import * as assert from 'uvu/assert';
+import {timeout} from './util/uvu-timeout.js';
+import {WireitTestRig} from './util/test-rig.js';
+
+const test = suite<{rig: WireitTestRig}>();
+
+test.before.each(async (ctx) => {
+  try {
+    ctx.rig = new WireitTestRig();
+    // process.env['SHOW_TEST_OUTPUT'] = 'true';
+    // ctx.rig.env['WIREIT_DEBUG_LOGGER'] = 'true';
+    await ctx.rig.setup();
+  } catch (error) {
+    // Uvu has a bug where it silently ignores failures in before and after,
+    // see https://github.com/lukeed/uvu/issues/191.
+    console.error('uvu before error', error);
+    process.exit(1);
+  }
+});
+
+test.after.each(async (ctx) => {
+  try {
+    await ctx.rig.cleanup();
+  } catch (error) {
+    // Uvu has a bug where it silently ignores failures in before and after,
+    // see https://github.com/lukeed/uvu/issues/191.
+    console.error('uvu after error', error);
+    process.exit(1);
+  }
+});
+
+test(
+  'CI logger with a dependency chain',
+  timeout(async ({rig}) => {
+    // a --> b --> c
+    rig.env.WIREIT_LOGGER = 'quiet-ci';
+    const cmdA = await rig.newCommand();
+    const cmdB = await rig.newCommand();
+    const cmdC = await rig.newCommand();
+    await rig.write({
+      'package.json': {
+        scripts: {
+          a: 'wireit',
+          b: 'wireit',
+          // wireit scripts can depend on non-wireit scripts.
+          c: cmdC.command,
+        },
+        wireit: {
+          a: {
+            command: cmdA.command,
+            dependencies: ['b'],
+          },
+          b: {
+            command: cmdB.command,
+            dependencies: ['c'],
+          },
+        },
+      },
+    });
+    const exec = rig.exec('npm run a');
+    await exec.waitForLog(/0% \[0 \/ 3\] \[1 running\] c/);
+
+    const invC = await cmdC.nextInvocation();
+    invC.stdout('c stdout');
+    invC.stderr('c stderr');
+    invC.exit(0);
+    await exec.waitForLog(/33% \[1 \/ 3\] \[1 running\] b/);
+
+    const invB = await cmdB.nextInvocation();
+    invB.stdout('b stdout');
+    invB.stderr('b stderr');
+    invB.exit(0);
+    await exec.waitForLog(/67% \[2 \/ 3\] \[1 running\] a/);
+
+    const invA = await cmdA.nextInvocation();
+    invA.stdout('a stdout\n');
+    // immediately logged, because it's the root command
+    await exec.waitForLog(/a stdout/);
+    invA.stderr('a stderr\n');
+    await exec.waitForLog(/a stderr/);
+    invA.exit(0);
+
+    const res = await exec.exit;
+    assert.equal(res.code, 0);
+    assert.equal(cmdA.numInvocations, 1);
+    assert.equal(cmdB.numInvocations, 1);
+    assert.equal(cmdC.numInvocations, 1);
+    assert.match(res.stdout, 'a stdout\n');
+    assert.match(res.stdout, /Ran 3 scripts and skipped 0/s);
+    assertEndsWith(
+      res.stderr.trim(),
+      `
+  0% [0 / 3] [1 running] c
+ 33% [1 / 3] [1 running] b
+ 67% [2 / 3] [1 running] a
+a stderr
+`.trim(),
+    );
+  }),
+);
+
+function assertEndsWith(actual: string, expected: string) {
+  const actualSuffix = actual.slice(-expected.length);
+  assert.equal(actualSuffix, expected);
+}
+
+test.run();