Check failed: result.second

[richardlau]

unrelated failure in multiple different PRs?

test.node-api/test_buffer/test

#
# Fatal error in , line 0
# Check failed: result.second.
#
#
#
#FailureMessage Object: 0x3fffcd8ab3d0
 1: 0x106f06f4  [out/Release/node]
 2: 0x11b83bec V8_Fatal(char const*, ...) [out/Release/node]
 3: 0x10c4685c v8::internal::GlobalBackingStoreRegistry::Register(std::shared_ptr<v8::internal::BackingStore>) [out/Release/node]
 4: 0x1089f2c0 v8::ArrayBuffer::GetBackingStore() [out/Release/node]
 5: 0x106385f8  [out/Release/node]
 6: 0x108fb184  [out/Release/node]
 7: 0x108fd324 v8::internal::Builtin_HandleApiCall(int, unsigned long*, v8::internal::Isolate*) [out/Release/node]
 8: 0x11377680  [out/Release/node]

Not sure why you pinged build here as that's a code problem (failing check). From the stack trace and previously (#31061) that check is to with arraybuffers and backing stores. If it's occurring in multiple PR's that would suggest something has landed on master that has regressed.

Originally posted by @richardlau in #32414 (comment)

[richardlau]

Pulling this out into a separate issue for visibility.

@ronag do you have links to the failing runs? If we can isolate when it started happening it might help work out what caused it.

[ronag]

https://ci.nodejs.org/job/node-test-commit-plinux/31722/

Might be flaky. I did see it in another PR as well but can't find it at the moment.

[davedoesdev]

I'm seeing this in Node 14.1.0 if I create two Buffers (using Napi::Buffer<uint8_t>::New) pointing to the same memory (stack trace below). I'm guessing this trips the CHECK in backing-store.cc because the address is already in map_.
Allocating two external buffers pointing to the same address used to work. Is the change in behaviour expected?

#
# Fatal error in , line 0
# Check failed: result.second.
#
#
#
#FailureMessage Object: 0x7ffc13226770
 1: 0x55f12e563285  [/home/david/node/out/Release/node]
 2: 0x55f12f57d916 V8_Fatal(char const*, ...) [/home/david/node/out/Release/node]
 3: 0x55f12e99b485 v8::internal::GlobalBackingStoreRegistry::Register(std::shared_ptr<v8::internal::BackingStore>) [/home/david/node/out/Release/node]
 4: 0x55f12e6bd967 v8::ArrayBuffer::GetBackingStore() [/home/david/node/out/Release/node]
 5: 0x55f12e4c4cbb node::Buffer::New(node::Environment*, char*, unsigned long, void (*)(char*, void*), void*) [/home/david/node/out/Release/node]
 6: 0x55f12e4c4fa2 node::Buffer::New(v8::Isolate*, char*, unsigned long, void (*)(char*, void*), void*) [/home/david/node/out/Release/node]
 7: 0x55f12e4b743e napi_create_external_buffer [/home/david/node/out/Release/node]
 8: 0x7f61c8d4e062 Napi::Buffer<unsigned char>::New(napi_env__*, unsigned char*, unsigned long) [/home/david/shared-memory-disruptor/build/Debug/disruptor.node]
 9: 0x7f61c8d4d2be Napi::Buffer<unsigned char> Disruptor::ProduceClaimSync<Napi::Buffer>(Napi::Env const&, bool, unsigned long&, unsigned long&) [/home/david/shared-memory-disruptor/build/Debug/disruptor.node]
10: 0x7f61c8d4565e Disruptor::ProduceClaim(Napi::CallbackInfo const&) [/home/david/shared-memory-disruptor/build/Debug/disruptor.node]
11: 0x7f61c8d4f49d Napi::ObjectWrap<Disruptor>::InstanceMethodCallbackWrapper(napi_env__*, napi_callback_info__*)::{lambda()#1}::operator()() const [/home/david/shared-memory-disruptor/build/Debug/disruptor.node]
12: 0x7f61c8d50c02 napi_value__* Napi::details::WrapCallback<Napi::ObjectWrap<Disruptor>::InstanceMethodCallbackWrapper(napi_env__*, napi_callback_info__*)::{lambda()#1}>(Napi::ObjectWrap<Disruptor>::InstanceMethodCallbackWrapper(napi_env__*, napi_callback_info__*)::{lambda()#1}) [/home/david/shared-memory-disruptor/build/Debug/disruptor.node]
13: 0x7f61c8d4f535 Napi::ObjectWrap<Disruptor>::InstanceMethodCallbackWrapper(napi_env__*, napi_callback_info__*) [/home/david/shared-memory-disruptor/build/Debug/disruptor.node]
14: 0x55f12e49a9d8  [/home/david/node/out/Release/node]
15: 0x55f12e6f6d3f v8::internal::FunctionCallbackArguments::Call(v8::internal::CallHandlerInfo) [/home/david/node/out/Release/node]
16: 0x55f12e6f7100  [/home/david/node/out/Release/node]
17: 0x55f12e6f799a  [/home/david/node/out/Release/node]
18: 0x55f12e6f824a v8::internal::Builtin_HandleApiCall(int, unsigned long*, v8::internal::Isolate*) [/home/david/node/out/Release/node]
19: 0x55f12ef766b9  [/home/david/node/out/Release/node]

[davedoesdev]

I guess this change is intended: https://monorail-prod.appspot.com/p/v8/issues/detail?id=9908

I'll try to work around it in my addons.

[lovell]

Here are a couple of downstream issues from native modules that have been impacted by this:

• ffi-napi 2.5.0 crashes on Node 14 on macOS 10.15.4 node-ffi-napi/node-ffi-napi#71
• "Check failed: result.second" in Node 14.1 via Sharp 0.24 lovell/sharp#2196

(Anecdotally I've heard https://github.com/grpc/grpc-node is also affected, but the only issue I can find that mentions it is pulumi/pulumi#4258 (comment) .)

Suggestions for a straightforward fix or workaround for this breaking change would be greatly appreciated.

[strigona-worksight]

I have experienced issues with grpc-node as well in some early tests of node 14. I haven't circled back to gather enough info to submit an issue to the project.

[jasnell]

/cc @addaleax

[davedoesdev]

My addon has a fixed memory range so I'm able to work around this issue by making a single buffer and then calling Buffer#slice when I need to return a view onto it.
Wouldn't work for addons which dynamically allocate memory though - I guess you could keep track of what you've allocated previously and use finalizers to determine when and when not to return the same object.

[chjj]

I'm having serious issues with this. I spent a while trying to debug it and I can't seem to figure it out. I've audited my code thoroughly and concluded that it does not pass live duplicate pointers into napi_create_external_buffer. I've also valgrinded it to ensure nothing funky is happening memory-wise.

From what I can guess this is happening:

1. Addon code allocates pointer P via malloc.
2. P is passed into napi_create_external_buffer with a finalization callback which calls free(P). P is inserted into v8's global array buffer table for tracking.
3. The finalization callback is executed on GC. P is freed and returned to the allocator. P is not yet removed from v8's global array buffer table.
4. Addon code attempts to allocate memory once again. The allocator returns P, as it is now available.
5. P is passed into napi_create_external_buffer. P still has not been removed from the v8 global array buffer table.
6. The world ends with Check failed: result.second.

Step 3 seems to be the issue (again, this is just my guess at what is happening). It's been difficult trying to isolate this as it appears to be a "now you see it, now you don't" type of issue. I've come up with an offensively slow workaround. I don't consider it acceptable performance-wise.

[addaleax]

@chjj Yeah, we’ve been having a lot of trouble with this, too. This isn’t quite trivial to fix, because the API contracts for napi_create_external_buffer and the V8 BackingStore aren’t the same – you can’t run JS from the BackingStore deleter callback or necessarily even be sure on which thread it runs, but you can do that from the Node.js/N-API Buffer free callback.

I’ll try to change the behavior here by making the Buffer free callback only fire once the BackingStore deleter runs, by posting a task back to the JS thread, but that’s not necessarily trivial either.

(It’s unfortunate that we have a Buffer API in N-API at all, tbh. But that’s a mistake we can’t undo now.)

[chjj]

@addaleax, thanks for the response.

I’ll try to change the behavior here by making the Buffer free callback only fire once the BackingStore deleter runs, by posting a task back to the JS thread, but that’s not necessarily trivial either.

I see. Now that I'm understanding the issue more, I suppose the alternative would be to allow the programmer to pass two finalize callbacks: one for JS stuff, one for non-JS stuff which would execute atomically with the BackingStore deletion. That seems pretty ugly though and probably not possible to implement at this point.

(It’s unfortunate that we have a Buffer API in N-API at all, tbh. But that’s a mistake we can’t undo now.)

Would napi_create_external_arraybuffer not have this issue? Based on what you said above, I assumed it would.

I'm going through my code now and considering how to rewrite all of this.