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 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
@ryzokuken ryzokuken mentioned this issue Oct 9, 2018
Closed
4 tasks
@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
@Trott
test: add logging to test-worker-memory
d60de05 
To help troubleshoot CI failures, add some logging.

Refs: nodejs#23277 (comment)
@Trott Trott mentioned this issue Oct 11, 2018
Closed
2 tasks
@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
@Trott
test: add logging to test-worker-memory
f121ac0 
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
@Trott @targos
test: add logging to test-worker-memory
b279b96 
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/

@refack refack mentioned this issue Oct 16, 2018
Closed
@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
@Trott @jasnell
test: add logging to test-worker-memory
0fa857f 
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
@Trott @MylesBorins
test: add logging to test-worker-memory
27dd4de 
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 •
edited
Loading

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
@Trott @rvagg
test: add logging to test-worker-memory
3781bab 
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
@Trott @MylesBorins
test: add logging to test-worker-memory
ad47ae7 
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
test: mark test-worker-memory flaky on Windows CI
5fad76f 
Refs: nodejs#23277
@Trott Trott mentioned this issue Dec 14, 2018
Closed
2 tasks
Trott added a commit to Trott/io.js that referenced this issue Dec 14, 2018
@Trott
test: mark test-worker-memory flaky on Windows CI
87006be 
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
@Trott @BethGriggs
test: mark test-worker-memory flaky on Windows CI
2825894 
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
@Trott @BethGriggs
test: mark test-worker-memory flaky on Windows CI
55680e3 
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
@Trott @BethGriggs
test: mark test-worker-memory flaky on Windows CI
3a2a08d 
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
@Trott @rvagg
test: mark test-worker-memory flaky on Windows CI
241986d 
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 gireeshpunathil mentioned this issue Feb 2, 2020
Closed
@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.

@gireeshpunathil gireeshpunathil mentioned this issue Feb 5, 2020
Closed
@mmarchini mmarchini mentioned this issue Mar 7, 2020
Closed
15 tasks
@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
test: remove test-worker-memory flaky designation
d809894 
Judging from https://github.com/nodejs/reliability/issues, this hasn't
failed in CI since November 2021.

Closes: nodejs#23277
@Trott Trott mentioned this issue Feb 5, 2022
Merged
@Trott Trott closed this as completed in 30bdee2 Feb 6, 2022
ruyadorno pushed a commit that referenced this issue Feb 8, 2022
@Trott @ruyadorno
test: remove test-worker-memory flaky designation
0d9248f 
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
@Trott @danielleadams
test: remove test-worker-memory flaky designation
6a94a6b 
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
@Trott @danielleadams
test: remove test-worker-memory flaky designation
33f6d7a 
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
@Trott @danielleadams
test: remove test-worker-memory flaky designation
d591285 
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
@Trott @danielleadams
test: remove test-worker-memory flaky designation
9b581a5 
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
@Trott @danielleadams
test: remove test-worker-memory flaky designation
708d932 
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
@Trott @danielleadams
test: remove test-worker-memory flaky designation
a8e4183 
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
Assignees
No one assigned
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
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

test: remove test-worker-memory flaky designation Trott/io.js
6 participants
@sam-github @refack @Trott @addaleax @targos @gireeshpunathil