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

Investigate flaky test-runner-cli #43618

Closed
F3n67u opened this issue Jun 29, 2022 · 2 comments · Fixed by #43666
Closed

Investigate flaky test-runner-cli #43618

F3n67u opened this issue Jun 29, 2022 · 2 comments · Fixed by #43666
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI. test_runner Issues and PRs related to the test runner subsystem.

Comments

@F3n67u
Copy link
Member

F3n67u commented Jun 29, 2022 •
edited
Loading

Test

test-runner-cli

Platform

macos

Console output

node:assert:1027
    throw err;
    ^

AssertionError [ERR_ASSERTION]: The input did not match the regular expression /not ok 1 - this should fail/. Input:

'TAP version 13\n' +
  '# Subtest: /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/index.js\n' +
  'not ok 1 - /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/index.js\n' +
  '  ---\n' +
  '  duration_ms: 0.065594886\n' +
  "  failureType: 'subtestsFailed'\n" +
  '  exitCode: 1\n' +
  "  stdout: ''\n" +
  '  stderr: |-\n' +
  '    /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/index.js:2\n' +
  "    throw new Error('thrown from index.js');\n" +
  '    ^\n' +
  '    \n' +
  '    Error: thrown from index.js\n' +
  '        at Object.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/index.js:2:7)\n' +
  '        at Module._compile (node:internal/modules/cjs/loader:1114:14)\n' +
  '        at Module._extensions..js (node:internal/modules/cjs/loader:1168:10)\n' +
  '        at Module.load (node:internal/modules/cjs/loader:992:32)\n' +
  '        at Module._load (node:internal/modules/cjs/loader:832:12)\n' +
  '        at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:81:12)\n' +
  '        at node:internal/main/run_main_module:17:47\n' +
  '    \n' +
  '    Node.js v19.0.0-pre\n' +
  '    \n' +
  "  error: 'test failed'\n" +
  "  code: 'ERR_TEST_FAILURE'\n" +
  '  ...\n' +
  '# Subtest: /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/index.test.js\n' +
  'ok 2 - /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/index.test.js\n' +
  '  ---\n' +
  '  duration_ms: 0.110061674\n' +
  '  ...\n' +
  '# Subtest: /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/random.test.mjs\n' +
  'not ok 3 - /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/random.test.mjs\n' +
  '  ---\n' +
  '  duration_ms: 0.072654973\n' +
  "  failureType: 'subtestsFailed'\n" +
  '  exitCode: 1\n' +
  "  stdout: ''\n" +
  "  stderr: ''\n" +
  "  error: 'test failed'\n" +
  "  code: 'ERR_TEST_FAILURE'\n" +
  '  ...\n' +
  '# Subtest: /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/subdir/subdir_test.js\n' +
  'ok 4 - /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/subdir/subdir_test.js\n' +
  '  ---\n' +
  '  duration_ms: 0.083164097\n' +
  '  ...\n' +
  '# Subtest: /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/test/random.cjs\n' +
  'ok 5 - /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/test/random.cjs\n' +
  '  ---\n' +
  '  duration_ms: 0.065502184\n' +
  '  ...\n' +
  '1..5\n' +
  '# tests 5\n' +
  '# pass 3\n' +
  '# fail 2\n' +
  '# skipped 0\n' +
  '# todo 0\n' +
  '# duration_ms 0.242462392\n'

    at Object.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/parallel/test-runner-cli.js:49:10)
    at Module._compile (node:internal/modules/cjs/loader:1114:14)
    at Module._extensions..js (node:internal/modules/cjs/loader:1168:10)
    at Module.load (node:internal/modules/cjs/loader:992:32)
    at Module._load (node:internal/modules/cjs/loader:832:12)
    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:81:12)
    at node:internal/main/run_main_module:17:47 {
  generatedMessage: true,
  code: 'ERR_ASSERTION',
  actual: 'TAP version 13\n' +
    '# Subtest: /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/index.js\n' +
    'not ok 1 - /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/index.js\n' +
    '  ---\n' +
    '  duration_ms: 0.065594886\n' +
    "  failureType: 'subtestsFailed'\n" +
    '  exitCode: 1\n' +
    "  stdout: ''\n" +
    '  stderr: |-\n' +
    '    /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/index.js:2\n' +
    "    throw new Error('thrown from index.js');\n" +
    '    ^\n' +
    '    \n' +
    '    Error: thrown from index.js\n' +
    '        at Object.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/index.js:2:7)\n' +
    '        at Module._compile (node:internal/modules/cjs/loader:1114:14)\n' +
    '        at Module._extensions..js (node:internal/modules/cjs/loader:1168:10)\n' +
    '        at Module.load (node:internal/modules/cjs/loader:992:32)\n' +
    '        at Module._load (node:internal/modules/cjs/loader:832:12)\n' +
    '        at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:81:12)\n' +
    '        at node:internal/main/run_main_module:17:47\n' +
    '    \n' +
    '    Node.js v19.0.0-pre\n' +
    '    \n' +
    "  error: 'test failed'\n" +
    "  code: 'ERR_TEST_FAILURE'\n" +
    '  ...\n' +
    '# Subtest: /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/index.test.js\n' +
    'ok 2 - /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/index.test.js\n' +
    '  ---\n' +
    '  duration_ms: 0.110061674\n' +
    '  ...\n' +
    '# Subtest: /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/random.test.mjs\n' +
    'not ok 3 - /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/random.test.mjs\n' +
    '  ---\n' +
    '  duration_ms: 0.072654973\n' +
    "  failureType: 'subtestsFailed'\n" +
    '  exitCode: 1\n' +
    "  stdout: ''\n" +
    "  stderr: ''\n" +
    "  error: 'test failed'\n" +
    "  code: 'ERR_TEST_FAILURE'\n" +
    '  ...\n' +
    '# Subtest: /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/subdir/subdir_test.js\n' +
    'ok 4 - /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/subdir/subdir_test.js\n' +
    '  ---\n' +
    '  duration_ms: 0.083164097\n' +
    '  ...\n' +
    '# Subtest: /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/test/random.cjs\n' +
    'ok 5 - /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/test/random.cjs\n' +
    '  ---\n' +
    '  duration_ms: 0.065502184\n' +
    '  ...\n' +
    '1..5\n' +
    '# tests 5\n' +
    '# pass 3\n' +
    '# fail 2\n' +
    '# skipped 0\n' +
    '# todo 0\n' +
    '# duration_ms 0.242462392\n',
  expected: /not ok 1 - this should fail/,
  operator: 'match'
}

Node.js v19.0.0-pre

Build links

https://ci.nodejs.org/job/node-test-commit-osx/45870/nodes=osx1015/testReport/junit/(root)/test/parallel_test_runner_cli/

Additional information

I cannot reproduce this flaky problem on my Mac with repeat 1000 ./node test/parallel/test-runner-cli.js

cc @nodejs/test_runner
@F3n67u F3n67u added flaky-test Issues and PRs related to the tests with unstable failures on the CI. test_runner Issues and PRs related to the test runner subsystem. labels Jun 29, 2022
@F3n67u
Copy link
Member Author

F3n67u commented Jun 29, 2022 •
edited
Loading

Related test:

node/test/parallel/test-runner-cli.js

Lines 37 to 51 in ed1e9ae

{
// User specified files that don't match the pattern are still run.
const args = ['--test', testFixtures, join(testFixtures, 'index.js')];
const child = spawnSync(process.execPath, args);
assert.strictEqual(child.status, 1);
assert.strictEqual(child.signal, null);
assert.strictEqual(child.stderr.toString(), '');
const stdout = child.stdout.toString();
assert.match(stdout, /not ok 1 - .+index\.js/);
assert.match(stdout, /ok 2 - .+index\.test\.js/);
assert.match(stdout, /not ok 3 - .+random\.test\.mjs/);
assert.match(stdout, /not ok 1 - this should fail/);
assert.match(stdout, /ok 4 - .+subdir.+subdir_test\.js/);
}

When running test/fixtures/test-runner/random.test.mjs, the stdout and stderr is empty. So the test fails, it expects stdout to have not ok 1 - this should fail message.

Actual

    'not ok 3 - /Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/fixtures/test-runner/random.test.mjs\n' +
    '  ---\n' +
    '  duration_ms: 0.072654973\n' +
    "  failureType: 'subtestsFailed'\n" +
    '  exitCode: 1\n' +
    "  stdout: ''\n" +
    "  stderr: ''\n" +
    "  error: 'test failed'\n" +
    "  code: 'ERR_TEST_FAILURE'\n" +
    '  ...\n' +

Expected

not ok 3 - /Users/bytedance/Projects/node/test/fixtures/test-runner/random.test.mjs
  ---
  duration_ms: 0.153871203
  failureType: 'subtestsFailed'
  exitCode: 1
  stdout: |-
    TAP version 13
    not ok 1 - this should fail
      ---
      duration_ms: 0.000535456
      failureType: 'testCodeFailure'
      error: 'this is a failing test'
      code: 'ERR_TEST_FAILURE'
      stack: |-
        TestContext.<anonymous> (file:///Users/bytedance/Projects/node/test/fixtures/test-runner/random.test.mjs:4:9)
        Test.runInAsyncScope (node:async_hooks:202:9)
        Test.run (node:internal/test_runner/test:340:20)
        Test.start (node:internal/test_runner/test:292:17)
        Test.test (node:internal/test_runner/harness:126:18)
        file:///Users/bytedance/Projects/node/test/fixtures/test-runner/random.test.mjs:3:1
        ModuleJob.run (node:internal/modules/esm/module_job:197:25)
        async Promise.all (index 0)
        async ESMLoader.import (node:internal/modules/esm/loader:527:24)
        async loadESM (node:internal/process/esm_loader:83:5)
      ...
    1..1
    # tests 1
    # pass 0
    # fail 1
    # skipped 0
    # todo 0
    # duration_ms 0.116038223
    
  stderr: |-
    (node:19382) ExperimentalWarning: The test runner is an experimental feature. This feature could change at any time
    (Use `node --trace-warnings ...` to show where the warning was created)
    
  error: 'test failed'
  code: 'ERR_TEST_FAILURE'
  ...

@MoLow
Copy link
Member

MoLow commented Jun 29, 2022

IL try taking a look

@MoLow MoLow mentioned this issue Jul 3, 2022
Merged
@MoLow MoLow mentioned this issue Jul 25, 2022
Merged
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. test_runner Issues and PRs related to the test runner subsystem.
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

test_runner: wait for stderr and stdout to complete MoLow/node
2 participants
@MoLow @F3n67u