google / zx

A tool for writing better scripts
https://google.github.io/zx/
Apache License 2.0
43.18k stars 1.1k forks source link

Changed output behavior when using quiet and verbose in version 8.2.0 #931

Open AlexanderKlump opened 3 weeks ago

AlexanderKlump commented 3 weeks ago

Testing the latest change from version 8.1.9 to 8.2.0 we detected some unexpected change of behavior in the output of our scripts working with zx. I tried to reproduce the observed behavior in the following TS script, which I run with node --loader ts-node/esm --no-warnings=ExperimentalWarning testZx.ts and my node version is v20.10.0.

import { $, LogEntry } from "zx";

await $`echo "$.verbose = ${$.verbose} & $.quiet = ${$.quiet}"`; //from this I infer what is the expected behavior for $.verbose = false and $.quiet = false
$.verbose = true;
await $`echo "$.verbose = ${$.verbose} & $.quiet = ${$.quiet}"`; //from this I infer what is the expected behavior for $.verbose = true and $.quiet = false
await $`echo "$.verbose = ${$.verbose} & $.quiet = ${$.quiet} & .verbose(false)"`.verbose(false); //expected to output nothing
await $`echo "$.verbose = ${$.verbose} & $.quiet = ${$.quiet} & .quiet(true)"`.quiet(true); //expected to output nothing
$.quiet = true;
await $`echo "$.verbose = ${$.verbose} & $.quiet = ${$.quiet}"`; //expected to output nothing
await $`echo "$.verbose = ${$.verbose} & $.quiet = ${$.quiet} & .quiet(false)"`.quiet(false); //expected to output the zx command and its output

$.verbose = false;
await $`echo "$.verbose = ${$.verbose} & $.quiet = ${$.quiet} & .quiet(false)"`.quiet(false); //expected to output nothing

$.verbose = true;

$.log = (entry: LogEntry) => {
    console.log(`entry.kind = ${entry.kind} & entry.verbose = ${entry.verbose}`);
};

$.quiet = false;

await $`echo "Hello World"`; //expected to lead to entry.verbose = true
await $`echo "Hello World"`.quiet(); //expected to lead to entry.verbose = false

With zx version 8.1.9 the output is:

$ echo "$.verbose = true & $.quiet = false"
$.verbose = true & $.quiet = false
$ echo "$.verbose = true & $.quiet = true & .quiet(false)"
$.verbose = true & $.quiet = true & .quiet(false)
entry.kind = cmd & entry.verbose = true
entry.kind = stdout & entry.verbose = true
entry.kind = cmd & entry.verbose = false
entry.kind = stdout & entry.verbose = false

Observations:

With zx version 8.2.0 we get this:

$ echo "$.verbose = true & $.quiet = false"
$.verbose = true & $.quiet = false
$ echo "$.verbose = true & $.quiet = false & .verbose(false)"
$ echo "$.verbose = true & $.quiet = false & .quiet(true)"
$.verbose = true & $.quiet = true & .quiet(false)
entry.kind = cmd & entry.verbose = true
entry.kind = stdout & entry.verbose = true
entry.kind = cmd & entry.verbose = true
entry.kind = stdout & entry.verbose = false

Observations:

For me this looks like an unintended behavior, or do I misperceive something?

antongolub commented 3 weeks ago

We've the fixed the internal process init logic, that previously blocked pid obtaining: in short cp.spawn is not wrapped with setImmediate workaround anymore.

$({quiet: true})cmd applies the option before the first log event may occur, meanwhile $cmd.quiet() modifies the behavior of the running process.

antongolub commented 3 weeks ago

@AlexanderKlump , Here's this specific piece. If you have any ideas on how to soften the subtle side effects, share them with us plz.