tools: include exit code in test failures #19855

Trott · 2018-04-06T17:46:41Z

Include the exit code in test failures. This will give us more
information during the currently-puzzling failures that provide no
information in CI such as:

03:10:10 not ok 563 parallel/test-fs-truncate
03:10:10   ---
03:10:10   duration_ms: 1.119
03:10:10   severity: fail
03:10:10   stack: |-
03:10:10   ...

@BridgeAR @addaleax @nodejs/build @nodejs/testing

Checklist

make -j4 test (UNIX), or vcbuild test (Windows) passes
commit message follows commit guidelines

Include the exit code in test failures. This will give us more information during the currently-puzzling failures that provide no information in CI such as: ``` 03:10:10 not ok 563 parallel/test-fs-truncate 03:10:10 --- 03:10:10 duration_ms: 1.119 03:10:10 severity: fail 03:10:10 stack: |- 03:10:10 ... ```

refack · 2018-04-06T18:10:37Z

Tad "hacky", I'll see if I can make something more TAPish.

refack · 2018-04-06T21:59:39Z

Just scribbling some tweaks

https://ci.nodejs.org/job/node-test-pull-request-lite/443/

rvagg · 2018-04-06T22:04:20Z

tools/test.py

@@ -325,12 +329,10 @@ def HasRun(self, output):
    # duration_ms is measured in seconds and is read as such by TAP parsers.
    # It should read as "duration including ms" rather than "duration in ms"
    logger.info('  ---')
-    logger.info('  duration_ms: %d.%d' %
+    logger.info('  duration (s): %d.%d' %


I know this is an annoyance for many folks but I'd advise against changing this and instead learn to read it as "duration including milliseconds". From memory there's some tooling in Jenkins that depends on this. It's become a TAP quirk, not something we've introduced.

Ack. I'm just smoke testing the CI TAP tooling

rvagg · 2018-04-06T22:08:47Z

tools/test.py

@@ -299,6 +302,7 @@ def HasRun(self, output):

      if output.HasTimedOut():
        self.severity = 'fail'
+        self.traceback += '\nTimed Out'


Not a big deal but I'd prefer we leave existing strings alone on this output where possible, it's parsable and we don't know what might depend on it--likely nothing but why risk it. I assume that in the majority of cases there's not going to be a traceback to append to so perhaps if you check for it being length>0 and then append \n and then regardless append 'timeout', so in the majority of cases we just get a 'timeout' and nothing's changed.

Ping @Trott @refack

My motivation was that the previous code was self.traceback = 'timeout', so in cases where there was output from the test we have been losing it if the test timesout.

As for the parsability of the output, I'm on a deepdive into the CI parsing code, trying to grok what's actually being consumed and what just passes through (I have same concern for the new exitcode field).

P.S. duration_ms is consumed in two code paths, one treats it as seconds (the red arrow):
https://github.com/jenkinsci/tap-plugin/blob/05bd8843f0c87a379fdaec4f6e007c1124f1a35c/src/main/java/org/tap4j/plugin/model/TapStreamResult.java#L165-L167

and another place as milliseconds (the green arrow):
https://github.com/jenkinsci/tap-plugin/blob/3a80a472c6acff847ae3f572bb6bcc47d64ab9dd/src/main/java/org/tap4j/plugin/model/TapTestResultResult.java#L260-L271

P.P.S. I'm looking into finishing the work started by @jbergstroem (tap2junit) as the final goal.

Rest of the changes look okay, but would it be okay to use self.severity to signal that the test has timed out? I think its better not to alter the traceback. Extreme corner case: if a test prints Timed Out and exits, we cannot be sure if the test exceeded the timelimit or not.

Just for context the old code did:

node/tools/test.py

Line 332 in bdcd041

self.traceback = 'timeout'

And even the current code does:

node/tools/test.py

Line 287 in 800ce94

self.traceback = output.output.stdout + output.output.stderr

and

node/tools/test.py

Line 298 in 800ce94

self.traceback = "oh no!\nexit code: " + PrintCrashed(exit_code)

So we are already being naughty with traceback

As for severity, it is the only really semantic field (the TAP plugin uses it to categorize the results), so I would advise against changing it. A different option is to add a message field or even a dedicated timed out field.

Trott · 2018-04-06T22:15:54Z

Because these changes are getting mildly more involved, I'll remove the fast-track label. Feel free to re-add it. (And thanks, @refack! I appreciate you making my quick hack more thoughtful!)

refack · 2018-04-06T22:18:55Z

(And thanks, @refack! I appreciate you making my quick hack more thoughtful!)

Ohh boy I got rusty with the git 👴, wanted to draft something with the GitHub GUI (always a mistake) and ended up pushing to your branch...

Pulled my changes out of your branch, sorry.

Trott · 2018-04-06T22:19:51Z

Pulled my changes out of your branch, sorry.

It's cool. You can work in my branch if you want. Or work in your own branch. Whatevs.

refack · 2018-04-06T22:25:19Z

It's cool. You can work in my branch if you want. Or work in your own branch. Whatevs.

Always the gracious host 🎩
Please forgive any faux pas I make while I re-get my footing.

Trott · 2018-04-06T22:32:53Z

Please forgive any faux pas I make while I re-get my footing.

@refack Delighted you're back!

Trott · 2018-04-09T04:22:46Z

@refack: As we continue to see severity: fail with no stdout or stderr in CI, I'm kind of eager to land even just my initial hacky change just to see what the exit codes are. Are your improvements likely to be ready to go soon? If so, AWESOME! If not, do you mind if I move forward with my one-line change and you can make it less hacky whenever you're done?

refack · 2018-04-09T17:11:32Z

I'm kind of eager to land

AFAICT this is ready to land as is. I've tested it in multiple scenarios. We just need a +1 from someone.

refack · 2018-04-09T17:34:48Z

Screenshot from synthetic timeout:

Trott · 2018-04-09T18:16:32Z

@nodejs/python

Trott · 2018-04-09T18:18:15Z

CI: https://ci.nodejs.org/job/node-test-pull-request/14144/

Trott · 2018-04-09T18:29:46Z

Linux failure is build/infra-related. Unfortunately, I'm unable to fix it. (Tried wiping the workspace in Jenkins.)

refack · 2018-04-09T20:03:51Z

Resume build: https://ci.nodejs.org/job/node-test-commit/17575/

BridgeAR · 2018-04-09T23:03:55Z

@refack please only add the author-ready label in case a PR has at least one LG as described in the collaborator guide.

BridgeAR · 2018-04-09T23:04:42Z

@nodejs/python @nodejs/build PTAL. This needs some LGs.

Trott · 2018-04-10T00:02:27Z

Re-running Windows (the only CI task that failed): https://ci.nodejs.org/job/node-test-commit-windows-fanned/17087/

rvagg · 2018-04-10T02:55:30Z

I'm still not cool with the change of the string timeout to \nTimed Out. It's a separate issue to there being a stack or not; most likely there will not be a stack so it'll just be a straight timeout -> \nTimed Out. Unnecessarily messing with a parseable format isn't a great idea.

refack · 2018-04-10T20:13:32Z

I'm still not cool with the change of the string timeout to \nTimed Out. It's a separate issue to there being a stack or not; most likely there will not be a stack so it'll just be a straight timeout -> \nTimed Out. Unnecessarily messing with a parseable format isn't a great idea.

I rolled-back that specific change, But I do want to point out:

node/tools/test.py

Line 287 in 800ce94

self.traceback = output.output.stdout + output.output.stderr

so the current code swallows not only stacks, but all output to stderr & stdout.

https://ci.nodejs.org/job/node-test-pull-request/14184/

Trott · 2018-04-11T00:15:11Z

LGTM but I guess I can't approve my own PR even if I didn't write any of the code. :-P

Trott · 2018-04-11T14:50:48Z

Would be nice to get at least one more approval. @nodejs/build @nodejs/python @jbergstroem @bnoordhuis @Fishrock123 @mscdex @rvagg @nodejs/testing

Trott · 2018-04-11T23:18:33Z

Re-running linux CI: https://ci.nodejs.org/job/node-test-commit-linux/17876/
Re-running Windows CI: https://ci.nodejs.org/job/node-test-commit-windows-fanned/17154/

Trott · 2018-04-11T23:55:55Z

Linux again: https://ci.nodejs.org/job/node-test-commit-linux/17879/

Trott · 2018-04-12T03:03:13Z

These test-http-readable-data-event failures are getting really old...

Linux yet again: https://ci.nodejs.org/job/node-test-commit-linux/17884/

Include the exit code in test failures. This will give us more information during the currently-puzzling failures that provide no information in CI such as: ``` 03:10:10 not ok 563 parallel/test-fs-truncate 03:10:10 --- 03:10:10 duration_ms: 1.119 03:10:10 severity: fail 03:10:10 stack: |- 03:10:10 ... ``` PR-URL: nodejs#19855 Reviewed-By: Sakthipriyan Vairamani <[email protected]> Reviewed-By: Ben Noordhuis <[email protected]> Reviewed-By: Gibson Fahnestock <[email protected]> Reviewed-By: Rod Vagg <[email protected]>

PR-URL: nodejs#19855 Reviewed-By: Sakthipriyan Vairamani <[email protected]> Reviewed-By: Ben Noordhuis <[email protected]> Reviewed-By: Gibson Fahnestock <[email protected]> Reviewed-By: Rod Vagg <[email protected]>

Trott · 2018-04-12T04:05:07Z

Landed in f3f1298...a3db1cc

Include the exit code in test failures. This will give us more information during the currently-puzzling failures that provide no information in CI such as: ``` 03:10:10 not ok 563 parallel/test-fs-truncate 03:10:10 --- 03:10:10 duration_ms: 1.119 03:10:10 severity: fail 03:10:10 stack: |- 03:10:10 ... ``` PR-URL: #19855 Reviewed-By: Sakthipriyan Vairamani <[email protected]> Reviewed-By: Ben Noordhuis <[email protected]> Reviewed-By: Gibson Fahnestock <[email protected]> Reviewed-By: Rod Vagg <[email protected]>

PR-URL: #19855 Reviewed-By: Sakthipriyan Vairamani <[email protected]> Reviewed-By: Ben Noordhuis <[email protected]> Reviewed-By: Gibson Fahnestock <[email protected]> Reviewed-By: Rod Vagg <[email protected]>

Include the exit code in test failures. This will give us more information during the currently-puzzling failures that provide no information in CI such as: ``` 03:10:10 not ok 563 parallel/test-fs-truncate 03:10:10 --- 03:10:10 duration_ms: 1.119 03:10:10 severity: fail 03:10:10 stack: |- 03:10:10 ... ``` PR-URL: #19855 Reviewed-By: Sakthipriyan Vairamani <[email protected]> Reviewed-By: Ben Noordhuis <[email protected]> Reviewed-By: Gibson Fahnestock <[email protected]> Reviewed-By: Rod Vagg <[email protected]>

PR-URL: #19855 Reviewed-By: Sakthipriyan Vairamani <[email protected]> Reviewed-By: Ben Noordhuis <[email protected]> Reviewed-By: Gibson Fahnestock <[email protected]> Reviewed-By: Rod Vagg <[email protected]>

Include the exit code in test failures. This will give us more information during the currently-puzzling failures that provide no information in CI such as: ``` 03:10:10 not ok 563 parallel/test-fs-truncate 03:10:10 --- 03:10:10 duration_ms: 1.119 03:10:10 severity: fail 03:10:10 stack: |- 03:10:10 ... ``` PR-URL: #19855 Reviewed-By: Sakthipriyan Vairamani <[email protected]> Reviewed-By: Ben Noordhuis <[email protected]> Reviewed-By: Gibson Fahnestock <[email protected]> Reviewed-By: Rod Vagg <[email protected]>

PR-URL: #19855 Reviewed-By: Sakthipriyan Vairamani <[email protected]> Reviewed-By: Ben Noordhuis <[email protected]> Reviewed-By: Gibson Fahnestock <[email protected]> Reviewed-By: Rod Vagg <[email protected]>

nodejs-github-bot added test Issues and PRs related to the tests. tools Issues and PRs related to the tools directory. labels Apr 6, 2018

rvagg reviewed Apr 6, 2018

View reviewed changes

refack force-pushed the add-error-code branch from ad307f1 to bdcd041 Compare April 6, 2018 22:15

Trott removed the fast-track PRs that do not need to wait for 48 hours to land. label Apr 6, 2018

refack added the author ready PRs that have at least one approval, no pending requests for changes, and a CI started. label Apr 9, 2018

Trott mentioned this pull request Apr 9, 2018

CI failures with no output/stack trace #19903

Closed

BridgeAR removed the author ready PRs that have at least one approval, no pending requests for changes, and a CI started. label Apr 9, 2018

tools: include exit code in TAP log

0a797a9

refack force-pushed the add-error-code branch from 16daf50 to 0a797a9 Compare April 10, 2018 20:08

thefourtheye approved these changes Apr 11, 2018

View reviewed changes

Trott added the author ready PRs that have at least one approval, no pending requests for changes, and a CI started. label Apr 11, 2018

bnoordhuis approved these changes Apr 11, 2018

View reviewed changes

gibfahn approved these changes Apr 11, 2018

View reviewed changes

rvagg approved these changes Apr 12, 2018

View reviewed changes

Trott closed this Apr 12, 2018

refack mentioned this pull request Apr 25, 2018

tools: show stdout/stderr for timed out tests #20260

Closed

2 tasks

MylesBorins mentioned this pull request Aug 17, 2018

v8.12.0 proposal #21593

Merged

Trott deleted the add-error-code branch January 13, 2022 22:49

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

tools: include exit code in test failures #19855

tools: include exit code in test failures #19855

Trott commented Apr 6, 2018

refack commented Apr 6, 2018

refack commented Apr 6, 2018

rvagg Apr 6, 2018

refack Apr 6, 2018

rvagg Apr 6, 2018

BridgeAR Apr 8, 2018

refack Apr 8, 2018

refack Apr 8, 2018

refack Apr 8, 2018

thefourtheye Apr 9, 2018

refack Apr 9, 2018

Trott commented Apr 6, 2018

refack commented Apr 6, 2018

Trott commented Apr 6, 2018

refack commented Apr 6, 2018

Trott commented Apr 6, 2018

Trott commented Apr 9, 2018

refack commented Apr 9, 2018

refack commented Apr 9, 2018

Trott commented Apr 9, 2018

Trott commented Apr 9, 2018

Trott commented Apr 9, 2018 •

edited

Loading

refack commented Apr 9, 2018

BridgeAR commented Apr 9, 2018

BridgeAR commented Apr 9, 2018

Trott commented Apr 10, 2018

rvagg commented Apr 10, 2018

refack commented Apr 10, 2018

Trott commented Apr 11, 2018

Trott commented Apr 11, 2018

Trott commented Apr 11, 2018

Trott commented Apr 11, 2018

Trott commented Apr 12, 2018 •

edited

Loading

Trott commented Apr 12, 2018

tools: include exit code in test failures #19855

tools: include exit code in test failures #19855

Conversation

Trott commented Apr 6, 2018

Checklist

refack commented Apr 6, 2018

refack commented Apr 6, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Trott commented Apr 6, 2018

refack commented Apr 6, 2018

Trott commented Apr 6, 2018

refack commented Apr 6, 2018

Trott commented Apr 6, 2018

Trott commented Apr 9, 2018

refack commented Apr 9, 2018

refack commented Apr 9, 2018

Trott commented Apr 9, 2018

Trott commented Apr 9, 2018

Trott commented Apr 9, 2018 • edited Loading

refack commented Apr 9, 2018

BridgeAR commented Apr 9, 2018

BridgeAR commented Apr 9, 2018

Trott commented Apr 10, 2018

rvagg commented Apr 10, 2018

refack commented Apr 10, 2018

Trott commented Apr 11, 2018

Trott commented Apr 11, 2018

Trott commented Apr 11, 2018

Trott commented Apr 11, 2018

Trott commented Apr 12, 2018 • edited Loading

Trott commented Apr 12, 2018

Trott commented Apr 9, 2018 •

edited

Loading

Trott commented Apr 12, 2018 •

edited

Loading