CI v8tests fails on master

[fhinkel]

When we ran node-test-commit-v8-linux on the CI for a V8 cherry-pick PR, we noticed that it's failing on master. Anybody want to bisect? Thanks 🙏 !

V8 CI: https://ci.nodejs.org/job/node-test-commit-v8-linux/1008/

It's the test in v8/deps/test/message/console.js. The test runner compares the output to the expected output in console.out. But I don't see the difference.

Actual output:

abcd: 0.055000
b: 0.000000
a: 0.001000
log more
warn 2
debug
info
/home/iojs/build/workspace/node-test-commit-v8-linux/nodes/benchmark/v8test/v8test/deps/v8/test/message/console.js:25: Error: exception
console.info({ toString: () => {throw new Error("exception");} })
                                ^
Error: exception
    at Object.toString (/home/iojs/build/workspace/node-test-commit-v8-linux/nodes/benchmark/v8test/v8test/deps/v8/test/message/console.js:25:39)
    at console.info (<anonymous>)
    at /home/iojs/build/workspace/node-test-commit-v8-linux/nodes/benchmark/v8test/v8test/deps/v8/test/message/console.js:25:9

Expected output:

abcd: {NUMBER}
b: 0.000000
a: {NUMBER}
log more
warn 2
debug
info
*%(basename)s:25: Error: exception
console.info({ toString: () => {throw new Error("exception");} })
                                ^
Error: exception
    at Object.toString (*%(basename)s:25:39)
    at console.info (<anonymous>)
    at *%(basename)s:25:9

[bnoordhuis]

FWIW, I can't reproduce locally:

$ ./configure --enable-d8 && make && cd deps/v8
# <output elided>

$ python tools/run-tests.py --shell-dir=../../out/Release --arch=x64 --mode=release \
  --extra-flags="--test --random-seed=-630402464 --no-stress-opt --nohard-abort" \
  message/console
>>> Running tests for x64.release
[00:00|% 100|+   1|-   0]: Done

(For that matter, all the message tests pass.)

[fhinkel]

Thanks for checking @bnoordhuis . I started another CI job on master. I'm confused because 1005 failed (with IMHO unrelated PR), 1007 passed, and 1008 failed again.
V8 CI: https://ci.nodejs.org/job/node-test-commit-v8-linux/1009/

If I read the test correctly, the test runner only compares stdout with the expected files. Are we doing anything weird on our CI and we get the failing test because the word error on stderr is piped to stdout?

_{refack: replace GitHub autolinks to CI manual links}

[fhinkel]

cc @nodejs/build

#1008 and #1009 are run on master.

[bnoordhuis]

Are we doing anything weird on our CI and we get the failing test because the word error on stderr is piped to stdout?

It goes to stderr. What you see is the test runner printing the captured output to stdout post facto, when the test is done:

=== message/console ===
--- stderr ---
error
--- stdout ---
default: 50.779000
abcd: 0.058000
# ...

[fhinkel]

Yes, was just a thought of what could maybe be different between local and CI.

Did I mess up the parameters for #1009 and it's not the regular Node master?

[bnoordhuis]

Nope, that's master alright.

[refack]

I'm doing preliminary biset:
[last passing] e07e708...27e12e7 [known fail]

1st candidate: 27e12e7

[fhinkel]

@refack Thanks for looking into this. Not sure if a bisect is useful - 1010 looks like a rerun of 1008, both with master and it's green again. Also, we can't reproduce it locally (and I don't see a difference between actual and expected output on the failing CI).

[refack]

@fhinkel I'm "bisecting" on the CI machine since there is some TTY manipulation there, and that's why I tend to suspect 27e12e7. 1010 is confusing though...

[fhinkel]

1006 and 1007 are green as well - though they ran on the same or later master as 1005 (I'm pretty sure the 1005 PR does not cause the failure, also because we see the failure later on master without that PR merged in, I just landed it a few minutes ago and it's green in 1011)...seeing that it's green again, just close this? 😆

[refack]

hmmm... with all this evidence it does look like a CI setup quirk. We can close this and I'll open an issue on the build repo

[fhinkel]

sgtm

[refack]

Cross-ref: nodejs/build#936