investigate flaky test/node-api/test_worker_terminate_finalization/test.js

[RaisinTen]

• Test: test/node-api/test_worker_terminate_finalization/test.js
• Platform: linux
• Console Output:

=== release test ===
Path: node-api/test_worker_terminate_finalization/test
Error: --- stderr ---
=================================================================
==14596==ERROR: AddressSanitizer: heap-use-after-free on address 0x60700000cc70 at pc 0x000000be11c4 bp 0x7f273ef6cda0 sp 0x7f273ef6cd98
READ of size 8 at 0x60700000cc70 thread T7
    #0 0xbe11c3 in v8impl::(anonymous namespace)::Reference::SecondPassCallback(v8::WeakCallbackInfo<v8impl::(anonymous namespace)::Reference> const&) (/home/runner/work/node/node/out/Release/node+0xbe11c3)
    #1 0x1706808 in v8::internal::GlobalHandles::InvokeSecondPassPhantomCallbacksFromTask() (/home/runner/work/node/node/out/Release/node+0x1706808)
    #2 0xe2b26f in node::PerIsolatePlatformData::RunForegroundTask(std::unique_ptr<v8::Task, std::default_delete<v8::Task> >) (/home/runner/work/node/node/out/Release/node+0xe2b26f)
    #3 0xe26300 in node::PerIsolatePlatformData::FlushForegroundTasksInternal() (/home/runner/work/node/node/out/Release/node+0xe26300)
    #4 0xe2ba45 in node::NodePlatform::DrainTasks(v8::Isolate*) (/home/runner/work/node/node/out/Release/node+0xe2ba45)
    #5 0xa8a5db in node::FreeEnvironment(node::Environment*) (/home/runner/work/node/node/out/Release/node+0xa8a5db)
    #6 0xf28d41 in node::worker::Worker::Run() (/home/runner/work/node/node/out/Release/node+0xf28d41)
    #7 0xf33fe0 in node::worker::Worker::StartThread(v8::FunctionCallbackInfo<v8::Value> const&)::$_3::__invoke(void*) (/home/runner/work/node/node/out/Release/node+0xf33fe0)
    #8 0x7f27453b96da in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76da)
    #9 0x7f2744cc271e in clone (/lib/x86_64-linux-gnu/libc.so.6+0x12171e)

0x60700000cc70 is located 0 bytes inside of 80-byte region [0x60700000cc70,0x60700000ccc0)
freed by thread T7 here:
    #0 0xa769bd in operator delete(void*) (/home/runner/work/node/node/out/Release/node+0xa769bd)
    #1 0xc1622d in node_napi_env__::~node_napi_env__() (/home/runner/work/node/node/out/Release/node+0xc1622d)
    #2 0xc12f53 in node::CallbackQueue<void, node::Environment*>::CallbackImpl<v8impl::(anonymous namespace)::BufferFinalizer::FinalizeBufferCallback(char*, void*)::'lambda'(node::Environment*)>::~CallbackImpl() (/home/runner/work/node/node/out/Release/node+0xc12f53)
    #3 0xb72a20 in node::Environment::RunAndClearNativeImmediates(bool)::$_5::operator()(node::CallbackQueue<void, node::Environment*>*) const (/home/runner/work/node/node/out/Release/node+0xb72a20)
    #4 0xb7070a in node::Environment::RunAndClearNativeImmediates(bool) (/home/runner/work/node/node/out/Release/node+0xb7070a)
    #5 0xb6ffb3 in node::Environment::CleanupHandles() (/home/runner/work/node/node/out/Release/node+0xb6ffb3)
    #6 0xb71177 in node::Environment::RunCleanup() (/home/runner/work/node/node/out/Release/node+0xb71177)
    #7 0xa8a514 in node::FreeEnvironment(node::Environment*) (/home/runner/work/node/node/out/Release/node+0xa8a514)
    #8 0xf28d41 in node::worker::Worker::Run() (/home/runner/work/node/node/out/Release/node+0xf28d41)
    #9 0xf33fe0 in node::worker::Worker::StartThread(v8::FunctionCallbackInfo<v8::Value> const&)::$_3::__invoke(void*) (/home/runner/work/node/node/out/Release/node+0xf33fe0)
    #10 0x7f27453b96da in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76da)

previously allocated by thread T7 here:
    #0 0xa7615d in operator new(unsigned long) (/home/runner/work/node/node/out/Release/node+0xa7615d)
    #1 0xbd4473 in napi_wrap (/home/runner/work/node/node/out/Release/node+0xbd4473)
    #2 0x7f273e71a925 in Test (/home/runner/work/node/node/test/node-api/test_worker_terminate_finalization/build/Release/test_worker_terminate_finalization.node+0x1925)
    #3 0xbdfcf2 in v8impl::(anonymous namespace)::FunctionCallbackWrapper::Invoke(v8::FunctionCallbackInfo<v8::Value> const&) (/home/runner/work/node/node/out/Release/node+0xbdfcf2)
    #4 0x138b2e3 in v8::internal::FunctionCallbackArguments::Call(v8::internal::CallHandlerInfo) (/home/runner/work/node/node/out/Release/node+0x138b2e3)
    #5 0x1389114 in v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<false>(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) (/home/runner/work/node/node/out/Release/node+0x1389114)
    #6 0x1387192 in v8::internal::Builtin_Impl_HandleApiCall(v8::internal::BuiltinArguments, v8::internal::Isolate*) (/home/runner/work/node/node/out/Release/node+0x1387192)
    #7 0x2ca6678 in Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_BuiltinExit (/home/runner/work/node/node/out/Release/node+0x2ca6678)
    #8 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #9 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #10 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #11 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #12 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #13 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #14 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #15 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #16 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #17 0x2c3afb9 in Builtins_JSEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3afb9)
    #18 0x2c3ad97 in Builtins_JSEntry (/home/runner/work/node/node/out/Release/node+0x2c3ad97)
    #19 0x16575ef in v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) (/home/runner/work/node/node/out/Release/node+0x16575ef)
    #20 0x1655374 in v8::internal::Execution::Call(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*) (/home/runner/work/node/node/out/Release/node+0x1655374)
    #21 0x124af20 in v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) (/home/runner/work/node/node/out/Release/node+0x124af20)
    #22 0xa7cbb2 in node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) (/home/runner/work/node/node/out/Release/node+0xa7cbb2)
    #23 0xad0b07 in node::AsyncWrap::MakeCallback(v8::Local<v8::Function>, int, v8::Local<v8::Value>*) (/home/runner/work/node/node/out/Release/node+0xad0b07)
    #24 0xd8dfbc in node::worker::MessagePort::OnMessage() (/home/runner/work/node/node/out/Release/node+0xd8dfbc)
    #25 0x2bf8c58 in uv__async_io /home/runner/work/node/node/out/../deps/uv/src/unix/async.c:163:5
    #26 0x2c2cf30 in uv__io_poll /home/runner/work/node/node/out/../deps/uv/src/unix/linux-core.c:462:11
    #27 0x2bf9c67 in uv_run /home/runner/work/node/node/out/../deps/uv/src/unix/core.c:385:5
    #28 0xa7f094 in node::SpinEventLoop(node::Environment*) (/home/runner/work/node/node/out/Release/node+0xa7f094)
    #29 0xf28bf4 in node::worker::Worker::Run() (/home/runner/work/node/node/out/Release/node+0xf28bf4)

Thread T7 created by T0 here:
    #0 0xa311aa in pthread_create (/home/runner/work/node/node/out/Release/node+0xa311aa)
    #1 0x2c2253a in uv_thread_create_ex /home/runner/work/node/node/out/../deps/uv/src/unix/thread.c:259:9
    #2 0xf313d4 in node::worker::Worker::StartThread(v8::FunctionCallbackInfo<v8::Value> const&) (/home/runner/work/node/node/out/Release/node+0xf313d4)
    #3 0x138b2e3 in v8::internal::FunctionCallbackArguments::Call(v8::internal::CallHandlerInfo) (/home/runner/work/node/node/out/Release/node+0x138b2e3)
    #4 0x1389114 in v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<false>(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) (/home/runner/work/node/node/out/Release/node+0x1389114)
    #5 0x1387192 in v8::internal::Builtin_Impl_HandleApiCall(v8::internal::BuiltinArguments, v8::internal::Isolate*) (/home/runner/work/node/node/out/Release/node+0x1387192)
    #6 0x2ca6678 in Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_BuiltinExit (/home/runner/work/node/node/out/Release/node+0x2ca6678)
    #7 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #8 0x2c35d98 in Builtins_ArgumentsAdaptorTrampoline (/home/runner/work/node/node/out/Release/node+0x2c35d98)
    #9 0x2c3a3c0 in Builtins_JSConstructStubGeneric (/home/runner/work/node/node/out/Release/node+0x2c3a3c0)
    #10 0x2d31480 in Builtins_ConstructHandler (/home/runner/work/node/node/out/Release/node+0x2d31480)
    #11 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #12 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #13 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #14 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #15 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #16 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #17 0x2c3d283 in Builtins_InterpreterEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3d283)
    #18 0x2c3afb9 in Builtins_JSEntryTrampoline (/home/runner/work/node/node/out/Release/node+0x2c3afb9)
    #19 0x2c3ad97 in Builtins_JSEntry (/home/runner/work/node/node/out/Release/node+0x2c3ad97)
    #20 0x16575ef in v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) (/home/runner/work/node/node/out/Release/node+0x16575ef)
    #21 0x1655374 in v8::internal::Execution::Call(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*) (/home/runner/work/node/node/out/Release/node+0x1655374)
    #22 0x124af20 in v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) (/home/runner/work/node/node/out/Release/node+0x124af20)
    #23 0xbfc638 in node::ExecuteBootstrapper(node::Environment*, char const*, std::vector<v8::Local<v8::String>, std::allocator<v8::Local<v8::String> > >*, std::vector<v8::Local<v8::Value>, std::allocator<v8::Local<v8::Value> > >*) (/home/runner/work/node/node/out/Release/node+0xbfc638)
    #24 0xc01001 in node::StartExecution(node::Environment*, char const*) (/home/runner/work/node/node/out/Release/node+0xc01001)
    #25 0xbff7ca in node::StartExecution(node::Environment*, std::function<v8::MaybeLocal<v8::Value> (node::StartExecutionCallbackInfo const&)>) (/home/runner/work/node/node/out/Release/node+0xbff7ca)
    #26 0xa8ad1b in node::LoadEnvironment(node::Environment*, std::function<v8::MaybeLocal<v8::Value> (node::StartExecutionCallbackInfo const&)>) (/home/runner/work/node/node/out/Release/node+0xa8ad1b)
    #27 0xd81832 in node::NodeMainInstance::Run(node::EnvSerializeInfo const*) (/home/runner/work/node/node/out/Release/node+0xd81832)
    #28 0xc054af in node::Start(int, char**) (/home/runner/work/node/node/out/Release/node+0xc054af)
    #29 0x7f2744bc2bf6 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21bf6)

SUMMARY: AddressSanitizer: heap-use-after-free (/home/runner/work/node/node/out/Release/node+0xbe11c3) in v8impl::(anonymous namespace)::Reference::SecondPassCallback(v8::WeakCallbackInfo<v8impl::(anonymous namespace)::Reference> const&)
Shadow bytes around the buggy address:
  0x0c0e7fff9930: fd fd fd fd fd fd fa fa fa fa fd fd fd fd fd fd
  0x0c0e7fff9940: fd fd fd fa fa fa fa fa fd fd fd fd fd fd fd fd
  0x0c0e7fff9950: fd fd fa fa fa fa 00 00 00 00 00 00 00 00 00 fa
  0x0c0e7fff9960: fa fa fa fa fd fd fd fd fd fd fd fd fd fd fa fa
  0x0c0e7fff9970: fa fa fd fd fd fd fd fd fd fd fd fd fa fa fa fa
=>0x0c0e7fff9980: fd fd fd fd fd fd fd fd fd fd fa fa fa fa[fd]fd
  0x0c0e7fff9990: fd fd fd fd fd fd fd fd fa fa fa fa fd fd fd fd
  0x0c0e7fff99a0: fd fd fd fd fd fa fa fa fa fa fd fd fd fd fd fd
  0x0c0e7fff99b0: fd fd fd fa fa fa fa fa fd fd fd fd fd fd fd fd
  0x0c0e7fff99c0: fd fa fa fa fa fa 00 00 00 00 00 00 00 00 00 fa
  0x0c0e7fff99d0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
  Shadow gap:              cc
==14596==ABORTING
Command: out/Release/node /home/runner/work/node/node/test/node-api/test_worker_terminate_finalization/test.js
make[1]: *** [test-ci] Error 1
make: *** [run-ci] Error 2

===
=== 1 tests failed
===
Makefile:514: recipe for target 'test-ci' failed
Makefile:544: recipe for target 'run-ci' failed
Error: Process completed with exit code 2.

=== release test ===
Path: node-api/test_worker_terminate_finalization/test
Error: Command: out/Release/node /home/runner/work/node/node/test/node-api/test_worker_terminate_finalization/test.js
--- CRASHED (Signal: 11) ---

===
=== 1 tests failed
=== 1 tests CRASHED
===
make[1]: *** [test-ci] Error 1
Makefile:514: recipe for target 'test-ci' failed
make: *** [run-ci] Error 2
Makefile:544: recipe for target 'run-ci' failed
Error: Process completed with exit code 2.

• Build Links:
• https://github.com/nodejs/node/pull/36853/checks?check_run_id=1676654688
• https://github.com/nodejs/node/pull/36853/checks?check_run_id=1676654768

Refs: #34731

[Trott]

https://ci.nodejs.org/job/node-test-commit-linux-containered/nodes=ubuntu1804_sharedlibs_withoutintl_x64/24583/console

00:07:12 not ok 3043 node-api/test_worker_terminate_finalization/test
00:07:12   ---
00:07:12   duration_ms: 0.330
00:07:12   severity: crashed
00:07:12   exitcode: -11
00:07:12   stack: |-
00:07:12   ...

[Trott]

@nodejs/n-api

[mhdawson]

Does not look like the test has changed in a few months:

[mhdawson]

Don't see any recent PRs that look suspect either:

[RaisinTen]

The log seems to point to this part:

node/src/js_native_api_v8.cc

Line 367 in 03fd363

data.GetParameter()->Finalize();

Perhaps what data.GetParameter() returns is freed already?

[mhdawson]

@gabrielschulhof can you think of any recent changes that could be related?

[mhdawson]

@RaisinTen it is worth seeing what data.GetParameter() looks like. First step would be to recreate locally. I wanted to find some time to do that today but did not get to it. Have you run/recreated on your own machine?

[RaisinTen]

@mhdawson it is indeed. I didn't get time to test this locally either. I'll try it out now.

[RaisinTen]

@mhdawson just ended up running the test a 1000 times and still couldn't replicate the error. :/

[mhdawson]

@RaisinTen No recreate for me in 500 runs on RHEL 8 either.
Next going to try to run under valgrind.

[mhdawson]

Valgrind with default options does not report anything of interest:

[midawson@midawson node]$ valgrind ./node test/node-api/test_worker_terminate_finalization/test.js
==2142587== Memcheck, a memory error detector
==2142587== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==2142587== Using Valgrind-3.16.0 and LibVEX; rerun with -h for copyright info
==2142587== Command: ./node test/node-api/test_worker_terminate_finalization/test.js
==2142587== 
==2142587== 
==2142587== HEAP SUMMARY:
==2142587==     in use at exit: 6,508 bytes in 24 blocks
==2142587==   total heap usage: 53,127 allocs, 53,103 frees, 47,206,475 bytes allocated
==2142587== 
==2142587== LEAK SUMMARY:
==2142587==    definitely lost: 0 bytes in 0 blocks
==2142587==    indirectly lost: 0 bytes in 0 blocks
==2142587==      possibly lost: 304 bytes in 1 blocks
==2142587==    still reachable: 6,204 bytes in 23 blocks
==2142587==         suppressed: 0 bytes in 0 blocks
==2142587== Rerun with --leak-check=full to see details of leaked memory
==2142587== 
==2142587== For lists of detected and suppressed errors, rerun with: -s
==2142587== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)
[midawson@midawson node]$