`ObjectWrap` destructors run after `CleanupHook`

[mmomtchev]

Version

16.17.0

Platform

Ubuntu 20.04

Subsystem

napi

What steps will reproduce the bug?

Having ObjectWrap objects when destroying the environment. May be related to having stale Persistent objects.

How often does it reproduce? Is there a required condition?

Always

What is the expected behavior?

All C++ objects are destroyed before the CleanupHook

What do you see instead?

This is the stack trace

pymport-native.node!Napi::ObjectWrap<pymport::PyObj>::FinalizeCallback(napi_env env, void * data) (/home/mmom/src/pymport/node_modules/node-addon-api/napi-inl.h:4597)
v8impl::RefBase::Finalize(bool) (Unknown Source:0)
node_napi_env__::~node_napi_env__() (Unknown Source:0)
node::Environment::RunCleanup() (Unknown Source:0)
node::FreeEnvironment(node::Environment*) (Unknown Source:0)
node::NodeMainInstance::Run() (Unknown Source:0)
node::Start(int, char**) (Unknown Source:0)
libc.so.6!__libc_start_main(int (*)(int, char **, char **) main, int argc, char ** argv, int (*)(int, char **, char **) init, void (*)(void) fini, void (*)(void) rtld_fini, void * stack_end) (/build/glibc-SzIz7B/glibc-2.31/csu/libc-start.c:308)
_start (Unknown Source:0)

Additional information

No response

[juanarbol]

cc @nodejs/node-api

[legendecas]

Currently, the document only defines that cleanup hooks are run in a reversed order, but no words on if the cleanup hooks are run before any other finalizers. As the status quo, all cleanup hooks are run before the finalizers, regardless of their registration order, as the napi_env's own cleanup is registered before the registration of any addon's cleanup hooks.

I believe it would be more reasonable to run cleanup hooks after pending finalizers are drained. After the cleanup hooks are invoked, there should be no callbacks can calling into the addon again.

[KevinEady]

Hi @legendecas , could this issue also be related to TSFN "release in ObjectWrap destructor" crash stacktraces we are seeing in nodejs/node-addon-api#1109?

[legendecas]

@KevinEady thanks for the link. At first sight, it seems like a finalization order problem too. I'll take a look at both issues.

[mmomtchev]

This is still the case in the latest Node 25, git checkout.

I see that the cleanup hooks are now explicitly sorted and run in reverse order.

However the problem is that my own module cleanup hook is registered after the cleanup hook of Node API itself - and this is the hook that runs the remaining destructors.

Look at the attached traces (git checkout from today).

I am working with a library that requires creating a context - which I do when the module is initialised - and destroying it on shutdown - which I do in a cleanup hook. Obviously, I am not supposed to continue destroying objects after I have destroyed the context.

I have instrumented the adding and calling of cleanup hooks in Node itself as well as the creation/destruction of the context and the individual object destructors.

We need some official way to solve this problem. This will certainly be a very common issue.

node(84587,0x1f327a200) malloc: nano zone abandoned due to inability to reserve vm space.
add cleanup hook, counter 0
add cleanup hook, counter 1
PROJ context register cleanup hook for instance_data 0x610000029a40 context 0x615000055080 tid 0x1f327a200
add cleanup hook, counter 2
will call cleanup hook 2
calling cleanup hook 2
PROJ instance_data 0x610000029a40 context 0x615000055080 destroyed tid 0x1f327a200
calling cleanup hook 2 done
will call cleanup hook 1
calling cleanup hook 1
destroying object in instance 0x610000029a40, tid 0x1f327a200
destroying object in instance 0x610000029a40, tid 0x1f327a200
destroying object in instance 0x610000029a40, tid 0x1f327a200
destroying object in instance 0x610000029a40, tid 0x1f327a200
destroying object in instance 0x610000029a40, tid 0x1f327a200
destroying object in instance 0x610000029a40, tid 0x1f327a200
destroying object in instance 0x610000029a40, tid 0x1f327a200
destroying object in instance 0x610000029a40, tid 0x1f327a200
destroying object in instance 0x610000029a40, tid 0x1f327a200
destroying object in instance 0x610000029a40, tid 0x1f327a200
=================================================================
==84587==ERROR: AddressSanitizer: heap-use-after-free on address 0x615000055098 at pc 0x0001372bc9f0 bp 0x00016ddc6080 sp 0x00016ddc6078
READ of size 4 at 0x615000055098 thread T0
    #0 0x0001372bc9ec in proj_context_errno 4D_api.cpp:2405
    #1 0x0001372affe4 in proj_errno 4D_api.cpp:2394
    #2 0x0001372f1a58 in proj_destroy malloc.cpp:108
    #3 0x000137068420 in jsPJ::~jsPJ() capi_wrap.cc:1164
    #4 0x0001370683c0 in jsPJ::~jsPJ() capi_wrap.cc:1164
    #5 0x000137068040 in _exports_PJ_templ<_exports_PJ_inst>::~_exports_PJ_templ() capi_wrap.cc:3497
    #6 0x000137068460 in _exports_PJ_inst::~_exports_PJ_inst() capi_wrap.cc:1876
    #7 0x000137066d24 in _exports_PJ_inst::~_exports_PJ_inst() capi_wrap.cc:1876
    #8 0x000137066d50 in _exports_PJ_inst::~_exports_PJ_inst() capi_wrap.cc:1876
    #9 0x0001370677b0 in Napi::ObjectWrap<_exports_PJ_inst>::FinalizeCallback(napi_env__*, void*, void*) napi-inl.h:5224
    #10 0x0001020f7014 in void napi_env__::CallIntoModule<void node_napi_env__::CallFinalizer<true>(void (*)(napi_env__*, void*, void*), void*, void*)::'lambda'(napi_env__*)&, void node_napi_env__::CallbackIntoModule<true, void node_napi_env__::CallFinalizer<true>(void (*)(napi_env__*, void*, void*), void*, void*)::'lambda'(napi_env__*)>(void node_napi_env__::CallFinalizer<true>(void (*)(napi_env__*, void*, void*), void*, void*)::'lambda'(napi_env__*)&&)::'lambda'(napi_env__*, v8::Local<v8::Value>)>(void node_napi_env__::CallFinalizer<true>(void (*)(napi_env__*, void*, void*), void*, void*)::'lambda'(napi_env__*)&, void node_napi_env__::CallFinalizer<true>(void (*)(napi_env__*, void*, void*), void*, void*)::'lambda'(napi_env__*)&&) js_native_api_v8.h:93
    #11 0x000104258a20 in void node_napi_env__::CallFinalizer<true>(void (*)(napi_env__*, void*, void*), void*, void*) node_api.cc:96
    #12 0x0001020d2908 in v8impl::Reference::Finalize() js_native_api_v8.cc:735
    #13 0x0001020f2950 in node_napi_env__::DeleteMe() node_api.cc:81
    #14 0x00010206babc in node::CleanupQueue::Drain() cleanup_queue.cc:41
    #15 0x0001020bd7e4 in node::Environment::RunCleanup() env.cc:1337
    #16 0x0001042301fc in node::FreeEnvironment(node::Environment*) environment.cc:538
    #17 0x0001021732f0 in node::NodeMainInstance::Run() node_main_instance.cc:101
    #18 0x0001020ef8ac in node::Start(int, char**) node.cc:1574
    #19 0x000184f46b94 in start+0x17b8 (dyld:arm64e+0xfffffffffff3ab94)

0x615000055098 is located 24 bytes inside of 464-byte region [0x615000055080,0x615000055250)
freed by thread T0 here:
    #0 0x00010a4cf82c in _ZdlPv+0x74 (libclang_rt.asan_osx_dynamic.dylib:arm64e+0x4b82c)
    #1 0x0001372bd0c4 in proj_context_destroy 4D_api.cpp:2490
    #2 0x0001372aa468 in Init(Napi::Env, Napi::Object)::$_0::operator()() const capi_wrap.cc:46997
    #3 0x0001372aa0a4 in Napi::BasicEnv::CleanupHook<Init(Napi::Env, Napi::Object)::$_0, void>::Wrapper(void*) napi-inl.h:697
    #4 0x00010206babc in node::CleanupQueue::Drain() cleanup_queue.cc:41
    #5 0x0001020bd7e4 in node::Environment::RunCleanup() env.cc:1337
    #6 0x0001042301fc in node::FreeEnvironment(node::Environment*) environment.cc:538
    #7 0x0001021732f0 in node::NodeMainInstance::Run() node_main_instance.cc:101
    #8 0x0001020ef8ac in node::Start(int, char**) node.cc:1574
    #9 0x000184f46b94 in start+0x17b8 (dyld:arm64e+0xfffffffffff3ab94)

previously allocated by thread T0 here:
    #0 0x00010a4cf644 in _ZnwmRKSt9nothrow_t+0x74 (libclang_rt.asan_osx_dynamic.dylib:arm64e+0x4b644)
    #1 0x0001372bcfc0 in proj_context_create 4D_api.cpp:2478
    #2 0x000136f800f0 in Init(Napi::Env, Napi::Object) capi_wrap.cc:46975
    #3 0x0001370205b0 in Napi::RegisterModule(napi_env__*, napi_value__*, Napi::Object (*)(Napi::Env, Napi::Object))::'lambda'()::operator()() const napi-inl.h:551
    #4 0x0001370201fc in napi_value__* Napi::details::WrapCallback<Napi::RegisterModule(napi_env__*, napi_value__*, Napi::Object (*)(Napi::Env, Napi::Object))::'lambda'()>(napi_env__*, Napi::RegisterModule(napi_env__*, napi_value__*, Napi::Object (*)(Napi::Env, Napi::Object))::'lambda'()) napi-inl.h:89
    #5 0x0001370200fc in Napi::RegisterModule(napi_env__*, napi_value__*, Napi::Object (*)(Napi::Env, Napi::Object)) napi-inl.h:549
    #6 0x000136faa78c in __napi_Init(napi_env__*, napi_value__*) capi_wrap.cc:50617
    #7 0x000136faa758 in napi_register_module_v1 capi_wrap.cc:50617
    #8 0x0001020f2d30 in napi_module_register_by_symbol(v8::Local<v8::Object>, v8::Local<v8::Value>, v8::Local<v8::Context>, napi_value__* (*)(napi_env__*, napi_value__*), int) node_api.cc:769
    #9 0x0001020f9a88 in std::__1::__function::__func<node::binding::DLOpen(v8::FunctionCallbackInfo<v8::Value> const&)::$_0, std::__1::allocator<node::binding::DLOpen(v8::FunctionCallbackInfo<v8::Value> const&)::$_0>, bool (node::binding::DLib*)>::operator()(node::binding::DLib*&&) function.h:319
    #10 0x0001020ba564 in node::Environment::TryLoadAddon(char const*, int, std::__1::function<bool (node::binding::DLib*)> const&) env.cc:722
    #11 0x000104259f28 in node::binding::DLOpen(v8::FunctionCallbackInfo<v8::Value> const&) node_binding.cc:473
    #12 0x00010302f234 in Builtins_CallApiCallbackGeneric+0x94 (node:arm64+0x100ff7234)
    #13 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #14 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #15 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #16 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #17 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #18 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #19 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #20 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #21 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #22 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #23 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #24 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #25 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #26 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #27 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #28 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)
    #29 0x00010302d588 in Builtins_InterpreterEntryTrampoline+0x108 (node:arm64+0x100ff5588)

SUMMARY: AddressSanitizer: heap-use-after-free 4D_api.cpp:2405 in proj_context_errno
Shadow bytes around the buggy address:
  0x615000054e00: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x615000054e80: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x615000054f00: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x615000054f80: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x615000055000: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
=>0x615000055080: fd fd fd[fd]fd fd fd fd fd fd fd fd fd fd fd fd
  0x615000055100: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x615000055180: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x615000055200: fd fd fd fd fd fd fd fd fd fd fa fa fa fa fa fa
  0x615000055280: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x615000055300: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
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
==84587==ABORTING
zsh: abort      ../node/node test/shared/quickstart-capi.debug.js

[mmomtchev]

Maybe the destructors should be run in a separate cleanup hook to be registered after the module has finished its initialisation.