Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

test: add error only reporter for node:test #52189

Open
wants to merge 3 commits into
base: main
Choose a base branch
from

Conversation

cjihrig
Copy link
Contributor

@cjihrig cjihrig commented Mar 22, 2024

Opening as a draft to determine if this is a desirable change.

This commit introduces a node:test reporter to the common utils. This reporter can be used to silence output other than errors from node:test. This is useful because in Node's own test suite, the output of node:test is included in the output of the Python test runner.

Refs: #49120

A comparison of output before and after this change is shown below. The TAP reporter is shown for the current output. The output is generated by ./tools/test.py test/parallel/test-runner-cli-concurrency.js with an artificial error introduced.

Before:

=== release test-runner-cli-concurrency ===                   
Path: parallel/test-runner-cli-concurrency
TAP version 13
# Subtest: default concurrency
ok 1 - default concurrency
  ---
  duration_ms: 74.002459
  ...
# Subtest: concurrency of one
ok 2 - concurrency of one
  ---
  duration_ms: 190.883208
  ...
# Subtest: concurrency of two
not ok 3 - concurrency of two
  ---
  duration_ms: 125.033667
  location: '/redacted/test/parallel/test-runner-cli-concurrency.js:23:1'
  failureType: 'testCodeFailure'
  error: 'bye'
  code: 'ERR_TEST_FAILURE'
  stack: |-
    TestContext.<anonymous> (/redacted/test/parallel/test-runner-cli-concurrency.js:27:9)
    Test.runInAsyncScope (node:async_hooks:206:9)
    Test.run (node:internal/test_runner/test:702:25)
    Test.processPendingSubtests (node:internal/test_runner/test:439:18)
    Test.postRun (node:internal/test_runner/test:807:19)
    Test.run (node:internal/test_runner/test:751:12)
    async Test.processPendingSubtests (node:internal/test_runner/test:439:7)
  ...
1..3
# tests 3
# suites 0
# pass 2
# fail 1
# cancelled 0
# skipped 0
# todo 0
# duration_ms 396.478041

After:

=== release test-runner-cli-concurrency ===                   
Path: parallel/test-runner-cli-concurrency
Test failure: 'concurrency of two'
Location: test/parallel/test-runner-cli-concurrency.js:23:1
Error: bye
    at TestContext.<anonymous> (/redacted/test/parallel/test-runner-cli-concurrency.js:27:9)
    at Test.runInAsyncScope (node:async_hooks:206:9)
    at Test.run (node:internal/test_runner/test:702:25)
    at Test.processPendingSubtests (node:internal/test_runner/test:439:18)
    at Test.postRun (node:internal/test_runner/test:807:19)
    at Test.run (node:internal/test_runner/test:751:12)
    at async Test.processPendingSubtests (node:internal/test_runner/test:439:7)

@nodejs-github-bot
Copy link
Collaborator

Review requested:

  • @nodejs/test_runner

@nodejs-github-bot nodejs-github-bot added needs-ci PRs that need a full CI run. test Issues and PRs related to the tests. labels Mar 22, 2024
@aduh95
Copy link
Contributor

aduh95 commented Mar 22, 2024

If you push the artificial error to your branch, we could try running a node-stress-single-test CI with a single run to validate how Jenkins would parse the test failure.

@cjihrig
Copy link
Contributor Author

cjihrig commented Mar 22, 2024

@aduh95 pushed

@aduh95
Copy link
Contributor

aduh95 commented Mar 22, 2024

@aduh95
Copy link
Contributor

aduh95 commented Mar 22, 2024

Unfortunately, the Jenkins output is still not great and doesn't show the actual failure: https://ci.nodejs.org/job/node-stress-single-test/479/nodes=rhel8-x64/testReport/junit/(root)/parallel/test_runner_cli_concurrency/

EDIT: see comments below, that's not actually related to node:test, wrong assumption on my end.

@cjihrig
Copy link
Contributor Author

cjihrig commented Mar 22, 2024

Interesting. Do you know how that is rendered.

I was targeting the output in https://ci.nodejs.org/job/node-stress-single-test/479/nodes=rhel8-x64/console, which does look much better. But it would be nice to fix https://ci.nodejs.org/job/node-stress-single-test/479/nodes=rhel8-x64/testReport/junit/(root)/parallel/test_runner_cli_concurrency/.

@aduh95
Copy link
Contributor

aduh95 commented Mar 22, 2024

It looks like Jenkins cuts the "stacktrace" when it encounters stack: |- – maybe because it thinks it's a substack? I honestly don't know, I can try to look around if they have any documentation around that behavior.
I think we're using JUnit plugin, but it's unclear how it actually parses the test output.

@cjihrig
Copy link
Contributor Author

cjihrig commented Mar 22, 2024

Is this just a general problem not related to the use of node:test? Looking at https://ci.nodejs.org/job/node-test-commit-linux-containered/42211/#showFailuresLink, I see 9 failures, and I don't think any of those tests use node:test. All of them look like this:

fail (1)

---
duration_ms: 815.156
exitcode: 1
severity: fail
...

EDIT: This seems to be related to tap2junit I think.

@richardlau
Copy link
Member

richardlau commented Mar 23, 2024

Unfortunately, the Jenkins output is still not great and doesn't show the actual failure: https://ci.nodejs.org/job/node-stress-single-test/479/nodes=rhel8-x64/testReport/junit/(root)/parallel/test_runner_cli_concurrency/

I think that's a tap2junit issue? Those Jenkins pages used to have the failure output in the "Stacktrace" box.

Copy link
Member

@atlowChemi atlowChemi left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Overall LGTM, I think this would be a nice addition

Comment on lines +22 to +32
const output = [
`Test failure: '${name}'`,
];

if (file) {
output.push(`Location: ${relative(cwd, file)}:${line}:${column}`);
}

output.push(inspect(error));
output.push('\n');
yield output.join('\n');
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why not yield the values directly, instead of having the output value?

@cjihrig
Copy link
Contributor Author

cjihrig commented Apr 11, 2024

Now that nodejs/tap2junit#54 has landed, what are the next steps to seeing it working in Jenkins?

@MoLow
Copy link
Member

MoLow commented Apr 11, 2024

it needs to be released and the updated in all the ci machines CC @nodejs/build @cclauss

@MoLow
Copy link
Member

MoLow commented Jun 17, 2024

@cjihrig nodejs/build#3761 is now deployed. should this PR be closed?

@cjihrig
Copy link
Contributor Author

cjihrig commented Jun 18, 2024

Unsure. That PR was blocking me from evaluating this PR in the CI to see if it could be beneficial.

@cjihrig
Copy link
Contributor Author

cjihrig commented Jun 19, 2024

So this still doesn't seem to work with the view in https://ci.nodejs.org/job/node-stress-single-test/514/nodes=rhel8-x64/testReport/junit/(root)/parallel/test_runner_cli_concurrency/, and I don't know what needs to happen to appease tap2junit (both with and without the change in this PR).

The console output (shown in the OP) is still significantly better IMO.

@cclauss cclauss requested a review from legendecas June 19, 2024 11:27
@cjihrig cjihrig closed this Jun 20, 2024
@cjihrig cjihrig deleted the test-reporter branch June 20, 2024 03:21
@cjihrig cjihrig restored the test-reporter branch December 18, 2024 20:09
@cjihrig cjihrig reopened this Dec 18, 2024
This commit introduces a node:test reporter to the common utils.
This reporter can be used to silence output other than errors
from node:test. This is useful because in Node's own test suite,
the output of node:test is included in the output of the
Python test runner.

Refs: nodejs#49120
@cjihrig cjihrig marked this pull request as ready for review December 18, 2024 20:23
@cjihrig
Copy link
Contributor Author

cjihrig commented Dec 18, 2024

@MoLow I'm interested in replacing the spec reporter with the less verbose one from this PR inside of GitHub Actions runs. However, it looks like the GitHub reporter is also sending output to stdout:

::debug::starting to run default concurrency
::debug::completed running default concurrency
::debug::starting to run concurrency of one
::debug::completed running concurrency of one
::debug::starting to run concurrency of two
::error title=concurrency of two,file=test/parallel/test-runner-cli-concurrency.js,line=26,col=9::[Error [ERR_TEST_FAILURE]: bye] {
  code: 'ERR_TEST_FAILURE',
  failureType: 'testCodeFailure',
  cause: Error: bye
      at TestContext.<anonymous> (/home/runner/work/node/node/test/parallel/test-runner-cli-concurrency.js:26:9)
      at Test.runInAsyncScope (node:async_hooks:211:14)
      at Test.run (node:internal/test_runner/test:931:25)
      at Test.processPendingSubtests (node:internal/test_runner/test:629:18)
      at Test.postRun (node:internal/test_runner/test:1042:19)
      at Test.run (node:internal/test_runner/test:970:12)
      at async Test.processPendingSubtests (node:internal/test_runner/test:629:7)
}

Is it possible to leverage the GitHub reporter for its annotations without it also logging things?

Copy link

codecov bot commented Dec 18, 2024

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 88.54%. Comparing base (0d00511) to head (5dc2c0a).
Report is 1 commits behind head on main.

Additional details and impacted files
@@            Coverage Diff             @@
##             main   #52189      +/-   ##
==========================================
+ Coverage   88.04%   88.54%   +0.50%     
==========================================
  Files         657      657              
  Lines      190290   190290              
  Branches    36245    36540     +295     
==========================================
+ Hits       167536   168488     +952     
+ Misses      15893    14971     -922     
+ Partials     6861     6831      -30     

see 89 files with indirect coverage changes

@cjihrig
Copy link
Contributor Author

cjihrig commented Dec 18, 2024

Sigh. It looks like the GitHub Actions toolkit writes directly to process.stdout, and I don't think there is a way to avoid that. actions/toolkit#1743 appears to be trying to do exactly what I'd like to do.

@cjihrig
Copy link
Contributor Author

cjihrig commented Dec 22, 2024

@JakobJingleheimer this might be something of interest to you.

@JakobJingleheimer
Copy link
Member

Awesome, this is a great idea! Do you need/want help finishing it?

@cjihrig
Copy link
Contributor Author

cjihrig commented Dec 24, 2024

Help would definitely be welcomed. There are a few things left:

  1. Figure out exactly what output everyone wants. I think this might be close since it only outputs failures with the test title and location.
  2. Figure out if we want to drop the GitHub reporter. As I mentioned in test: add error only reporter for node:test #52189 (comment), it seems to create a lot of noise on stdout, which would go against the idea of only showing failure output. My personal opinion is that we can remove it even though the annotations are kind of neat.
  3. It might be worth adding a fail fast feature to this reporter (which basically just exits the process when a test:fail event is encountered). Maybe this could be configured via an environment variable or something so that people who want that behavior can opt into it.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
needs-ci PRs that need a full CI run. test Issues and PRs related to the tests.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

7 participants