Skip to content

Investigate flaky test-worker-init-failure #33759

Closed
#34727
Closed
Investigate flaky test-worker-init-failure#33759
#34727
Labels
flaky-testIssues and PRs involving tests that fail intermittently in CI.macosIssues and PRs related to the macOS platform.

Description

@Trott
Trott
opened on Jun 5, 2020
  • Test: test-worker-init-failure
  • Platform: macOS
  • Console Output:
2020-06-05T18:48:01.6873370Z === release test-worker-init-failure ===
2020-06-05T18:48:01.6873870Z Path: parallel/test-worker-init-failure
2020-06-05T18:48:01.6874340Z --- stderr ---
2020-06-05T18:48:01.6874460Z assert.js:103
2020-06-05T18:48:01.6874620Z   throw new AssertionError(obj);
2020-06-05T18:48:01.6874720Z   ^
2020-06-05T18:48:01.6874780Z 
2020-06-05T18:48:01.6874950Z AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
2020-06-05T18:48:01.6875030Z 
2020-06-05T18:48:01.6875120Z 1 !== 0
2020-06-05T18:48:01.6875180Z 
2020-06-05T18:48:01.6875770Z     at ChildProcess.<anonymous> (/Users/runner/runners/2.263.0/work/node/node/test/parallel/test-worker-init-failure.js:64:12)
2020-06-05T18:48:01.6875930Z     at ChildProcess.<anonymous> (/Users/runner/runners/2.263.0/work/node/node/test/common/index.js:363:15)
2020-06-05T18:48:01.6876700Z     at ChildProcess.emit (events.js:315:20)
2020-06-05T18:48:01.6876820Z     at Process.ChildProcess._handle.onexit (internal/child_process.js:276:12) {
2020-06-05T18:48:01.6876940Z   generatedMessage: true,
2020-06-05T18:48:01.6877410Z   code: 'ERR_ASSERTION',
2020-06-05T18:48:01.6877530Z   actual: 1,
2020-06-05T18:48:01.6877630Z   expected: 0,
2020-06-05T18:48:01.6878040Z   operator: 'strictEqual'
2020-06-05T18:48:01.6878160Z }
2020-06-05T18:48:01.6878550Z --- stdout ---
2020-06-05T18:48:01.6878650Z child stdout: 
2020-06-05T18:48:01.6878710Z 
2020-06-05T18:48:01.6878810Z child stderr: assert.js:920
2020-06-05T18:48:01.6878910Z     throw err;
2020-06-05T18:48:01.6879000Z     ^
2020-06-05T18:48:01.6879060Z 
2020-06-05T18:48:01.6879170Z AssertionError [ERR_ASSERTION]: The input did not match the regular expression /EMFILE/. Input:
2020-06-05T18:48:01.6879230Z 
2020-06-05T18:48:01.6879660Z 'ENOENT: no such file or directory, uv_cwd'
2020-06-05T18:48:01.6879740Z 
2020-06-05T18:48:01.6880250Z     at Worker.<anonymous> (/Users/runner/runners/2.263.0/work/node/node/test/parallel/test-worker-init-failure.js:38:14)
2020-06-05T18:48:01.6880380Z     at Worker.emit (events.js:315:20)
2020-06-05T18:48:01.6880820Z     at Worker.[kOnErrorMessage] (internal/worker.js:235:10)
2020-06-05T18:48:01.6880990Z     at Worker.[kOnMessage] (internal/worker.js:245:37)
2020-06-05T18:48:01.6881140Z     at MessagePort.<anonymous> (internal/worker.js:166:57)
2020-06-05T18:48:01.6881260Z     at MessagePort.emit (events.js:315:20)
2020-06-05T18:48:01.6881460Z     at MessagePort.onmessage (internal/worker/io.js:80:8)
2020-06-05T18:48:01.6881580Z     at MessagePort.exports.emitMessage (internal/per_context/messageport.js:11:10)
2020-06-05T18:48:01.6881700Z     at Worker.[kOnExit] (internal/worker.js:217:5)
2020-06-05T18:48:01.6881810Z     at Worker.<computed>.onexit (internal/worker.js:163:20) {
2020-06-05T18:48:01.6881920Z   generatedMessage: true,
2020-06-05T18:48:01.6882380Z   code: 'ERR_ASSERTION',
2020-06-05T18:48:01.6882840Z   actual: 'ENOENT: no such file or directory, uv_cwd',
2020-06-05T18:48:01.6882960Z   expected: /EMFILE/,
2020-06-05T18:48:01.6883350Z   operator: 'match'
2020-06-05T18:48:01.6883460Z }
2020-06-05T18:48:01.6883950Z Command: out/Release/node /Users/runner/runners/2.263.0/work/node/node/test/parallel/test-worker-init-failure.js
2020-06-05T18:48:01.6884040Z

Activity

  1. Trott
    added
    flaky-testIssues and PRs involving tests that fail intermittently in CI.
    on Jun 5, 2020

  2. MylesBorins commented on Jul 14, 2020

    @MylesBorins
    MylesBorins
    on Jul 14, 2020
    Contributor

    Seeing this flake a bunch locally while preparing a 14.x release

  3. Trott commented on Jul 15, 2020

    @Trott
    Trott
    on Jul 15, 2020
    MemberAuthor

    Happened in node-daily-master today.

    https://ci.nodejs.org/job/node-test-commit-osx/35263/nodes=osx1015/console

    00:25:58 not ok 2457 parallel/test-worker-init-failure
00:25:58   ---
00:25:58   duration_ms: 3.821
00:25:58   severity: fail
00:25:58   exitcode: 1
00:25:58   stack: |-
00:25:58     child stdout: 
00:25:58     
00:25:58     child stderr: assert.js:920
00:25:58         throw err;
00:25:58         ^
00:25:58     
00:25:58     AssertionError [ERR_ASSERTION]: The input did not match the regular expression /EMFILE/. Input:
00:25:58     
00:25:58     'ENOENT: no such file or directory, uv_cwd'
00:25:58     
00:25:58         at Worker.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/parallel/test-worker-init-failure.js:38:14)
00:25:58         at Worker.emit (events.js:314:20)
00:25:58         at Worker.[kOnErrorMessage] (internal/worker.js:238:10)
00:25:58         at Worker.[kOnMessage] (internal/worker.js:248:37)
00:25:58         at MessagePort.<anonymous> (internal/worker.js:167:57)
00:25:58         at MessagePort.emit (events.js:314:20)
00:25:58         at MessagePort.onmessage (internal/worker/io.js:80:8)
00:25:58         at MessagePort.exports.emitMessage (internal/per_context/messageport.js:11:10)
00:25:58         at Worker.[kOnExit] (internal/worker.js:220:5)
00:25:58         at Worker.<computed>.onexit (internal/worker.js:164:20) {
00:25:58       generatedMessage: true,
00:25:58       code: 'ERR_ASSERTION',
00:25:58       actual: 'ENOENT: no such file or directory, uv_cwd',
00:25:58       expected: /EMFILE/,
00:25:58       operator: 'match'
00:25:58     }
00:25:58     
00:25:58     
00:25:58     assert.js:103
00:25:58       throw new AssertionError(obj);
00:25:58       ^
00:25:58     
00:25:58     AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
00:25:58     
00:25:58     1 !== 0
00:25:58     
00:25:58         at ChildProcess.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/parallel/test-worker-init-failure.js:64:12)
00:25:58         at ChildProcess.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/common/index.js:365:15)
00:25:58         at ChildProcess.emit (events.js:314:20)
00:25:58         at Process.ChildProcess._handle.onexit (internal/child_process.js:276:12) {
00:25:58       generatedMessage: true,
00:25:58       code: 'ERR_ASSERTION',
00:25:58       actual: 1,
00:25:58       expected: 0,
00:25:58       operator: 'strictEqual'
00:25:58     }
00:25:58   ...

  4. Trott commented on Jul 15, 2020

    @Trott
    Trott
    on Jul 15, 2020
    MemberAuthor

    cc @nodejs/workers @HarshithaKP

  5. addaleax
    added
    macosIssues and PRs related to the macOS platform.
    on Jul 15, 2020

  6. addaleax commented on Jul 15, 2020

    @addaleax
    addaleax
    on Jul 15, 2020
    Member

    I think this might be specific to macOS. If somebody can reproduce locally, I’m up for a joint debugging session.

  7. HarshithaKP commented on Jul 15, 2020

    @HarshithaKP
    HarshithaKP
    on Jul 15, 2020
    Member

    I will try to reproduce it.

  8. MylesBorins commented on Jul 16, 2020

    @MylesBorins
    MylesBorins
    on Jul 16, 2020
    Contributor

    @addaleax I can reproduce this somewhat reliably if you want to pair.

  9. Trott commented on Jul 16, 2020

    @Trott
    Trott
    on Jul 16, 2020
    MemberAuthor

    Showed up in node-daily-master again today.

    https://ci.nodejs.org/job/node-test-commit-osx/35280/nodes=osx1015/console

    Details 
    01:33:40 not ok 2460 parallel/test-worker-init-failure
01:33:40   ---
01:33:40   duration_ms: 3.787
01:33:40   severity: fail
01:33:40   exitcode: 1
01:33:40   stack: |-
01:33:40     child stdout: 
01:33:40     
01:33:40     child stderr: assert.js:920
01:33:40         throw err;
01:33:40         ^
01:33:40     
01:33:40     AssertionError [ERR_ASSERTION]: The input did not match the regular expression /EMFILE/. Input:
01:33:40     
01:33:40     'ENOENT: no such file or directory, uv_cwd'
01:33:40     
01:33:40         at Worker.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/parallel/test-worker-init-failure.js:38:14)
01:33:40         at Worker.emit (events.js:314:20)
01:33:40         at Worker.[kOnErrorMessage] (internal/worker.js:238:10)
01:33:40         at Worker.[kOnMessage] (internal/worker.js:248:37)
01:33:40         at MessagePort.<anonymous> (internal/worker.js:167:57)
01:33:40         at MessagePort.emit (events.js:314:20)
01:33:40         at MessagePort.onmessage (internal/worker/io.js:80:8)
01:33:40         at MessagePort.exports.emitMessage (internal/per_context/messageport.js:11:10)
01:33:40         at Worker.[kOnExit] (internal/worker.js:220:5)
01:33:40         at Worker.<computed>.onexit (internal/worker.js:164:20) {
01:33:40       generatedMessage: true,
01:33:40       code: 'ERR_ASSERTION',
01:33:40       actual: 'ENOENT: no such file or directory, uv_cwd',
01:33:40       expected: /EMFILE/,
01:33:40       operator: 'match'
01:33:40     }
01:33:40     
01:33:40     
01:33:40     assert.js:103
01:33:40       throw new AssertionError(obj);
01:33:40       ^
01:33:40     
01:33:40     AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
01:33:40     
01:33:40     1 !== 0
01:33:40     
01:33:40         at ChildProcess.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/parallel/test-worker-init-failure.js:64:12)
01:33:40         at ChildProcess.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/common/index.js:365:15)
01:33:40         at ChildProcess.emit (events.js:314:20)
01:33:40         at Process.ChildProcess._handle.onexit (internal/child_process.js:276:12) {
01:33:40       generatedMessage: true,
01:33:40       code: 'ERR_ASSERTION',
01:33:40       actual: 1,
01:33:40       expected: 0,
01:33:40       operator: 'strictEqual'
01:33:40     }
01:33:40   ...

  10. gireeshpunathil commented on Jul 17, 2020

    @gireeshpunathil
    gireeshpunathil
    on Jul 17, 2020
    Member

    node/test/parallel/test-worker-init-failure.js

    Lines 37 to 40 in bf0d82c

    worker.on('error', (e) => {
    assert.match(e.message, /EMFILE/);
    assert.ok(e.code === 'ERR_WORKER_INIT_FAILED' || e.code === 'EMFILE');
    });

    I think the assumption that only EMFILE (too many open files) can occur in a ulimit -n setting is incorrect. Depending on where (early phase of process creation and setup versus runtime of the process) the inability to open new files occurs, the actual error code my differ.

    • I don't know what control flow triggered ENOENT
    • I don't know how many such places and errors exist

    Accommodating this error code too in the assertion seems to a pragmatic approach?

  11. Trott commented on Jul 17, 2020

    @Trott
    Trott
    on Jul 17, 2020
    MemberAuthor

    Accommodating this error code too in the assertion seems to a pragmatic approach?

    Accommodating a helpful ENOENT error message would indeed be pragmatic. Does 'ENOENT: no such file or directory, uv_cwd' qualify as sufficiently useful to the end user? uv_cwd is internal. It seems like the message is less than ideal. The test has this comment:

    // Test that workers fail with meaningful error message
// when their initialization fails.

    I'm conflicted about whether the right thing to do is to accommodate this error message or if the right thing to do is to try to improve it somehow.

  12. gireeshpunathil commented on Jul 17, 2020

    @gireeshpunathil
    gireeshpunathil
    on Jul 17, 2020
    Member

    @Trott - agree, makes sense!

    I think part of it has also to do with a limitation in libuv: it does not tell which file was missing. We had discussions on that in a different issue, but there wasn't any solution.

  13. gireeshpunathil commented on Jul 17, 2020

    @gireeshpunathil
    gireeshpunathil
    on Jul 17, 2020
    Member

    Ref: #11520

  14. addaleax commented on Jul 17, 2020

    @addaleax
    addaleax
    on Jul 17, 2020
    Member

    I would suggest that it’s worth figuring out why libuv is failing with this error, particularly because it’s OS-dependent.

    @MylesBorins I’m available most of next week, maybe we can find some time then :)

  15. MylesBorins commented on Jul 17, 2020

    @MylesBorins
    MylesBorins
    on Jul 17, 2020
    Contributor

    @addaleax next week is tough for me due to TC39. Ping me on chat and maybe we can work something out

  16. 5 remaining items

  17. addaleax commented on Jul 26, 2020

    @addaleax
    addaleax
    on Jul 26, 2020
    Member

    Yeah, that makes sense – I think it would be nice to wrap the process.argv[1] = path.resolve(process.argv[1]); line in a try ... catch, we can’t expect it to succeed in all cases anyway.

  18. gireeshpunathil
    closed this as completedin 4692e28on Jul 30, 2020
  19. codebytere
    added a commit that references this issue on Aug 5, 2020

    lib: absorb `path` error cases

    335cb0d

  20. Trott commented on Aug 11, 2020

    @Trott
    Trott
    on Aug 11, 2020
    MemberAuthor

    Still failing on CI on macOS.

    https://ci.nodejs.org/job/node-test-commit-osx/35686/nodes=osx1015/console

    01:05:25 not ok 2470 parallel/test-worker-init-failure
01:05:25   ---
01:05:25   duration_ms: 2.550
01:05:25   severity: fail
01:05:25   exitcode: 1
01:05:25   stack: |-
01:05:25     child stdout: 
01:05:25     
01:05:25     child stderr: events.js:291
01:05:25           throw er; // Unhandled 'error' event
01:05:25           ^
01:05:25     
01:05:25     AssertionError [ERR_ASSERTION]: The input did not match the regular expression /EMFILE/. Input:
01:05:25     
01:05:25     'ENOENT: no such file or directory, uv_cwd'
01:05:25     
01:05:25         at Worker.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/parallel/test-worker-init-failure.js:38:14)
01:05:25         at Worker.emit (events.js:314:20)
01:05:25         at Worker.[kOnErrorMessage] (internal/worker.js:241:10)
01:05:25         at Worker.[kOnMessage] (internal/worker.js:251:37)
01:05:25         at MessagePort.<anonymous> (internal/worker.js:167:57)
01:05:25         at MessagePort.[nodejs.internal.kHybridDispatch] (internal/event_target.js:353:41)
01:05:25         at MessagePort.exports.emitMessage (internal/per_context/messageport.js:18:26)
01:05:25         at Worker.[kOnExit] (internal/worker.js:223:5)
01:05:25         at Worker.<computed>.onexit (internal/worker.js:164:20)
01:05:25     Emitted 'error' event on process instance at:
01:05:25         at emitUnhandledRejectionOrErr (internal/event_target.js:542:11)
01:05:25         at MessagePort.[nodejs.internal.kHybridDispatch] (internal/event_target.js:357:9)
01:05:25         at MessagePort.exports.emitMessage (internal/per_context/messageport.js:18:26)
01:05:25         at Worker.[kOnExit] (internal/worker.js:223:5)
01:05:25         at Worker.<computed>.onexit (internal/worker.js:164:20) {
01:05:25       generatedMessage: true,
01:05:25       code: 'ERR_ASSERTION',
01:05:25       actual: 'ENOENT: no such file or directory, uv_cwd',
01:05:25       expected: /EMFILE/,
01:05:25       operator: 'match'
01:05:25     }
01:05:25     
01:05:25     
01:05:25     assert.js:103
01:05:25       throw new AssertionError(obj);
01:05:25       ^
01:05:25     
01:05:25     AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
01:05:25     
01:05:25     1 !== 0
01:05:25     
01:05:25         at ChildProcess.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/parallel/test-worker-init-failure.js:64:12)
01:05:25         at ChildProcess.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/common/index.js:365:15)
01:05:25         at ChildProcess.emit (events.js:314:20)
01:05:25         at Process.ChildProcess._handle.onexit (internal/child_process.js:276:12) {
01:05:25       generatedMessage: true,
01:05:25       code: 'ERR_ASSERTION',
01:05:25       actual: 1,
01:05:25       expected: 0,
01:05:25       operator: 'strictEqual'
01:05:25     }
01:05:25   ...
  21. Trott
    reopened this on Aug 11, 2020

  22. Trott commented on Aug 11, 2020

    @Trott
    Trott
    on Aug 11, 2020
    MemberAuthor

    I wonder if the right thing to do is remove the e.message check and let the e.code check suffice.

  23. Trott
    added a commit that references this issue on Aug 11, 2020

    test: remove error message checking in test-worker-init-failure

    5cf4c45

  24. gireeshpunathil commented on Aug 11, 2020

    @gireeshpunathil
    gireeshpunathil
    on Aug 11, 2020
    Member

    looks like we have one more case that we missed here: the exact same libuv failure, but occurring after the worker is fully booted up - in which case the error is emitted as opposed to thrown.

    So if we accept the previous fix in principle, the right thing is to accommodate this error type in the test case itself.

    /cc @addaleax for opinion.

  25. gireeshpunathil commented on Aug 11, 2020

    @gireeshpunathil
    gireeshpunathil
    on Aug 11, 2020
    Member

    o! failed to see @Trott 's PR. will review that instead.

  26. Trott
    closed this as completedin #34727on Aug 14, 2020
  27. addaleax
    added 2 commits that reference this issue on Sep 22, 2020

    lib: absorb `path` error cases

    8505bfe

    lib: absorb `path` error cases

    633b4d5
  28. MayaLekova
    added a commit that references this issue on May 22, 2026

    lib: absorb `path` error cases

    4692e28
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    flaky-testIssues and PRs involving tests that fail intermittently in CI.macosIssues and PRs related to the macOS platform.

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions