crash in v8::ArrayBuffer::GetBackingStore

[gireeshpunathil]

steps to reprouce:

gireesh@p1:~/mq/rec1$ node -v
v14.15.4

gireesh@p1:~/mq/rec1$ cat rec.js

var ref = require('ref-napi');
var st = require('ref-struct-di')(ref);
var at = require('ref-array-di')(ref);

var rt = st({
  asid: at(ref.types.char,1024),
  os: st({ptr: ref.refType(ref.types.void)})
})

var idx = 0
const r = new rt()
r.os.ptr = Buffer.alloc(10)
setInterval(() => {
  ref.reinterpret(r.os.ptr, 0, 'utf8');
  if (++idx % 1000 === 0) console.log(`${idx}th iteration`)
  r.os.ptr = Buffer.alloc(10)
},1)

gireesh@p1:~/mq/rec1$ node rec

1000th iteration


#
# Fatal error in , line 0
# Check failed: result.second.
#
#
#
#FailureMessage Object: 0x7ffd839cc040
 1: 0xa71261  [node]
 2: 0x19d3254 V8_Fatal(char const*, ...) [node]
 3: 0xe5b549 v8::internal::GlobalBackingStoreRegistry::Register(std::shared_ptr<v8::internal::BackingStore>) [node]
 4: 0xba6a98 v8::ArrayBuffer::GetBackingStore() [node]
 5: 0x9c1be0 napi_get_typedarray_info [node]
 6: 0x7fea6e5ef0ef  [/home/gireesh/mq/rec1/node_modules/ref-napi/prebuilds/linux-x64/node.napi.node]
 7: 0x7fea6e5f15bb  [/home/gireesh/mq/rec1/node_modules/ref-napi/prebuilds/linux-x64/node.napi.node]
 8: 0x7fea6e5f7ceb Napi::details::CallbackData<void (*)(Napi::CallbackInfo const&), void>::Wrapper(napi_env__*, napi_callback_info__*) [/home/gireesh/mq/rec1/node_modules/ref-napi/prebuilds/linux-x64/node.napi.node]
 9: 0x9b8c6f  [node]
10: 0xbe571b  [node]
11: 0xbe6cc6  [node]
12: 0xbe7346 v8::internal::Builtin_HandleApiCall(int, unsigned long*, v8::internal::Isolate*) [node]
13: 0x14012d9  [node]
Illegal instruction (core dumped)
gireesh@p1:~/mq/rec1$ 

[gireeshpunathil]

I have a more elaborate stack trace, if that helps - that shows WritePointer in the stack where the backing array is required.

(lldb) bt
* thread #1, name = 'node', stop reason = signal SIGILL
  * frame #0: 0x0000000000962729 node`v8::base::OS::Abort() + 9
    frame #1: 0x00000000019d3265 node`V8_Fatal(char const*, ...) + 357
    frame #2: 0x0000000000e5b549 node`v8::internal::GlobalBackingStoreRegistry::Register(std::shared_ptr<v8::internal::BackingStore>) + 697
    frame #3: 0x0000000000ba6a98 node`v8::ArrayBuffer::GetBackingStore() + 88
    frame #4: 0x00000000009c1be0 node`napi_get_typedarray_info + 256
    frame #5: 0x00007f65a886b0ef node.napi.node`(anonymous namespace)::GetBufferData(Napi::Value) + 95
    frame #6: 0x00007f65a886d5bb node.napi.node`(anonymous namespace)::WritePointer(Napi::CallbackInfo const&) + 155
    frame #7: 0x00007f65a8873ceb node.napi.node`Napi::details::CallbackData<void (*)(Napi::CallbackInfo const&), void>::Wrapper(napi_env__*, napi_callback_info__*) + 235
    frame #8: 0x00000000009b8c6f node`v8impl::(anonymous namespace)::FunctionCallbackWrapper::Invoke(v8::FunctionCallbackInfo<v8::Value> const&) + 127
    frame #9: 0x0000000000be571b node`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) + 491
    frame #10: 0x0000000000be6cc6 node`v8::internal::Builtin_Impl_HandleApiCall(v8::internal::BuiltinArguments, v8::internal::Isolate*) + 166
    frame #11: 0x0000000000be7346 node`v8::internal::Builtin_HandleApiCall(int, unsigned long*, v8::internal::Isolate*) + 22
    frame #12: 0x00000000014012d9 node`Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_BuiltinExit + 57
    frame #13: 0x000000000139a582 node`Builtins_InterpreterEntryTrampoline + 194
    frame #14: 0x00001b9541a06435
    frame #15: 0x000000000139a582 node`Builtins_InterpreterEntryTrampoline + 194
    frame #16: 0x000000000139829a node`Builtins_JSEntryTrampoline + 90
    frame #17: 0x0000000001398078 node`Builtins_JSEntry + 120
    frame #18: 0x0000000000cc2cf1 node`v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) + 449
    frame #19: 0x0000000000cc3b5f node`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>*) + 95
    frame #20: 0x0000000000f266ab node`v8::internal::Object::SetPropertyWithAccessor(v8::internal::LookupIterator*, v8::internal::Handle<v8::internal::Object>, v8::Maybe<v8::internal::ShouldThrow>) + 347
    frame #21: 0x0000000000f469e3 node`v8::internal::Object::SetPropertyInternal(v8::internal::LookupIterator*, v8::internal::Handle<v8::internal::Object>, v8::Maybe<v8::internal::ShouldThrow>, v8::internal::StoreOrigin, bool*) + 611
    frame #22: 0x0000000000f46fb2 node`v8::internal::Object::SetProperty(v8::internal::LookupIterator*, v8::internal::Handle<v8::internal::Object>, v8::internal::StoreOrigin, v8::Maybe<v8::internal::ShouldThrow>) + 98
    frame #23: 0x0000000000dd61cf node`v8::internal::StoreIC::Store(v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Name>, v8::internal::Handle<v8::internal::Object>, v8::internal::StoreOrigin) + 575
    frame #24: 0x0000000000dd6af6 node`v8::internal::Runtime_StoreIC_Miss(int, unsigned long*, v8::internal::Isolate*) + 342
    frame #25: 0x00000000014011f9 node`Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_NoBuiltinExit + 57
    frame #26: 0x0000000001476a7e node`Builtins_StaNamedPropertyHandler + 126
    frame #27: 0x000000000139a582 node`Builtins_InterpreterEntryTrampoline + 194
    frame #28: 0x000000000139a582 node`Builtins_InterpreterEntryTrampoline + 194
    frame #29: 0x000000000139a582 node`Builtins_InterpreterEntryTrampoline + 194
    frame #30: 0x000000000139a582 node`Builtins_InterpreterEntryTrampoline + 194
    frame #31: 0x000000000139a582 node`Builtins_InterpreterEntryTrampoline + 194
    frame #32: 0x000000000139a582 node`Builtins_InterpreterEntryTrampoline + 194
    frame #33: 0x000000000139a582 node`Builtins_InterpreterEntryTrampoline + 194
    frame #34: 0x000000000139a582 node`Builtins_InterpreterEntryTrampoline + 194
    frame #35: 0x000000000139829a node`Builtins_JSEntryTrampoline + 90
    frame #36: 0x0000000001398078 node`Builtins_JSEntry + 120
    frame #37: 0x0000000000cc2cf1 node`v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) + 449
    frame #38: 0x0000000000cc3b5f node`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>*) + 95
    frame #39: 0x0000000000b8ba54 node`v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) + 324
    frame #40: 0x000000000096b347 node`node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) + 631
    frame #41: 0x000000000096b51c node`node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) + 156
    frame #42: 0x00000000009d68fb node`napi_make_callback + 875
    frame #43: 0x00007f65a8641bc0 ffi_bindings.node`FFI::FFI::FinishAsyncFFICall(uv_work_s*, int) + 288
    frame #44: 0x00000000013774ed node`uv__work_done(handle=0x000000000446c870) at threadpool.c:313:5
    frame #45: 0x000000000137bae6 node`uv__async_io.part.1 at async.c:163:5
    frame #46: 0x000000000138e5c5 node`uv__io_poll at linux-core.c:462:11
    frame #47: 0x000000000137c418 node`uv_run(loop=0x000000000446c7c0, mode=UV_RUN_DEFAULT) at core.c:385:5
    frame #48: 0x0000000000a44974 node`node::NodeMainInstance::Run() + 580
    frame #49: 0x00000000009d1e15 node`node::Start(int, char**) + 277
    frame #50: 0x00007f65ab2aa0b3 libc.so.6`__libc_start_main + 243
    frame #51: 0x00000000009694cc node`_start + 41
(lldb) 

Could this be due to gc (incorrectly) collecting the Buffer object as it is not referenced by anyone in the JS space?

[gireeshpunathil]

chatting with @mhdawson , it was revealed that an entry for the backing store was found in the global backing store registery, where it was not expecting one, is how the crash is materializing.

I am not good in interpreting the trace log of --trace-backing-store, but looking at the last entry

BS:reg bs=0x55b41104b420 mem=0x55b411217430 (length=10, capacity=10)

and searching backwards, I found a matching registration for a huge chunk:

BS:reg bs=0x55b411217450 mem=0x55b411217430 (length=1073741823, capacity=1073741823)
the backing stores are different, with capacities 1GB and 10 bytes, but they share backing_store->buffer_start() (starting address of the chunk?) there is no evidence of the large chunk being freed up yet.

[mhdawson]

After incrementally adding a bunch of instrumentation it looked be related to WritePointer being called as that seemed to be what was always on the stack when the crash occurred. (EDIT I see Gireesh pointed that out above, but I'd started down the instrumentation path before then).

In writePointer

exports.writePointer = function writePointer (buf, offset, ptr) {
  debug('writing pointer to buffer', buf, offset, ptr);
  exports._writePointer(buf, offset, ptr);
  exports._attach(buf, ptr);
};

_attach tries to avoid the buffer to which the pointer refers being freed before the buffer to which the pointer was written. However I seem to remember @addaleax mentioning that it was difficult to ensure that the cleanup for the buffer to which the pointer was written was complete before the reference buffer was freed. Currently it only ensures that both buffers become eligible to be collected and their finalizes run at the same time but does not ensure which order that will happen.

This patch will ensure that the buffer to which the pointer refers will only become eligible to be collected AFTER the finalizers for the buffer to which the pointer was written have been run. It seems to avoid the crash:

diff --git a/src/binding.cc b/src/binding.cc
index d1fefbd..2cbc5f7 100644
--- a/src/binding.cc
+++ b/src/binding.cc
@@ -355,6 +355,17 @@ void WritePointer(const CallbackInfo& args) {
   if (input.IsNull()) {
     *reinterpret_cast<char**>(ptr) = nullptr;
   } else {
+    // create a napi reference and finalizer to ensure that
+    // the buffer whoes pointer is written can only be
+    // collected after the finalizers for the buffer
+    // to which the pointer was written have already run
+    napi_ref* _ref = new napi_ref;
+    napi_create_reference(env, args[2], 1, _ref);
+    args[0].As<Object>().AddFinalizer([](Env env, napi_ref* ref) {
+      napi_delete_reference(env, *ref);
+      delete ref;
+    }, _ref);
+         
     char* input_ptr = GetBufferData(input);
     *reinterpret_cast<char**>(ptr) = input_ptr;
   }

There are other places that use _attach so this might not be the full fix, but I thought I'd post share what I've figured out so far.

[mhdawson]

Ok the same thing but using node-addon-api versus dropping down into node-api c calls:

diff --git a/src/binding.cc b/src/binding.cc
index d1fefbd..7d8906e 100644
--- a/src/binding.cc
+++ b/src/binding.cc
@@ -355,6 +355,16 @@ void WritePointer(const CallbackInfo& args) {
   if (input.IsNull()) {
     *reinterpret_cast<char**>(ptr) = nullptr;
   } else {
+    // create a node-api reference and finalizer to ensure that
+    // the buffer whoes pointer is written can only be
+    // collected after the finalizers for the buffer
+    // to which the pointer was written have already run
+    Reference<Value>* ref = new Reference<Value>;
+    *ref = Persistent(args[2]);
+    args[0].As<Object>().AddFinalizer([](Env env, Reference<Value>* ref) {
+      delete ref;
+    }, ref);
+
     char* input_ptr = GetBufferData(input);
     *reinterpret_cast<char**>(ptr) = input_ptr;
   }

I'm going to open a PR and discussion on whether it is the right fix can continue there.

[mhdawson]

Created PR: #55

[prabhatmishra33]

is my issue any relatable to this one @gireeshpunathil @mhdawson here is the issue

[mhdawson]

@prabhatmishra33 I see this on the stack in the issue you posted 6: 0x7f268814b0ef [/app/node_modules/ref-napi/prebuilds/linux-x64/node.napi.node] so its possible.

Since it's in production it might be hard to try the change in #55, but that would be the best way to confirm one way or the other.