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

Investigate flaky parallel/test-worker-memory #23277

Closed
Trott opened this issue Oct 5, 2018 · 30 comments · Fixed by #41867
Closed

Investigate flaky parallel/test-worker-memory #23277

Trott opened this issue Oct 5, 2018 · 30 comments · Fixed by #41867
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI. windows Issues and PRs related to the Windows platform. worker Issues and PRs related to Worker support.

Comments

@Trott
Copy link
Member

Trott commented Oct 5, 2018

https://ci.nodejs.org/job/node-test-commit-arm/18980/nodes=centos7-arm64-gcc6/console

00:03:00 not ok 2022 parallel/test-worker-memory
00:03:00   ---
00:03:00   duration_ms: 1.17
00:03:00   severity: crashed
00:03:00   exitcode: -7
00:03:00   stack: |-
00:03:00   ...
@Trott Trott added the flaky-test Issues and PRs related to the tests with unstable failures on the CI. label Oct 5, 2018
@Trott
Copy link
Member Author

Trott commented Oct 10, 2018

Different:

https://ci.nodejs.org/job/node-test-commit-linux/22212/nodes=ubuntu1804-docker/console

00:51:34 not ok 2141 parallel/test-worker-memory
00:51:34   ---
00:51:34   duration_ms: 120.40
00:51:34   severity: fail
00:51:34   exitcode: -15
00:51:34   stack: |-
00:51:34     timeout

@Trott
Copy link
Member Author

Trott commented Oct 10, 2018

@nodejs/workers

@Trott
Copy link
Member Author

Trott commented Oct 11, 2018

https://ci.nodejs.org/job/node-test-binary-windows/20610/COMPILED_BY=vs2017,RUNNER=win2008r2-vs2017,RUN_SUBSET=0/console

08:12:48 not ok 519 parallel/test-worker-memory
08:12:48   ---
08:12:48   duration_ms: 120.92
08:12:48   severity: fail
08:12:48   exitcode: 1
08:12:48   stack: |-
08:12:48     timeout
08:12:48   ...

@addaleax addaleax added the worker Issues and PRs related to Worker support. label Oct 11, 2018
@addaleax
Copy link
Member

It’s unfortunate that none of these have any console output… -7 would be SIGBUS on arm Linux, if I am correct, which is something that could point to an actual bug.

@Trott
Copy link
Member Author

Trott commented Oct 11, 2018

It’s unfortunate that none of these have any console output… -7 would be SIGBUS on arm Linux, if I am correct, which is something that could point to an actual bug.

We can add some console.log() calls to get an idea where the thing is getting hung up.

Trott added a commit to Trott/io.js that referenced this issue Oct 11, 2018
To help troubleshoot CI failures, add some logging.

Refs: nodejs#23277 (comment)
@Trott
Copy link
Member Author

Trott commented Oct 11, 2018

Some minimal logging added in #23418.

Trott added a commit to Trott/io.js that referenced this issue Oct 11, 2018
To help troubleshoot CI failures, add some logging.

Refs: nodejs#23277 (comment)

PR-URL: nodejs#23418
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
Reviewed-By: Sakthipriyan Vairamani <thechargingvolcano@gmail.com>
targos pushed a commit that referenced this issue Oct 12, 2018
To help troubleshoot CI failures, add some logging.

Refs: #23277 (comment)

PR-URL: #23418
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
Reviewed-By: Sakthipriyan Vairamani <thechargingvolcano@gmail.com>
@targos
Copy link
Member

targos commented Oct 16, 2018

Example failure with logging:

timeout
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)

https://ci.nodejs.org/job/node-test-commit-linux-containered/nodes=ubuntu1604_sharedlibs_zlib_x64/7859/testReport/(root)/test/parallel_test_worker_memory/

@Trott
Copy link
Member Author

Trott commented Oct 16, 2018

Is there more logging we should add? Is it just taking a while? n keeps decreasing. So maybe the test just needs to be moved to sequential and/or have its iterations (or something else) reduced?

Also happened in https://ci.nodejs.org/job/node-test-commit-linux-containered/7855/nodes=ubuntu1604_sharedlibs_zlib_x64/console:

00:40:04 not ok 2193 parallel/test-worker-memory
00:40:04   ---
00:40:04   duration_ms: 120.161
00:40:04   severity: fail
00:40:04   exitcode: -15
00:40:04   stack: |-
00:40:04     timeout
00:40:04     run() called with n=15 (numWorkers=4)
00:40:04     run() called with n=15 (numWorkers=4)
00:40:04     run() called with n=15 (numWorkers=4)
00:40:04     run() called with n=15 (numWorkers=4)
00:40:04     run() called with n=14 (numWorkers=4)
00:40:04     run() called with n=14 (numWorkers=4)
00:40:04     run() called with n=14 (numWorkers=4)
00:40:04     run() called with n=14 (numWorkers=4)
00:40:04     run() called with n=13 (numWorkers=4)
00:40:04     run() called with n=13 (numWorkers=4)
00:40:04     run() called with n=13 (numWorkers=4)
00:40:04     run() called with n=13 (numWorkers=4)
00:40:04     run() called with n=12 (numWorkers=4)
00:40:04     run() called with n=12 (numWorkers=4)
00:40:04     run() called with n=12 (numWorkers=4)
00:40:04     run() called with n=12 (numWorkers=4)
00:40:04     run() called with n=11 (numWorkers=4)
00:40:04     run() called with n=11 (numWorkers=4)
00:40:04     run() called with n=11 (numWorkers=4)
00:40:04     run() called with n=11 (numWorkers=4)
00:40:04     run() called with n=10 (numWorkers=4)
00:40:04     run() called with n=10 (numWorkers=4)
00:40:04     run() called with n=10 (numWorkers=4)
00:40:04     run() called with n=10 (numWorkers=4)
00:40:04     run() called with n=9 (numWorkers=4)
00:40:04     run() called with n=9 (numWorkers=4)
00:40:04     run() called with n=9 (numWorkers=4)
00:40:04     run() called with n=9 (numWorkers=4)
00:40:04     run() called with n=8 (numWorkers=4)
00:40:04     run() called with n=8 (numWorkers=4)
00:40:04     run() called with n=8 (numWorkers=4)
00:40:04     run() called with n=7 (numWorkers=4)
00:40:04     run() called with n=8 (numWorkers=4)
00:40:04     run() called with n=7 (numWorkers=4)
00:40:04     run() called with n=7 (numWorkers=4)
00:40:04     run() called with n=6 (numWorkers=4)
00:40:04     run() called with n=7 (numWorkers=4)
00:40:04     run() called with n=6 (numWorkers=4)
00:40:04     run() called with n=5 (numWorkers=4)
00:40:04     run() called with n=6 (numWorkers=4)
00:40:04     run() called with n=6 (numWorkers=4)
00:40:04   ...

jasnell pushed a commit that referenced this issue Oct 17, 2018
To help troubleshoot CI failures, add some logging.

Refs: #23277 (comment)

PR-URL: #23418
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
Reviewed-By: Sakthipriyan Vairamani <thechargingvolcano@gmail.com>
MylesBorins pushed a commit that referenced this issue Oct 30, 2018
To help troubleshoot CI failures, add some logging.

Refs: #23277 (comment)

PR-URL: #23418
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
Reviewed-By: Sakthipriyan Vairamani <thechargingvolcano@gmail.com>
@Trott
Copy link
Member Author

Trott commented Nov 2, 2018

https://ci.nodejs.org/job/node-test-commit-arm/19636/nodes=ubuntu1604-arm64/console

19:53:45 not ok 2011 parallel/test-worker-memory
19:53:45   ---
19:53:45   duration_ms: 1.535
19:53:45   severity: crashed
19:53:45   exitcode: -11
19:53:45   stack: |-
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45     run() called with n=1.2 (numWorkers=50)
19:53:45   ...

@Trott
Copy link
Member Author

Trott commented Nov 13, 2018

I'm finding this test pretty easy to crash locally. Seems like perhaps a candidate to move to sequential (or find a way to have it run with fewer workers).

$ tools/test.py -j 32 --repeat 64 test/parallel/test-worker-memory.js 
=== release test-worker-memory ===                    
Path: parallel/test-worker-memory
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
out/Release/node[15392]: ../src/node_worker.cc:98:node::worker::Worker::Worker(node::Environment *, Local<v8::Object>, const std::string &): Assertion `(uv_loop_init(&loop_)) == (0)' failed.
 1: 0x10005edb3 node::Abort() [/Users/trott/io.js/out/Release/node]
 2: 0x10005ecf0 node::PrintErrorString(char const*, ...) [/Users/trott/io.js/out/Release/node]
 3: 0x1000c56fa node::worker::Worker::Worker(node::Environment*, v8::Local<v8::Object>, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&) [/Users/trott/io.js/out/Release/node]
 4: 0x1000c679d node::worker::Worker::New(v8::FunctionCallbackInfo<v8::Value> const&) [/Users/trott/io.js/out/Release/node]
 5: 0x10022efb4 v8::internal::FunctionCallbackArguments::Call(v8::internal::CallHandlerInfo*) [/Users/trott/io.js/out/Release/node]
 6: 0x10022e21b v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<true>(v8::internal::Isolate*, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::FunctionTemplateInfo>, v8::internal::Handle<v8::internal::Object>, v8::internal::BuiltinArguments) [/Users/trott/io.js/out/Release/node]
 7: 0x10022dbf9 v8::internal::Builtin_Impl_HandleApiCall(v8::internal::BuiltinArguments, v8::internal::Isolate*) [/Users/trott/io.js/out/Release/node]
 8: 0x3b503064fb7d
Command: out/Release/node --experimental-worker /Users/trott/io.js/test/parallel/test-worker-memory.js
--- CRASHED (Signal: 6) ---
=== release test-worker-memory ===                    
Path: parallel/test-worker-memory
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
events.js:167
      throw er; // Unhandled 'error' event
      ^
Error: ENFILE: file table overflow, uv_cwd
    at MessagePort.port.on (internal/worker.js:453:50)
    at MessagePort.emit (events.js:182:13)
    at MessagePort.onmessage (internal/worker.js:84:8)
Emitted 'error' event at:
    at Worker.[kOnErrorMessage] (internal/worker.js:332:10)
    at Worker.[kOnMessage] (internal/worker.js:342:37)
    at MessagePort.Worker.(anonymous function).on (internal/worker.js:279:57)
    at MessagePort.emit (events.js:182:13)
    at MessagePort.onmessage (internal/worker.js:84:8)
Command: out/Release/node --experimental-worker /Users/trott/io.js/test/parallel/test-worker-memory.js
=== release test-worker-memory ===                    
Path: parallel/test-worker-memory
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
events.js:167
      throw er; // Unhandled 'error' event
      ^
Error: ENFILE: file table overflow, uv_cwd
    at MessagePort.port.on (internal/worker.js:453:50)
    at MessagePort.emit (events.js:182:13)
    at MessagePort.onmessage (internal/worker.js:84:8)
Emitted 'error' event at:
    at Worker.[kOnErrorMessage] (internal/worker.js:332:10)
    at Worker.[kOnMessage] (internal/worker.js:342:37)
    at MessagePort.Worker.(anonymous function).on (internal/worker.js:279:57)
    at MessagePort.emit (events.js:182:13)
    at MessagePort.onmessage (internal/worker.js:84:8)
Command: out/Release/node --experimental-worker /Users/trott/io.js/test/parallel/test-worker-memory.js
=== release test-worker-memory ===                    
Path: parallel/test-worker-memory
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
out/Release/node[15404]: ../src/node_worker.cc:98:node::worker::Worker::Worker(node::Environment *, Local<v8::Object>, const std::string &): Assertion `(uv_loop_init(&loop_)) == (0)' failed.
 1: 0x10005edb3 node::Abort() [/Users/trott/io.js/out/Release/node]
 2: 0x10005ecf0 node::PrintErrorString(char const*, ...) [/Users/trott/io.js/out/Release/node]
 3: 0x1000c56fa node::worker::Worker::Worker(node::Environment*, v8::Local<v8::Object>, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&) [/Users/trott/io.js/out/Release/node]
 4: 0x1000c679d node::worker::Worker::New(v8::FunctionCallbackInfo<v8::Value> const&) [/Users/trott/io.js/out/Release/node]
 5: 0x10022efb4 v8::internal::FunctionCallbackArguments::Call(v8::internal::CallHandlerInfo*) [/Users/trott/io.js/out/Release/node]
 6: 0x10022e21b v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<true>(v8::internal::Isolate*, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::FunctionTemplateInfo>, v8::internal::Handle<v8::internal::Object>, v8::internal::BuiltinArguments) [/Users/trott/io.js/out/Release/node]
 7: 0x10022dbf9 v8::internal::Builtin_Impl_HandleApiCall(v8::internal::BuiltinArguments, v8::internal::Isolate*) [/Users/trott/io.js/out/Release/node]
 8: 0x1dda888cfb7d
Command: out/Release/node --experimental-worker /Users/trott/io.js/test/parallel/test-worker-memory.js
--- CRASHED (Signal: 6) ---
=== release test-worker-memory ===                    
Path: parallel/test-worker-memory
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=3 (numWorkers=4)
run() called with n=3 (numWorkers=4)
out/Release/node[15405]: ../src/node_worker.cc:98:node::worker::Worker::Worker(node::Environment *, Local<v8::Object>, const std::string &): Assertion `(uv_loop_init(&loop_)) == (0)' failed.
 1: 0x10005edb3 node::Abort() [/Users/trott/io.js/out/Release/node]
 2: 0x10005ecf0 node::PrintErrorString(char const*, ...) [/Users/trott/io.js/out/Release/node]
 3: 0x1000c56fa node::worker::Worker::Worker(node::Environment*, v8::Local<v8::Object>, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&) [/Users/trott/io.js/out/Release/node]
 4: 0x1000c679d node::worker::Worker::New(v8::FunctionCallbackInfo<v8::Value> const&) [/Users/trott/io.js/out/Release/node]
 5: 0x10022efb4 v8::internal::FunctionCallbackArguments::Call(v8::internal::CallHandlerInfo*) [/Users/trott/io.js/out/Release/node]
 6: 0x10022e21b v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<true>(v8::internal::Isolate*, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::FunctionTemplateInfo>, v8::internal::Handle<v8::internal::Object>, v8::internal::BuiltinArguments) [/Users/trott/io.js/out/Release/node]
 7: 0x10022dbf9 v8::internal::Builtin_Impl_HandleApiCall(v8::internal::BuiltinArguments, v8::internal::Isolate*) [/Users/trott/io.js/out/Release/node]
 8: 0x354d7cecfb7d
Command: out/Release/node --experimental-worker /Users/trott/io.js/test/parallel/test-worker-memory.js
--- CRASHED (Signal: 6) ---
=== release test-worker-memory ===                    
Path: parallel/test-worker-memory
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=3 (numWorkers=4)
run() called with n=3 (numWorkers=4)
run() called with n=4 (numWorkers=4)
out/Release/node[15403]: ../src/node_worker.cc:98:node::worker::Worker::Worker(node::Environment *, Local<v8::Object>, const std::string &): Assertion `(uv_loop_init(&loop_)) == (0)' failed.
 1: 0x10005edb3 node::Abort() [/Users/trott/io.js/out/Release/node]
 2: 0x10005ecf0 node::PrintErrorString(char const*, ...) [/Users/trott/io.js/out/Release/node]
 3: 0x1000c56fa node::worker::Worker::Worker(node::Environment*, v8::Local<v8::Object>, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&) [/Users/trott/io.js/out/Release/node]
 4: 0x1000c679d node::worker::Worker::New(v8::FunctionCallbackInfo<v8::Value> const&) [/Users/trott/io.js/out/Release/node]
 5: 0x10022efb4 v8::internal::FunctionCallbackArguments::Call(v8::internal::CallHandlerInfo*) [/Users/trott/io.js/out/Release/node]
 6: 0x10022e21b v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<true>(v8::internal::Isolate*, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::FunctionTemplateInfo>, v8::internal::Handle<v8::internal::Object>, v8::internal::BuiltinArguments) [/Users/trott/io.js/out/Release/node]
 7: 0x10022dbf9 v8::internal::Builtin_Impl_HandleApiCall(v8::internal::BuiltinArguments, v8::internal::Isolate*) [/Users/trott/io.js/out/Release/node]
 8: 0x9f67ba4fb7d
Command: out/Release/node --experimental-worker /Users/trott/io.js/test/parallel/test-worker-memory.js
--- CRASHED (Signal: 6) ---
=== release test-worker-memory ===                    
Path: parallel/test-worker-memory
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=15 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=14 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=13 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=12 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=11 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=10 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=9 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=8 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=7 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=6 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=5 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=4 (numWorkers=4)
run() called with n=3 (numWorkers=4)
run() called with n=3 (numWorkers=4)
run() called with n=3 (numWorkers=4)
run() called with n=3 (numWorkers=4)
run() called with n=2 (numWorkers=4)
run() called with n=2 (numWorkers=4)
run() called with n=2 (numWorkers=4)
run() called with n=2 (numWorkers=4)
run() called with n=1 (numWorkers=4)
out/Release/node[15410]: ../src/node_worker.cc:98:node::worker::Worker::Worker(node::Environment *, Local<v8::Object>, const std::string &): Assertion `(uv_loop_init(&loop_)) == (0)' failed.
 1: 0x10005edb3 node::Abort() [/Users/trott/io.js/out/Release/node]
 2: 0x10005ecf0 node::PrintErrorString(char const*, ...) [/Users/trott/io.js/out/Release/node]
 3: 0x1000c56fa node::worker::Worker::Worker(node::Environment*, v8::Local<v8::Object>, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&) [/Users/trott/io.js/out/Release/node]
 4: 0x1000c679d node::worker::Worker::New(v8::FunctionCallbackInfo<v8::Value> const&) [/Users/trott/io.js/out/Release/node]
 5: 0x10022efb4 v8::internal::FunctionCallbackArguments::Call(v8::internal::CallHandlerInfo*) [/Users/trott/io.js/out/Release/node]
 6: 0x10022e21b v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<true>(v8::internal::Isolate*, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::FunctionTemplateInfo>, v8::internal::Handle<v8::internal::Object>, v8::internal::BuiltinArguments) [/Users/trott/io.js/out/Release/node]
 7: 0x10022dbf9 v8::internal::Builtin_Impl_HandleApiCall(v8::internal::BuiltinArguments, v8::internal::Isolate*) [/Users/trott/io.js/out/Release/node]
 8: 0x89d04d4fb7d
Command: out/Release/node --experimental-worker /Users/trott/io.js/test/parallel/test-worker-memory.js
--- CRASHED (Signal: 6) ---
[01:27|% 100|+  57|-   7]: Done
$

rvagg pushed a commit that referenced this issue Nov 28, 2018
To help troubleshoot CI failures, add some logging.

Refs: #23277 (comment)

PR-URL: #23418
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
Reviewed-By: Sakthipriyan Vairamani <thechargingvolcano@gmail.com>
MylesBorins pushed a commit that referenced this issue Nov 29, 2018
To help troubleshoot CI failures, add some logging.

Refs: #23277 (comment)

PR-URL: #23418
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
Reviewed-By: Sakthipriyan Vairamani <thechargingvolcano@gmail.com>
@Trott
Copy link
Member Author

Trott commented Dec 14, 2018

Seems to now be showing up with some frequency on Windows, possibly only the win2008r2-vs2017 variant.

https://ci.nodejs.org/job/node-test-binary-windows/22438/COMPILED_BY=vs2017,RUNNER=win2008r2-vs2017,RUN_SUBSET=2/console

test-rackspace-win2008r2-x64-6

21:37:24 not ok 530 parallel/test-worker-memory
21:37:24   ---
21:37:24   duration_ms: 120.81
21:37:24   severity: fail
21:37:24   exitcode: 1
21:37:24   stack: |-
21:37:24     timeout
21:37:24     run() called with n=7.5 (numWorkers=8)
21:37:24     run() called with n=7.5 (numWorkers=8)
21:37:24     run() called with n=7.5 (numWorkers=8)
21:37:24     run() called with n=7.5 (numWorkers=8)
21:37:24     run() called with n=7.5 (numWorkers=8)
21:37:24     run() called with n=7.5 (numWorkers=8)
21:37:24     run() called with n=7.5 (numWorkers=8)
21:37:24     run() called with n=7.5 (numWorkers=8)
21:37:24     run() called with n=6.5 (numWorkers=8)
21:37:24     run() called with n=6.5 (numWorkers=8)
21:37:24     run() called with n=6.5 (numWorkers=8)
21:37:24     run() called with n=6.5 (numWorkers=8)
21:37:24     run() called with n=6.5 (numWorkers=8)
21:37:24     run() called with n=6.5 (numWorkers=8)
21:37:24     run() called with n=6.5 (numWorkers=8)
21:37:24     run() called with n=6.5 (numWorkers=8)
21:37:24     run() called with n=5.5 (numWorkers=8)
21:37:24     run() called with n=5.5 (numWorkers=8)
21:37:24     run() called with n=5.5 (numWorkers=8)
21:37:24     run() called with n=5.5 (numWorkers=8)
21:37:24     run() called with n=5.5 (numWorkers=8)
21:37:24     run() called with n=5.5 (numWorkers=8)
21:37:24     run() called with n=5.5 (numWorkers=8)
21:37:24     run() called with n=5.5 (numWorkers=8)
21:37:24     run() called with n=4.5 (numWorkers=8)
21:37:24     run() called with n=4.5 (numWorkers=8)
21:37:24     run() called with n=4.5 (numWorkers=8)
21:37:24     run() called with n=4.5 (numWorkers=8)
21:37:24     run() called with n=4.5 (numWorkers=8)
21:37:24     run() called with n=4.5 (numWorkers=8)
21:37:24     run() called with n=4.5 (numWorkers=8)
21:37:24     run() called with n=4.5 (numWorkers=8)
21:37:24     run() called with n=3.5 (numWorkers=8)
21:37:24     run() called with n=3.5 (numWorkers=8)
21:37:24     run() called with n=3.5 (numWorkers=8)
21:37:24     run() called with n=3.5 (numWorkers=8)
21:37:24     run() called with n=3.5 (numWorkers=8)
21:37:24     run() called with n=3.5 (numWorkers=8)
21:37:24     run() called with n=3.5 (numWorkers=8)
21:37:24     run() called with n=3.5 (numWorkers=8)
21:37:24     run() called with n=2.5 (numWorkers=8)
21:37:24     run() called with n=2.5 (numWorkers=8)
21:37:24     run() called with n=2.5 (numWorkers=8)
21:37:24     run() called with n=2.5 (numWorkers=8)
21:37:24     run() called with n=2.5 (numWorkers=8)
21:37:24     run() called with n=2.5 (numWorkers=8)
21:37:24     run() called with n=2.5 (numWorkers=8)
21:37:24     run() called with n=2.5 (numWorkers=8)
21:37:24     run() called with n=1.5 (numWorkers=8)
21:37:24     run() called with n=1.5 (numWorkers=8)
21:37:24     run() called with n=1.5 (numWorkers=8)
21:37:24     run() called with n=1.5 (numWorkers=8)
21:37:24     run() called with n=1.5 (numWorkers=8)
21:37:24     run() called with n=1.5 (numWorkers=8)
21:37:24     run() called with n=1.5 (numWorkers=8)
21:37:24     run() called with n=1.5 (numWorkers=8)
21:37:24     run() called with n=0.5 (numWorkers=8)
21:37:24     run() called with n=0.5 (numWorkers=8)
21:37:24     run() called with n=0.5 (numWorkers=8)
21:37:24     run() called with n=0.5 (numWorkers=8)
21:37:24     run() called with n=0.5 (numWorkers=8)
21:37:24     run() called with n=0.5 (numWorkers=8)
21:37:24     run() called with n=0.5 (numWorkers=8)
21:37:24     run() called with n=0.5 (numWorkers=8)
21:37:24     run() called with n=-0.5 (numWorkers=8)
21:37:24     done() called (finished=0)
21:37:24     run() called with n=-0.5 (numWorkers=8)
21:37:24     done() called (finished=1)
21:37:24     run() called with n=-0.5 (numWorkers=8)
21:37:24     done() called (finished=2)
21:37:24     run() called with n=-0.5 (numWorkers=8)
21:37:24     done() called (finished=3)
21:37:24     run() called with n=-0.5 (numWorkers=8)
21:37:24     done() called (finished=4)
21:37:24     run() called with n=-0.5 (numWorkers=8)
21:37:24     done() called (finished=5)
21:37:24     run() called with n=-0.5 (numWorkers=8)
21:37:24     done() called (finished=6)
21:37:24     run() called with n=-0.5 (numWorkers=8)
21:37:24     done() called (finished=7)
21:37:24   ...

@Trott
Copy link
Member Author

Trott commented Dec 14, 2018

Appears to be specific to (or particularly prone to happen) on win2008r2-vs2017 in CI.

https://ci.nodejs.org/job/node-test-binary-windows/22443/COMPILED_BY=vs2017,RUNNER=win2008r2-vs2017,RUN_SUBSET=2/console

test-rackspace-win2008r2-x64-4

00:58:18 not ok 530 parallel/test-worker-memory
00:58:18   ---
00:58:18   duration_ms: 120.116
00:58:18   severity: fail
00:58:18   exitcode: 1
00:58:18   stack: |-
00:58:18     timeout
00:58:18     run() called with n=7.5 (numWorkers=8)
00:58:18     run() called with n=7.5 (numWorkers=8)
00:58:18     run() called with n=7.5 (numWorkers=8)
00:58:18     run() called with n=7.5 (numWorkers=8)
00:58:18     run() called with n=7.5 (numWorkers=8)
00:58:18     run() called with n=7.5 (numWorkers=8)
00:58:18     run() called with n=7.5 (numWorkers=8)
00:58:18     run() called with n=7.5 (numWorkers=8)
00:58:18     run() called with n=6.5 (numWorkers=8)
00:58:18     run() called with n=6.5 (numWorkers=8)
00:58:18     run() called with n=6.5 (numWorkers=8)
00:58:18     run() called with n=6.5 (numWorkers=8)
00:58:18     run() called with n=6.5 (numWorkers=8)
00:58:18     run() called with n=6.5 (numWorkers=8)
00:58:18     run() called with n=6.5 (numWorkers=8)
00:58:18     run() called with n=6.5 (numWorkers=8)
00:58:18     run() called with n=5.5 (numWorkers=8)
00:58:18     run() called with n=5.5 (numWorkers=8)
00:58:18     run() called with n=5.5 (numWorkers=8)
00:58:18     run() called with n=5.5 (numWorkers=8)
00:58:18     run() called with n=5.5 (numWorkers=8)
00:58:18     run() called with n=5.5 (numWorkers=8)
00:58:18     run() called with n=5.5 (numWorkers=8)
00:58:18     run() called with n=5.5 (numWorkers=8)
00:58:18     run() called with n=4.5 (numWorkers=8)
00:58:18     run() called with n=4.5 (numWorkers=8)
00:58:18     run() called with n=4.5 (numWorkers=8)
00:58:18     run() called with n=4.5 (numWorkers=8)
00:58:18     run() called with n=4.5 (numWorkers=8)
00:58:18     run() called with n=4.5 (numWorkers=8)
00:58:18     run() called with n=4.5 (numWorkers=8)
00:58:18     run() called with n=4.5 (numWorkers=8)
00:58:18     run() called with n=3.5 (numWorkers=8)
00:58:18     run() called with n=3.5 (numWorkers=8)
00:58:18     run() called with n=3.5 (numWorkers=8)
00:58:18     run() called with n=3.5 (numWorkers=8)
00:58:18     run() called with n=3.5 (numWorkers=8)
00:58:18     run() called with n=3.5 (numWorkers=8)
00:58:18     run() called with n=3.5 (numWorkers=8)
00:58:18     run() called with n=3.5 (numWorkers=8)
00:58:18     run() called with n=2.5 (numWorkers=8)
00:58:18     run() called with n=2.5 (numWorkers=8)
00:58:18     run() called with n=2.5 (numWorkers=8)
00:58:18     run() called with n=2.5 (numWorkers=8)
00:58:18     run() called with n=2.5 (numWorkers=8)
00:58:18     run() called with n=2.5 (numWorkers=8)
00:58:18     run() called with n=2.5 (numWorkers=8)
00:58:18     run() called with n=2.5 (numWorkers=8)
00:58:18     run() called with n=1.5 (numWorkers=8)
00:58:18     run() called with n=1.5 (numWorkers=8)
00:58:18     run() called with n=1.5 (numWorkers=8)
00:58:18     run() called with n=1.5 (numWorkers=8)
00:58:18     run() called with n=1.5 (numWorkers=8)
00:58:18     run() called with n=1.5 (numWorkers=8)
00:58:18     run() called with n=1.5 (numWorkers=8)
00:58:18     run() called with n=1.5 (numWorkers=8)
00:58:18     run() called with n=0.5 (numWorkers=8)
00:58:18     run() called with n=0.5 (numWorkers=8)
00:58:18     run() called with n=0.5 (numWorkers=8)
00:58:18     run() called with n=0.5 (numWorkers=8)
00:58:18     run() called with n=0.5 (numWorkers=8)
00:58:18     run() called with n=0.5 (numWorkers=8)
00:58:18     run() called with n=0.5 (numWorkers=8)
00:58:18     run() called with n=0.5 (numWorkers=8)
00:58:18     run() called with n=-0.5 (numWorkers=8)
00:58:18     done() called (finished=0)
00:58:18     run() called with n=-0.5 (numWorkers=8)
00:58:18     done() called (finished=1)
00:58:18     run() called with n=-0.5 (numWorkers=8)
00:58:18     done() called (finished=2)
00:58:18     run() called with n=-0.5 (numWorkers=8)
00:58:18     done() called (finished=3)
00:58:18     run() called with n=-0.5 (numWorkers=8)
00:58:18     done() called (finished=4)
00:58:18     run() called with n=-0.5 (numWorkers=8)
00:58:18     done() called (finished=5)
00:58:18     run() called with n=-0.5 (numWorkers=8)
00:58:18     done() called (finished=6)
00:58:18     run() called with n=-0.5 (numWorkers=8)
00:58:18     done() called (finished=7)
00:58:18   ...

Trott added a commit to Trott/io.js that referenced this issue Dec 14, 2018
Trott added a commit to Trott/io.js that referenced this issue Dec 14, 2018
Refs: nodejs#23277

PR-URL: nodejs#25042
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
BethGriggs pushed a commit that referenced this issue Dec 18, 2018
Refs: #23277

PR-URL: #25042
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
BethGriggs pushed a commit that referenced this issue Feb 12, 2019
Refs: #23277

PR-URL: #25042
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
BethGriggs pushed a commit that referenced this issue Feb 20, 2019
Refs: #23277

PR-URL: #25042
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
rvagg pushed a commit that referenced this issue Feb 28, 2019
Refs: #23277

PR-URL: #25042
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
@sam-github sam-github added the windows Issues and PRs related to the Windows platform. label Jun 7, 2019
@gireeshpunathil
Copy link
Member

I am now tending to suspect that the behavior explained in #21266 (comment) apply here. Therss memory to quiesce fully and come back to near-normal, there should be memory demand in other parts of the system, or else it just stays active in the current process.

@gireeshpunathil
Copy link
Member

ok, I am able to confim my theory. I found a system where I can consistently reproduce this failure.

looking at the system spec w.r.t cpu and memory:

$ cat /proc/cpuinfo | grep processor | wc -l
120
$ cat /proc/meminfo | grep MemFree
MemFree:        1041442704 kB

in view of the rss theory, the issue now become evident - there was no drivers for pulling down the bloated rss.

diff --git a/test/parallel/test-worker-memory.js b/test/parallel/test-worker-memory.js
index 19b89d4..9d47271 100644
--- a/test/parallel/test-worker-memory.js
+++ b/test/parallel/test-worker-memory.js
@@ -38,7 +38,10 @@ for (let i = 0; i < numWorkers; ++i) {
   run(60 / numWorkers, () => {
     console.log(`done() called (finished=${finished})`);
     if (++finished === numWorkers) {
-      const finishStats = process.memoryUsage();
+      setInterval(() => {
+        const finishStats = process.memoryUsage();
+        console.log(Math.round(finishStats.rss / (1024 * 1024)))
+      }, 2000)
       // A typical value for this ratio would be ~1.15.
       // 5 as a upper limit is generous, but the main point is that we
       // don't have the memory of 50 Isolates/Node.js environments just lying

With this patch I kept the program alive, ran some load on the system, and saw the rss coming down.

I guess we need to devise a new stratgey for checking memory leak in this test case, without the usage of rss.

Re-opening this based on root cause identified.

@Trott
Copy link
Member Author

Trott commented Mar 6, 2021

@gireeshpunathil Is there any chance the root cause has been fixed since we last visited this issue? This test hasn't failed recently.

@gireeshpunathil
Copy link
Member

@Trott - none that I am aware of. IMO, the issue cannot be comprehensively solved as long as we don't have a way to compute the actual / active / used memory by a process.

However, if CI is consistently passing this, I guess we have no reason to keep this open. We can always re-open if we start to see this again.

@Trott Trott reopened this Apr 25, 2021
@Trott
Copy link
Member Author

Trott commented Apr 25, 2021

https://ci.nodejs.org/job/node-test-binary-windows-js-suites/9616/RUN_SUBSET=2,nodes=win2012r2-COMPILED_BY-vs2019-x86/console

00:12:14 not ok 708 parallel/test-worker-memory # TODO : Fix flaky test
00:12:14   ---
00:12:14   duration_ms: 1.360
00:12:14   severity: crashed
00:12:14   exitcode: 3221225477
00:12:14   stack: |-
00:12:14     run() called with n=7.5 (numWorkers=8)
00:12:14     run() called with n=7.5 (numWorkers=8)
00:12:14     run() called with n=7.5 (numWorkers=8)
00:12:14     run() called with n=7.5 (numWorkers=8)
00:12:14     run() called with n=7.5 (numWorkers=8)
00:12:14     run() called with n=7.5 (numWorkers=8)
00:12:14     run() called with n=7.5 (numWorkers=8)
00:12:14     run() called with n=7.5 (numWorkers=8)
00:12:14     run() called with n=6.5 (numWorkers=8)
00:12:14     run() called with n=6.5 (numWorkers=8)
00:12:14     run() called with n=6.5 (numWorkers=8)
00:12:14     run() called with n=6.5 (numWorkers=8)
00:12:14     run() called with n=6.5 (numWorkers=8)
00:12:14     run() called with n=6.5 (numWorkers=8)
00:12:14     run() called with n=6.5 (numWorkers=8)
00:12:14     run() called with n=6.5 (numWorkers=8)
00:12:14     run() called with n=5.5 (numWorkers=8)
00:12:14     run() called with n=5.5 (numWorkers=8)
00:12:14     run() called with n=5.5 (numWorkers=8)
00:12:14     run() called with n=5.5 (numWorkers=8)
00:12:14     run() called with n=5.5 (numWorkers=8)
00:12:14     run() called with n=5.5 (numWorkers=8)
00:12:14     run() called with n=4.5 (numWorkers=8)
00:12:14     run() called with n=5.5 (numWorkers=8)
00:12:14     run() called with n=4.5 (numWorkers=8)
00:12:14     run() called with n=4.5 (numWorkers=8)
00:12:14     run() called with n=5.5 (numWorkers=8)
00:12:14     run() called with n=4.5 (numWorkers=8)
00:12:14     run() called with n=4.5 (numWorkers=8)
00:12:14     run() called with n=4.5 (numWorkers=8)
00:12:14     run() called with n=3.5 (numWorkers=8)
00:12:14     run() called with n=4.5 (numWorkers=8)
00:12:14     run() called with n=3.5 (numWorkers=8)
00:12:14     run() called with n=3.5 (numWorkers=8)
00:12:14     run() called with n=4.5 (numWorkers=8)
00:12:14     run() called with n=3.5 (numWorkers=8)
00:12:14     run() called with n=2.5 (numWorkers=8)
00:12:14     run() called with n=3.5 (numWorkers=8)
00:12:14     run() called with n=2.5 (numWorkers=8)
00:12:14     run() called with n=3.5 (numWorkers=8)
00:12:14     run() called with n=3.5 (numWorkers=8)
00:12:14     run() called with n=2.5 (numWorkers=8)
00:12:14     run() called with n=1.5 (numWorkers=8)
00:12:14     run() called with n=2.5 (numWorkers=8)
00:12:14     run() called with n=3.5 (numWorkers=8)
00:12:14     run() called with n=2.5 (numWorkers=8)
00:12:14     run() called with n=2.5 (numWorkers=8)
00:12:14     run() called with n=2.5 (numWorkers=8)
00:12:14     run() called with n=0.5 (numWorkers=8)
00:12:14     run() called with n=1.5 (numWorkers=8)
00:12:14     run() called with n=2.5 (numWorkers=8)
00:12:14     run() called with n=1.5 (numWorkers=8)
00:12:14     run() called with n=1.5 (numWorkers=8)
00:12:14     run() called with n=1.5 (numWorkers=8)
00:12:14     run() called with n=1.5 (numWorkers=8)
00:12:14     run() called with n=-0.5 (numWorkers=8)
00:12:14     done() called (finished=0)
00:12:14     run() called with n=0.5 (numWorkers=8)
00:12:14     run() called with n=1.5 (numWorkers=8)
00:12:14     run() called with n=0.5 (numWorkers=8)
00:12:14     run() called with n=0.5 (numWorkers=8)
00:12:14     run() called with n=0.5 (numWorkers=8)
00:12:14     run() called with n=0.5 (numWorkers=8)
00:12:14     run() called with n=0.5 (numWorkers=8)
00:12:14     run() called with n=-0.5 (numWorkers=8)
00:12:14     done() called (finished=1)
00:12:14     run() called with n=-0.5 (numWorkers=8)
00:12:14     done() called (finished=2)
00:12:14     run() called with n=-0.5 (numWorkers=8)
00:12:14     done() called (finished=3)
00:12:14     run() called with n=-0.5 (numWorkers=8)
00:12:14     done() called (finished=4)
00:12:14     run() called with n=-0.5 (numWorkers=8)
00:12:14     done() called (finished=5)
00:12:14     
00:12:14     
00:12:14     #
00:12:14     # Fatal error in , line 0
00:12:14     # Check failed: IsEmpty().
00:12:14     #
00:12:14     #
00:12:14     #
00:12:14     #FailureMessage Object: 08DFF4F4
00:12:14   ...

Trott added a commit to Trott/io.js that referenced this issue Feb 5, 2022
@Trott Trott closed this as completed in 30bdee2 Feb 6, 2022
ruyadorno pushed a commit that referenced this issue Feb 8, 2022
Judging from https://github.com/nodejs/reliability/issues, this hasn't
failed in CI since November 2021.

Closes: #23277

PR-URL: #41867
Fixes: #23277
Reviewed-By: Tobias Nießen <tniessen@tnie.de>
Reviewed-By: Mestery <mestery@protonmail.com>
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
danielleadams pushed a commit that referenced this issue Mar 2, 2022
Judging from https://github.com/nodejs/reliability/issues, this hasn't
failed in CI since November 2021.

Closes: #23277

PR-URL: #41867
Fixes: #23277
Reviewed-By: Tobias Nießen <tniessen@tnie.de>
Reviewed-By: Mestery <mestery@protonmail.com>
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
danielleadams pushed a commit that referenced this issue Mar 3, 2022
Judging from https://github.com/nodejs/reliability/issues, this hasn't
failed in CI since November 2021.

Closes: #23277

PR-URL: #41867
Fixes: #23277
Reviewed-By: Tobias Nießen <tniessen@tnie.de>
Reviewed-By: Mestery <mestery@protonmail.com>
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
danielleadams pushed a commit to danielleadams/node that referenced this issue Mar 4, 2022
Judging from https://github.com/nodejs/reliability/issues, this hasn't
failed in CI since November 2021.

Closes: nodejs#23277

PR-URL: nodejs#41867
Fixes: nodejs#23277
Reviewed-By: Tobias Nießen <tniessen@tnie.de>
Reviewed-By: Mestery <mestery@protonmail.com>
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
danielleadams pushed a commit to danielleadams/node that referenced this issue Mar 4, 2022
Judging from https://github.com/nodejs/reliability/issues, this hasn't
failed in CI since November 2021.

Closes: nodejs#23277

PR-URL: nodejs#41867
Fixes: nodejs#23277
Reviewed-By: Tobias Nießen <tniessen@tnie.de>
Reviewed-By: Mestery <mestery@protonmail.com>
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
danielleadams pushed a commit that referenced this issue Mar 8, 2022
Judging from https://github.com/nodejs/reliability/issues, this hasn't
failed in CI since November 2021.

Closes: #23277

PR-URL: #41867
Fixes: #23277
Reviewed-By: Tobias Nießen <tniessen@tnie.de>
Reviewed-By: Mestery <mestery@protonmail.com>
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
danielleadams pushed a commit that referenced this issue Mar 14, 2022
Judging from https://github.com/nodejs/reliability/issues, this hasn't
failed in CI since November 2021.

Closes: #23277

PR-URL: #41867
Fixes: #23277
Reviewed-By: Tobias Nießen <tniessen@tnie.de>
Reviewed-By: Mestery <mestery@protonmail.com>
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI. windows Issues and PRs related to the Windows platform. worker Issues and PRs related to Worker support.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants