investigate flaky test-worker-prof on Windows

[Trott]

• Test: sequential/test-worker-prof
• Platform: win10-COMPILED_BY-vs2019
• Console Output:

00:32:04 not ok 780 sequential/test-worker-prof
00:32:04   ---
00:32:04   duration_ms: 30.267
00:32:04   severity: fail
00:32:04   exitcode: 1
00:32:04   stack: |-
00:32:04     node:assert:122
00:32:04       throw new AssertionError(obj);
00:32:04       ^
00:32:04     
00:32:04     AssertionError [ERR_ASSERTION]: child exited with signal: {
00:32:04       error: Error: spawnSync C:\workspace\node-test-binary-windows-js-suites\node\Release\node.exe ETIMEDOUT
00:32:04           at Object.spawnSync (node:internal/child_process:1086:20)
00:32:04           at spawnSync (node:child_process:676:24)
00:32:04           at Object.<anonymous> (C:\workspace\node-test-binary-windows-js-suites\node\test\sequential\test-worker-prof.js:53:23)
00:32:04           at Module._compile (node:internal/modules/cjs/loader:1095:14)
00:32:04           at Object.Module._extensions..js (node:internal/modules/cjs/loader:1124:10)
00:32:04           at Module.load (node:internal/modules/cjs/loader:975:32)
00:32:04           at Function.Module._load (node:internal/modules/cjs/loader:816:14)
00:32:04           at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:76:12)
00:32:04           at node:internal/main/run_main_module:17:47 {
00:32:04         errno: -4039,
00:32:04         code: 'ETIMEDOUT',
00:32:04         syscall: 'spawnSync C:\\workspace\\node-test-binary-windows-js-suites\\node\\Release\\node.exe',
00:32:04         path: 'C:\\workspace\\node-test-binary-windows-js-suites\\node\\Release\\node.exe',
00:32:04         spawnargs: [
00:32:04           '--prof',
00:32:04           'C:\\workspace\\node-test-binary-windows-js-suites\\node\\test\\sequential\\test-worker-prof.js',
00:32:04           'child'
00:32:04         ]
00:32:04       },
00:32:04       status: null,
00:32:04       signal: 'SIGTERM',
00:32:04       output: [ null, '', '' ],
00:32:04       pid: 608,
00:32:04       stdout: '',
00:32:04       stderr: ''
00:32:04     }
00:32:04         at Object.<anonymous> (C:\workspace\node-test-binary-windows-js-suites\node\test\sequential\test-worker-prof.js:59:10)
00:32:04         at Module._compile (node:internal/modules/cjs/loader:1095:14)
00:32:04         at Object.Module._extensions..js (node:internal/modules/cjs/loader:1124:10)
00:32:04         at Module.load (node:internal/modules/cjs/loader:975:32)
00:32:04         at Function.Module._load (node:internal/modules/cjs/loader:816:14)
00:32:04         at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:76:12)
00:32:04         at node:internal/main/run_main_module:17:47 {
00:32:04       generatedMessage: false,
00:32:04       code: 'ERR_ASSERTION',
00:32:04       actual: 'SIGTERM',
00:32:04       expected: null,
00:32:04       operator: 'strictEqual'
00:32:04     }
00:32:04   ...

• Build Links: https://ci.nodejs.org/job/node-test-binary-windows-js-suites/8712/RUN_SUBSET=2,nodes=win10-COMPILED_BY-vs2019/console

Previous issue with test: #26401

[bcoe]

@Trott is this related to the fairly red state we're seeing in CI/CD for Windows suites?

[Trott]

@Trott is this related to the fairly red state we're seeing in CI/CD for Windows suites?

This is part of the js suite, and the current windows js test suite is pretty green. The failures are showing up in native test suites, specifically win2012r2-vs2019-COMPILED_BY-vs2019-x86, and seem to be build failures rather than test failures.

[Trott]

https://ci.nodejs.org/job/node-test-binary-windows-js-suites/8791/RUN_SUBSET=3,nodes=win10-COMPILED_BY-vs2019/console

Details

00:32:36 not ok 780 sequential/test-worker-prof
00:32:36   ---
00:32:36   duration_ms: 1.273
00:32:36   severity: fail
00:32:36   exitcode: 1
00:32:36   stack: |-
00:32:36     node:assert:122
00:32:36       throw new AssertionError(obj);
00:32:36       ^
00:32:36     
00:32:36     AssertionError [ERR_ASSERTION]: child exited with non-zero status:                      {
00:32:36       status: 3221225477,
00:32:36       signal: null,
00:32:36       output: [ null, '', '' ],
00:32:36       pid: 9724,
00:32:36       stdout: '',
00:32:36       stderr: ''
00:32:36     }
00:32:36         at Object.<anonymous> (C:\workspace\node-test-binary-windows-js-suites\node\test\sequential\test-worker-prof.js:61:10)
00:32:36         at Module._compile (node:internal/modules/cjs/loader:1095:14)
00:32:36         at Object.Module._extensions..js (node:internal/modules/cjs/loader:1124:10)
00:32:36         at Module.load (node:internal/modules/cjs/loader:975:32)
00:32:36         at Function.Module._load (node:internal/modules/cjs/loader:816:14)
00:32:36         at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:76:12)
00:32:36         at node:internal/main/run_main_module:17:47 {
00:32:36       generatedMessage: false,
00:32:36       code: 'ERR_ASSERTION',
00:32:36       actual: 3221225477,
00:32:36       expected: 0,
00:32:36       operator: 'strictEqual'
00:32:36     }
00:32:36   ...
00:32:36 

[Trott]

The message details in the previous failure are different than in the original report, but I suspect it's all related.

[Trott]

https://ci.nodejs.org/job/node-test-binary-windows-js-suites/9007/RUN_SUBSET=0,nodes=win10-COMPILED_BY-vs2019/console

02:44:30 not ok 782 sequential/test-worker-prof
02:44:30   ---
02:44:30   duration_ms: 30.312
02:44:30   severity: fail
02:44:30   exitcode: 1
02:44:30   stack: |-
02:44:30     node:assert:122
02:44:30       throw new AssertionError(obj);
02:44:30       ^
02:44:30     
02:44:30     AssertionError [ERR_ASSERTION]: child exited with signal: {
02:44:30       error: Error: spawnSync C:\workspace\node-test-binary-windows-js-suites\node\Release\node.exe ETIMEDOUT
02:44:30           at Object.spawnSync (node:internal/child_process:1086:20)
02:44:30           at spawnSync (node:child_process:693:24)
02:44:30           at Object.<anonymous> (C:\workspace\node-test-binary-windows-js-suites\node\test\sequential\test-worker-prof.js:53:23)
02:44:30           at Module._compile (node:internal/modules/cjs/loader:1108:14)
02:44:30           at Object.Module._extensions..js (node:internal/modules/cjs/loader:1137:10)
02:44:30           at Module.load (node:internal/modules/cjs/loader:988:32)
02:44:30           at Function.Module._load (node:internal/modules/cjs/loader:828:14)
02:44:30           at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:76:12)
02:44:30           at node:internal/main/run_main_module:17:47 {
02:44:30         errno: -4039,
02:44:30         code: 'ETIMEDOUT',
02:44:30         syscall: 'spawnSync C:\\workspace\\node-test-binary-windows-js-suites\\node\\Release\\node.exe',
02:44:30         path: 'C:\\workspace\\node-test-binary-windows-js-suites\\node\\Release\\node.exe',
02:44:30         spawnargs: [
02:44:30           '--prof',
02:44:30           'C:\\workspace\\node-test-binary-windows-js-suites\\node\\test\\sequential\\test-worker-prof.js',
02:44:30           'child'
02:44:30         ]
02:44:30       },
02:44:30       status: null,
02:44:30       signal: 'SIGTERM',
02:44:30       output: [ null, '', '' ],
02:44:30       pid: 16992,
02:44:30       stdout: '',
02:44:30       stderr: ''
02:44:30     }
02:44:30         at Object.<anonymous> (C:\workspace\node-test-binary-windows-js-suites\node\test\sequential\test-worker-prof.js:59:10)
02:44:30         at Module._compile (node:internal/modules/cjs/loader:1108:14)
02:44:30         at Object.Module._extensions..js (node:internal/modules/cjs/loader:1137:10)
02:44:30         at Module.load (node:internal/modules/cjs/loader:988:32)
02:44:30         at Function.Module._load (node:internal/modules/cjs/loader:828:14)
02:44:30         at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:76:12)
02:44:30         at node:internal/main/run_main_module:17:47 {
02:44:30       generatedMessage: false,
02:44:30       code: 'ERR_ASSERTION',
02:44:30       actual: 'SIGTERM',
02:44:30       expected: null,
02:44:30       operator: 'strictEqual'
02:44:30     }
02:44:30   ...

[Trott]

@nodejs/workers @nodejs/platform-windows

[Brooooooklyn]

avajs/ava#2926 (comment)

Testing failed after upgrading to ava@4 because of the worker_threads

[shnooshnoo]

hey I wanted to look into fixing this, here are my findings so far:

• according to reliability reports its been failing a lot this year - nearly every day uptil early october
• there is this commit landed around the same time when it stopped failing - c3c6c4f007
• I have a strong feeling that these two things are related and the test was fixed by that commit, apparently it's not flaky at the moment

@Trott with this in mind, do you think this ticket can be closed now?