Skip to content

fix(core): apply chained configurators to the cmd log entry - #1496

Open
DevCop95 wants to merge 1 commit into
google:mainfrom
DevCop95:fix/log-cmd-chained-configurators
Open

fix(core): apply chained configurators to the cmd log entry#1496
DevCop95 wants to merge 1 commit into
google:mainfrom
DevCop95:fix/log-cmd-chained-configurators

Conversation

@DevCop95

Copy link
Copy Markdown

Fixes #931

Problem

.quiet() / .verbose() chained onto a template tag are not reflected in the cmd log entry:

$.verbose = true
await $`echo foo`.quiet()   // still prints `$ echo foo`

The reporter noticed this in 8.2.0; it still reproduces on main (8.9.0).

Root cause

A process starts eagerly: $ calls pp.run() synchronously inside the template tag (core.ts, $ factory), and exec() fires on.start in the same tick. So the cmd entry is emitted before the chained configurators have run, and isVerbose() is evaluated against a snapshot that is still the default one.

stdout / stderr / end entries are unaffected because they arrive on later ticks — hence the inconsistency the issue describes, where a single process logs cmd: verbose=true next to stdout: verbose=false.

Instrumented on main:

A: before tag
  LOG cmd verbose=true     <- emitted during the tag, before .quiet()
B: after tag, before .quiet()
C: after .quiet()
  LOG stdout verbose=false
  LOG end verbose=false

Fix

Defer the cmd entry by one microtask so the synchronous configurator chain is applied first. queueMicrotask (not setImmediate) keeps the entry ahead of any I/O-driven stdout/stderr/end entry.

Sync mode is excluded: $.sync returns ProcessOutput rather than a ProcessPromise, so there is nothing to chain, and spawnSync emits its output in the same tick — deferring there would print the command after its output.

Output for the script in the issue now matches the pre-8.2.0 behaviour it documents as expected.

Trade-off

Output the caller writes synchronously between the tag and the next await now lands before the $ cmd banner:

const p = $`echo hi`
console.log('---')   // printed before `$ echo hi`
await p

That window is one microtask wide, and it is the cost of letting .quiet()/.verbose() affect the entry they are supposed to affect.

Tests

  • applies chained configurators to the cmd entry — covers all three symptoms from the issue (.quiet(), .verbose(false), and .quiet(false) re-enabling output). Fails on main.
  • keeps the cmd entry ahead of the output in sync mode — guards the sync carve-out.

A process starts eagerly: `$` calls `run()` synchronously inside the
template tag and `exec()` fires `on.start` in the same tick, so the `cmd`
entry was emitted before `.quiet()` / `.verbose()` could be applied. The
later `stdout`/`stderr`/`end` entries did see them, which is why a single
process could log `cmd: verbose=true` next to `stdout: verbose=false`.

Defer the entry by a microtask so the synchronous configurator chain lands
first, while keeping it ahead of the I/O-driven entries. Sync mode is
excluded: it has nothing to chain and emits its output in the same tick.

Fixes google#931
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Changed output behavior when using quiet and verbose in version 8.2.0

1 participant