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.

Sign up for GitHub

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

Jump to bottom

flaky: test-runner-output #52139

Closed
mhdawson opened this issue Mar 18, 2024 · 2 comments · Fixed by #52146
Closed

flaky: test-runner-output #52139

mhdawson opened this issue Mar 18, 2024 · 2 comments · Fixed by #52146
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI. macos Issues and PRs related to the macOS platform / OSX.

Comments

@mhdawson
Copy link
Member

Test

test-runner-output

Platform

macOS x64

Console output

Error Message
fail (1)
Stacktrace
---
duration_ms: 8745.582
exitcode: 1
severity: fail
...

Build links

Additional information

No response
@mhdawson mhdawson added the flaky-test Issues and PRs related to the tests with unstable failures on the CI. label Mar 18, 2024
@github-actions github-actions bot added the macos Issues and PRs related to the macOS platform / OSX. label Mar 18, 2024
@aduh95
Copy link
Contributor

aduh95 commented Mar 18, 2024

The actual output is

...
not ok 2409 parallel/test-runner-output
  ---
  duration_ms: 8745.58200
  severity: fail
  exitcode: 1
  stack: |-
    TAP version 13
    # Subtest: test runner output
        # Subtest: test-runner/output/abort.js
        ok 1 - test-runner/output/abort.js
          ---
          duration_ms: 2331.231606
          ...
        # Subtest: test-runner/output/abort_suite.js
        ok 2 - test-runner/output/abort_suite.js
          ---
          duration_ms: 2448.074803
          ...
        # Subtest: test-runner/output/abort_hooks.js
        ok 3 - test-runner/output/abort_hooks.js
          ---
          duration_ms: 2290.014996
          ...
        # Subtest: test-runner/output/describe_it.js
        ok 4 - test-runner/output/describe_it.js
          ---
          duration_ms: 3964.524905
          ...
        # Subtest: test-runner/output/describe_nested.js
        ok 5 - test-runner/output/describe_nested.js
          ---
          duration_ms: 2244.888429
          ...
        # Subtest: test-runner/output/eval_dot.js
        ok 6 - test-runner/output/eval_dot.js
          ---
          duration_ms: 2207.241466
          ...
        # Subtest: test-runner/output/eval_spec.js
        ok 7 - test-runner/output/eval_spec.js
          ---
          duration_ms: 2181.106077
          ...
        # Subtest: test-runner/output/eval_tap.js
        ok 8 - test-runner/output/eval_tap.js
          ---
          duration_ms: 1974.114745
          ...
        # Subtest: test-runner/output/hooks.js
        ok 9 - test-runner/output/hooks.js
          ---
          duration_ms: 4240.514089
          ...
        # Subtest: test-runner/output/hooks_spec_reporter.js
        ok 10 - test-runner/output/hooks_spec_reporter.js
          ---
          duration_ms: 5868.836485
          ...
        # Subtest: test-runner/output/timeout_in_before_each_should_not_affect_further_tests.js
        ok 11 - test-runner/output/timeout_in_before_each_should_not_affect_further_tests.js
          ---
          duration_ms: 2525.783007
          ...
        # Subtest: test-runner/output/hooks-with-no-global-test.js
        ok 12 - test-runner/output/hooks-with-no-global-test.js
          ---
          duration_ms: 2232.266074
          ...
        # Subtest: test-runner/output/global-hooks-with-no-tests.js
        ok 13 - test-runner/output/global-hooks-with-no-tests.js
          ---
          duration_ms: 2222.838485
          ...
        # Subtest: test-runner/output/before-and-after-each-too-many-listeners.js
        ok 14 - test-runner/output/before-and-after-each-too-many-listeners.js
          ---
          duration_ms: 2179.269254
          ...
        # Subtest: test-runner/output/before-and-after-each-with-timeout-too-many-listeners.js
        ok 15 - test-runner/output/before-and-after-each-with-timeout-too-many-listeners.js
          ---
          duration_ms: 2270.039281
          ...
        # Subtest: test-runner/output/force_exit.js
        ok 16 - test-runner/output/force_exit.js
          ---
          duration_ms: 1921.597563
          ...
        # Subtest: test-runner/output/global_after_should_fail_the_test.js
        ok 17 - test-runner/output/global_after_should_fail_the_test.js
          ---
          duration_ms: 1938.23092
          ...
        # Subtest: test-runner/output/no_refs.js
        ok 18 - test-runner/output/no_refs.js
          ---
          duration_ms: 2366.599986
          ...
        # Subtest: test-runner/output/no_tests.js
        ok 19 - test-runner/output/no_tests.js
          ---
          duration_ms: 1842.804127
          ...
        # Subtest: test-runner/output/only_tests.js
        ok 20 - test-runner/output/only_tests.js
          ---
          duration_ms: 3168.233906
          ...
        # Subtest: test-runner/output/dot_reporter.js
        not ok 21 - test-runner/output/dot_reporter.js
          ---
          duration_ms: 5473.050121
          location: '/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx11-x64/test/parallel/test-runner-output.mjs:149:5'
          failureType: 'testCodeFailure'
          error: |-
            Expected values to be strictly equal:
            + actual - expected
            
              '..XX...X..XXX.X.....\n' +
                'XXX.....X..X...X....\n' +
                '.....X...XXX.XX.....\n' +
            +   '.XXXXXX....XXXXX\n'
            -   '.XXXXXXX...XXXXX\n'
          code: 'ERR_ASSERTION'
          name: 'AssertionError'
          expected: |-
            ..XX...X..XXX.X.....
            XXX.....X..X...X....
            .....X...XXX.XX.....
            .XXXXXXX...XXXXX
            
          actual: |-
            ..XX...X..XXX.X.....
            XXX.....X..X...X....
            .....X...XXX.XX.....
            .XXXXXX....XXXXX
            
          operator: 'strictEqual'
          stack: |-
            assertSnapshot (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx11-x64/test/common/assertSnapshot.js:56:12)
            async Module.spawnAndAssert (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx11-x64/test/common/assertSnapshot.js:84:3)
            async TestContext.<anonymous> (file:///Users/iojs/build/workspace/node-test-commit-osx/nodes/osx11-x64/test/parallel/test-runner-output.mjs:143:5)
            async Test.run (node:internal/test_runner/test:703:9)
            async Promise.all (index 20)
            async Suite.run (node:internal/test_runner/test:1047:7)
            async Test.processPendingSubtests (node:internal/test_runner/test:439:7)
          ...
        # Subtest: test-runner/output/junit_reporter.js
        ok 22 - test-runner/output/junit_reporter.js
          ---
          duration_ms: 5615.539884
          ...
        # Subtest: test-runner/output/spec_reporter_successful.js
        ok 23 - test-runner/output/spec_reporter_successful.js
          ---
          duration_ms: 2247.617472
          ...
        # Subtest: test-runner/output/spec_reporter.js
        ok 24 - test-runner/output/spec_reporter.js
          ---
          duration_ms: 5618.560288
          ...
        # Subtest: test-runner/output/spec_reporter_cli.js
        ok 25 - test-runner/output/spec_reporter_cli.js
          ---
          duration_ms: 7138.063799
          ...
        # Subtest: test-runner/output/source_mapped_locations.mjs
        ok 26 - test-runner/output/source_mapped_locations.mjs
          ---
          duration_ms: 2024.6214
          ...
        # Subtest: test-runner/output/lcov_reporter.js
        ok 27 - test-runner/output/lcov_reporter.js
          ---
          duration_ms: 5902.875905
          ...
        # Subtest: test-runner/output/output.js
        ok 28 - test-runner/output/output.js
          ---
          duration_ms: 4296.632757
          ...
        # Subtest: test-runner/output/output_cli.js
        ok 29 - test-runner/output/output_cli.js
          ---
          duration_ms: 7189.615013
          ...
        # Subtest: test-runner/output/name_pattern.js
        ok 30 - test-runner/output/name_pattern.js
          ---
          duration_ms: 3546.251282
          ...
        # Subtest: test-runner/output/name_pattern_with_only.js
        ok 31 - test-runner/output/name_pattern_with_only.js
          ---
          duration_ms: 2474.793434
          ...
        # Subtest: test-runner/output/unfinished-suite-async-error.js
        ok 32 - test-runner/output/unfinished-suite-async-error.js
          ---
          duration_ms: 1978.521109
          ...
        # Subtest: test-runner/output/unresolved_promise.js
        ok 33 - test-runner/output/unresolved_promise.js
          ---
          duration_ms: 2290.614996
          ...
        # Subtest: test-runner/output/default_output.js
        ok 34 - test-runner/output/default_output.js
          ---
          duration_ms: 3106.341035
          ...
        # Subtest: test-runner/output/arbitrary-output.js
        ok 35 - test-runner/output/arbitrary-output.js
          ---
          duration_ms: 2192.128238
          ...
        # Subtest: test-runner/output/async-test-scheduling.mjs
        ok 36 - test-runner/output/async-test-scheduling.mjs
          ---
          duration_ms: 2766.491767
          ...
        # Subtest: test-runner/output/arbitrary-output-colored.js
        ok 37 - test-runner/output/arbitrary-output-colored.js
          ---
          duration_ms: 6898.695176
          ...
        # Subtest: test-runner/output/dot_output_custom_columns.js
        ok 38 - test-runner/output/dot_output_custom_columns.js
          ---
          duration_ms: 4532.009243
          ...
        # Subtest: test-runner/output/tap_escape.js
        ok 39 - test-runner/output/tap_escape.js
          ---
          duration_ms: 2273.249776
          ...
        # Subtest: test-runner/output/coverage_failure.js
        ok 40 - test-runner/output/coverage_failure.js
          ---
          duration_ms: 2993.119377
          ...
        1..40
    not ok 1 - test runner output
      ---
      duration_ms: 8282.290018
      type: 'suite'
      location: '/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx11-x64/test/parallel/test-runner-output.mjs:147:1'
      failureType: 'subtestsFailed'
      error: '1 subtest failed'
      code: 'ERR_TEST_FAILURE'
      ...
    1..1
    # tests 40
    # suites 1
    # pass 39
    # fail 1
    # cancelled 0
    # skipped 0
    # todo 0
    # duration_ms 8314.362079
  ...

cjihrig added a commit to cjihrig/node that referenced this issue Mar 18, 2024
@cjihrig
Revert "test_runner: abort unfinished tests on async error"
014500c 
This reverts commit 29b2317.

Fixes: nodejs#52139
@cjihrig cjihrig mentioned this issue Mar 18, 2024
Closed
@cjihrig
Copy link
Contributor

cjihrig commented Mar 18, 2024

#52140

@cjihrig cjihrig mentioned this issue Mar 18, 2024
Merged
cjihrig added a commit to cjihrig/node that referenced this issue Mar 18, 2024
@cjihrig
test: reduce flakiness of test-runner-output.mjs
21c7305 
This commit is similar to nodejs#51952. When the system is under load
it is possible for these timeout tests to become flaky. We
work around that by using a much longer setTimeout() in the test
so that it is not racing against the test's timeout. But, we have
to unref() such a large timeout. And, because test timeouts do
not currently keep the event loop alive, we use a different
setTimeout() for that purpose.

Fixes: nodejs#52139
Refs: nodejs#52140
@cjihrig cjihrig mentioned this issue Mar 18, 2024
Merged
nodejs-github-bot pushed a commit that referenced this issue Mar 19, 2024
@cjihrig
test: reduce flakiness of test-runner-output.mjs
978d5a2 
This commit is similar to #51952. When the system is under load
it is possible for these timeout tests to become flaky. We
work around that by using a much longer setTimeout() in the test
so that it is not racing against the test's timeout. But, we have
to unref() such a large timeout. And, because test timeouts do
not currently keep the event loop alive, we use a different
setTimeout() for that purpose.

Fixes: #52139
Refs: #52140
PR-URL: #52146
Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
rdw-msft pushed a commit to rdw-msft/node that referenced this issue Mar 26, 2024
@cjihrig @rdw-msft
test: reduce flakiness of test-runner-output.mjs
e9e6edc 
This commit is similar to nodejs#51952. When the system is under load
it is possible for these timeout tests to become flaky. We
work around that by using a much longer setTimeout() in the test
so that it is not racing against the test's timeout. But, we have
to unref() such a large timeout. And, because test timeouts do
not currently keep the event loop alive, we use a different
setTimeout() for that purpose.

Fixes: nodejs#52139
Refs: nodejs#52140
PR-URL: nodejs#52146
Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
marco-ippolito pushed a commit that referenced this issue May 2, 2024
@cjihrig @marco-ippolito
test: reduce flakiness of test-runner-output.mjs
3a75341 
This commit is similar to #51952. When the system is under load
it is possible for these timeout tests to become flaky. We
work around that by using a much longer setTimeout() in the test
so that it is not racing against the test's timeout. But, we have
to unref() such a large timeout. And, because test timeouts do
not currently keep the event loop alive, we use a different
setTimeout() for that purpose.

Fixes: #52139
Refs: #52140
PR-URL: #52146
Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
marco-ippolito pushed a commit that referenced this issue May 3, 2024
@cjihrig @marco-ippolito
test: reduce flakiness of test-runner-output.mjs
d7bfb4e 
This commit is similar to #51952. When the system is under load
it is possible for these timeout tests to become flaky. We
work around that by using a much longer setTimeout() in the test
so that it is not racing against the test's timeout. But, we have
to unref() such a large timeout. And, because test timeouts do
not currently keep the event loop alive, we use a different
setTimeout() for that purpose.

Fixes: #52139
Refs: #52140
PR-URL: #52146
Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
@aduh95 aduh95 mentioned this issue Oct 16, 2024
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI. macos Issues and PRs related to the macOS platform / OSX.
Projects
None yet
Milestone
No milestone
3 participants
@cjihrig @mhdawson @aduh95