Waiting for bursts of external writes: what an interactive terminal shows

Summary

Tradeoffs

Bursts and sustained outside output

 BUNDLE  ./index.js ░░░░░░░░░░░░░░░░ 0% (51/3000)
EXT 00002 out
 BUNDLE  ./index.js ░░░░░░░░░░░░░░░░ 0% (101/3000)
EXT 00003 out
 BUNDLE  ./index.js ░░░░░░░░░░░░░░░░ 0% (151/3000)
EXT 00004 out
 BUNDLE  ./index.js ░░░░░░░░░░░░░░░░ 0% (202/3000)
EXT 00005 out

 BUNDLE  ./index.js ░░░░░░░░░░░░░░░░ 0% (32/3000)
EXT 00001 out
EXT 00002 out
EXT 00003 out
EXT 00004 out
EXT 00005 out
EXT 00006 out
EXT 00007 out

The first eight rows of the rendered screen in a synthetic 6 s build with a line every 100 ms. The status lines continue below in the same pattern.

Real Metro.runServer builds, 2 runs per side, ranges shown. Copies are status lines left in the whole scrollback at the end. In the no-output row, the longest wait reflects main-thread stalls in the build and not the terminal code.

The status blinks during terminal.log traffic

Share of a synthetic 6 s build with the status on the 40-row screen, sampled at 60 Hz. Medians of 3 runs for main, the PR and the 33 ms column, and 2 runs for the 100 ms columns.

Build time and main-thread cost

Dev bundle through a PTY with a fast reader. Medians of 16 runs per side (warm), 8 (warm with lines) and 6 (cold). Reporter time, main → PR → fix: 3.1 → 134.5 → 4.1 ms warm, 132 → 261 → 162 ms with lines, 22 → 407 → 57 ms cold. Bytes written: 2.0 → 3.4 → 3.3 KB warm, 0.93 → 0.93 → 2.43 MB with lines, 21 → 59 → 56 KB cold. Main-thread CPU on the PR against main: +148 ms warm (CI +110 to +186), +119 ms warm with lines (CI +84 to +154), +328 ms cold (CI +246 to +413). Against main, the fix's CIs for CPU include zero when warm and cold.

Slow readers

Medians of 2 runs per side (cold) and 3 (warm), with the read rate set by a reader on the PTY, not a real slow link. The limit columns include the log() fix, which doesn't write more without log lines. The unlimited cold row is from the 6-run comparison above, except for the 100 ms column, which shows its 2 runs.

What's unchanged or better

• No outside output: The bar updates at about 30 Hz against 10 Hz, with no leftovers and the same final state.
• Wrapping and resizing: Clean at 20 and 40 columns, including multi-line and two-bundle statuses. Narrowing the window from 120 to 40 columns leaves one reflowed line on both sides. The bytes differ (\r against a long cursor-left), and the rendered result is the same.
• Windows 11 through ssh -tt: Erasing, wrapping, logs and the beforeExit flush render correctly. A burst leaves a copy per line on main and none between its lines on the PR. This ran the Terminal class on its own through conhost, without a full Metro build.
• HMR: "Done" lines arrive within about 1 ms on both sides, including straight after a console.log. A rebuild under 333 ms following a log shows no bar, which reads as cleaner.
• Key handling: Fine in raw mode with a menu status. The stale menu copy left on main when a line lands right after a build was gone in the one run of this scenario on each side.
• Exit: A natural exit writes the latest status. process.exit() and an uncaught error leave the same or a newer status. After Ctrl-C the status stayed on screen in 5 of 6 runs against 6 of 6, with the cursor correct in all of them. The sixth run simply has no status left.
• Writers bytesWritten can't see: Lines from stdio: 'inherit' children and fs.writeSync(1, …) are erased by the next redraw and a status copy stays, the same on both sides. This is the known limit from react/metro#2130.
• Separate streams: With a TTY on stdout and stderr piped, stderr bytes count as outside output though they never reach the terminal. That summing already exists on main (60 copies at 10 lines/s, against 3 here), and on the PR the bar updates only about every 2 s in this setup.
• Piped stdout: 3 status lines over a 6 s build on both sides.
• API: #isUpdating and #hasPendingUpdate were private, so removing them isn't an API change. [Breaking] is the right scope for the removed event type.

Smaller points

• Mixed traffic loses the benefit. #write rolls outside bytes into the count, so console.log followed by terminal.log looks quiet to the next status. Alternating the two at 10 lines/s leaves 60 copies on both sides.
• Old output still delays the next status. The wait compares bytes, not time, so one console.log long ago delays the next status by 333 ms: 336 ms against 1 ms after 3 s of quiet. Log lines aren't affected.
• Several Terminals at once. 11 or more updating together trigger MaxListenersExceededWarning on beforeExit.
• Non-TTY waitForUpdates(). With the process kept alive, it takes 3.5 s against 35 ms when the status has changed. Metro, @expo/cli and React Native's community CLI plugin don't call it.

Expo CLI, when it adopts this version

• Progress events: MetroTerminalReporter emits bundling:progress from the removed bundle_transform_progressed_throttled event. Moving to bundle_transform_progressed means handling every event, so it needs a limit of its own.
• Warnings and errors: LogRespectingTerminal clears the status, flushes, writes to stderr directly and restores the status. That write counts as outside output, so each warning hides the status for up to 333 ms. At 10 warnings/s it's on screen 1.7% of a build against 100%. This is one run of the same logic in the harness, not of Expo CLI itself.
• Types: TerminalReporter.types.ts declares the removed _scheduleUpdateBundleProgress.

Recommendation

• Limit rendering in TerminalReporter to one progress update per 100 ms. This removes the warm build cost and the slow-reader regression, and it's a timestamp check, so lodash.throttle stays out. The bar stays at the 10 Hz it has today. Without a trailing render, the count on screen can lag until the next event or bundle_build_done.
• Restore the status in Terminal.log(), in the same write as the line. This removes the blink at every rate measured. It writes more at very high log rates, and if that matters more, the status can be restored only below some rate.
• Add a test that the status stays on the screen across log(). The new tests use fake timers over a small screen model with real escape handling, which suits this well, and they don't cover it yet.
• Consider the 333 ms quiet period against lines 333–500 ms apart. Lowering it is a judgement call, and leaving it as it is seems reasonable.

// TerminalReporter.update()
this._log(event);
this._updateState(event);
if (event.type === 'bundle_transform_progressed') {
  const now = performance.now();
  if (now - (this._lastProgressRender ?? -Infinity) < 100) {
    return;
  }
  this._lastProgressRender = now;
}
this.terminal.status(this._getStatusMessage());

// Terminal.log()
const shownStatus = this.#writtenStatus;
this.#eraseWrittenStatusMaybe();
const isErased =
  this.#ttyStream != null &&
  shownStatus.length > 0 &&
  this.#getBytesWritten() === this.#bytesWrittenAfterLastWrite;
this.#write(
  util.format(format, ...args) + '\n' + (isErased ? shownStatus + '\n' : ''),
);
if (isErased) {
  this.#writtenStatus = shownStatus;
}
this.#scheduleStatusUpdate();

These are the measured changes, applied to Babel-compiled copies of the PR's files. _log and _updateState still run per event, so subclass overrides see every event.

Method

const term = new Terminal({cols, rows, scrollback: 50000, allowProposedApi: true});
const STATUS = /(?:BUNDLE|PREBUNDLE)\s.*\((\d+)\/(\d+)\)/;
for (const {t, data} of recording) {
  await new Promise(resolve => term.write(data, resolve));
  const rows = viewportRows(term);
  frames.push({t, onScreen: rows.some(r => STATUS.test(r)), bottom: STATUS.test(lastNonEmpty(rows))});
}
for (let t = start; t < end; t += 16.67) {
  // Take the latest frame at or before t, and count onScreen and bottom.
}

const reporter = new TerminalReporter(new Terminal(process.stdout));
reporter.update({type: 'bundle_build_started', buildID, isPrefetch: false, bundleDetails});
// Every 5 ms: catch up to elapsed / duration * total, then the scenario's output.
reporter.update({type: 'bundle_transform_progressed', buildID, transformedFileCount, totalFileCount});
// Outside output:
console.log(line);
// Output through Terminal, at the rate under test:
reporter.update({type: 'client_log', level: 'log', data: [line]});
reporter.update({type: 'bundle_build_done', buildID});

Revisions

Each revision links to a frozen copy of the report as it was published. The commit history has every edit.