BackingStore destruction crashes with Debug Addon

[d3x0r]

• Node.js Version: 14.4.0
• OS: Windows 10
• Scope (install, code, runtime, meta, other?): runtime, native addon
• Module (and version) (if relevant): N/A

I recently updated to node 14.4.0. (previously 14.0.0), and updated my native addon code to use BackingStore for ArrayBuffer storage; instead of a custom holder object to get a callback on weakreference deletion.

Now, when the buffers are deallocated node is crashing in the backing store destructor.

'node.exe' (Win32): Loaded 'C:\Windows\System32\dhcpcsvc.dll'. 
HEAP[node.exe]: Invalid address specified to RtlValidateHeap( 0000017399670000, 000001739C42B210 )
node.exe has triggered a breakpoint.

###################
# this is the callstack

 	ntdll.dll!00007ffa13e2ebe2()	Unknown
 	ntdll.dll!00007ffa13df3d4a()	Unknown
 	ntdll.dll!00007ffa13d95665()	Unknown
 	KernelBase.dll!00007ffa114c201b()	Unknown
 	ucrtbased.dll!00007ff9b56237d1()	Unknown
 	ucrtbased.dll!00007ff9b5621b85()	Unknown
 	ucrtbased.dll!00007ff9b56251c5()	Unknown
>	sack_gui.node!operator delete(void * block) Line 38	C++  (BLOCK = 0x000001739c42b240 )
 	sack_gui.node!operator delete(void * block, unsigned __int64 __formal) Line 32	C++
 	sack_gui.node!v8::BackingStore::`scalar deleting destructor'(unsigned int)	C++
 	sack_gui.node!std::default_delete<v8::BackingStore>::operator()(v8::BackingStore * _Ptr) Line 1762	C++

<memory>     _Mypair._Get_first()(_Mypair._Myval2);  // myVal2 == 0x000001739c42b240

 	sack_gui.node!std::_Ref_count_resource<v8::BackingStore *,std::default_delete<v8::BackingStore>>::_Destroy() Line 710	C++
 	node.exe!00007ff6b04cf0e0()	Unknown


// this is logged when the backing store is allocated.  (backing store, my buf, mybuf length)
// (time)|(threadId)~(source(line)):(msg)
// this is allocated in the main thread.
08:36:48.782|4B0000004658~vfs_module.cc(887):Backing store:000000692457E300 000001739B3981A8 278

// This is logged when I get the callback to delete my data in the buffer.
// (here all I get is mybuf, and length avaialble to log)
// this is closed in a background thread
08:36:48.851|4B0000004AE0~vfs_module.cc(806):Backing store:000001739B3981A8 278

before returning from the destructor and after calling the release callback, BackingStore delete thinks its releasing an invalid pointer.   The value of the pointer it is releasing is the one it asked for...

// other threads are doing things at the same time...  (4658 is the main thread)
// logged after my deallocate logging; and before the breakpoint in the delete...

08:36:48.851|4B0000004658~sharemem.cpp(2213): jsox_parser.cpp(2255): Release 00000173999CE0F0(00000173999CE104)
08:37:22.993|4B0000004AE0~sharemem.cpp(2213):vfs_module.cc(807): Release 000001739B398190(000001739B3981A4)
08:37:22.993|4B0000004658~sharemem.cpp(2213): jsox_parser.cpp(2255): Release 000001739C48CCB0(000001739C48CCC4)

This is the address of the backing store... 
000000692457E300

Which is quite far from the space I'm allocating from 
00000173999CE104
So I doubt I would have been able to overwrite anything spuriously.

nodejs/node-v8#115 shows a very similar crash; and I am using worker-threads; although no threads have exited....

[addaleax]

@d3x0r I don’t think there’s an easy way to debug this without having a reproduction or knowing your addon better.

If you can’t share more information, I think your only route is to go build a debug build of Node.js, and use node --trace-backing-store to get a better idea over what’s going on.

[d3x0r]

says bad option --trace-backing-store

Edit:

M:\javascript\FFFFFR>C:\\Users\\d3x0r\\AppData\\Roaming\\npm\\node_modules\\node\\bin\\node.exe --version
v14.4.0
M:\javascript\FFFFFR>C:\\Users\\d3x0r\\AppData\\Roaming\\npm\\node_modules\\node\\bin\\node.exe --trace-backing-store
C:\Users\d3x0r\AppData\Roaming\npm\node_modules\node\bin\node.exe: bad option: --trace-backing-store

[addaleax]

@d3x0r Yeah, you need a debug build in order for that option to be available, i.e. you need to build Node.js from source with debugging enabled – that takes quite a while, unfortunately

[d3x0r]

I checked out 14.4.0 (so the plugin API would be the same) and built the debug version. It(V14.4 Debug) does not demonstrate the same issue. It(V14.4 Debug) does generate more errors on some of my casts of arguments to functions, but having 'fixed' a few of those, it(v14.4Release) still does the same thing, and crashes.
M:\node\Debug\node.exe

BS:free   bs=0000018F9F822F70 mem=0000018F9DCF8940 (length=13871, capacity=13871)
BS:custome deleter bs=0000018F9F823C90 mem=0000018F9D967D18 (length=2926, capacity=2926)
10:42:48.869|1C7C000055D8~vfs_module.cc(806):Backing store:0000018F9D967D18 2926
10:42:48.869|1C7C000055D8~sharemem.cpp(2213): M:\javascript\sack-gui\src\vfs_module.cc(807): Release 0000018F9D967D00(0000018F9D967D14)
BS:free   bs=0000018F9F825270 mem=0000018F9DCA2C10 (length=32, capacity=32)
BS:custome deleter bs=0000018F9F823BB0 mem=0000018F9DD10F08 (length=34306, capacity=34306)
10:42:48.871|1C7C000055D8~vfs_module.cc(806):Backing store:0000018F9DD10F08 34306
10:42:48.871|1C7C000055D8~sharemem.cpp(2213): M:\javascript\sack-gui\src\vfs_module.cc(807): Release 0000018F9DD10EF0(0000018F9DD10F04)
BS:custome deleter bs=0000018F9F8264D0 mem=0000018F9DF54618 (length=278, capacity=278)
10:42:48.872|1C7C000055D8~vfs_module.cc(806):Backing store:0000018F9DF54618 278
10:42:48.873|1C7C000055D8~sharemem.cpp(2213): M:\javascript\sack-gui\src\vfs_module.cc(807): Release 0000018F9DF54600(0000018F9DF54614)
BS:free   bs=0000018F9F826150 mem=0000018F9DCA48F0 (length=32, capacity=32)
BS:free   bs=0000018F9F827F80 mem=0000018F9DCA5C10 (length=32, capacity=32)
BS:free   bs=0000018F9F826AF0 mem=0000018F9DCA7E30 (length=32, capacity=32)
BS:free   bs=0000018F9F829870 mem=0000018F9DCA9B10 (length=32, capacity=32)
BS:free   bs=0000018F9F829100 mem=0000018F9DCA7C50 (length=32, capacity=32)

[d3x0r]

So; What I'm actually assuming is that this BackingStore class seems to be a static reference in my addon code, and that is built against a debug runtime, whereas node is built as a release runtime and somehow the backing store allocate and free are not calling the correct pair of functions; but rather is allocating release and releasing debug.

[addaleax]

@d3x0r So … does the problem go away when you build your addon in Release config for a Node.js binary in Release config? 😬 That would seem like a pretty severe bug with Node.js to me…

[d3x0r]

I'm using ArrayBuffer::NewBackingStore( buf, len, releaseBufferBackingStore, NULL ); to get the store, so that's a release allocation, but the delete is definitely happening in my module...
And yes; release module and release node is not an issue :(

[addaleax]

@d3x0r I see … we have an issue on ARM that might resemble yours: nodejs/node#30786 – tl;dr: On ARMv7 and ARMv6, std::shared_ptr does not have the same internals.

Maybe that’s what happening here as well? Maybe std::shared_ptr has a different object layout in debug mode? I don’t really know where MSVC keeps the headers that are shipped with a compiler, but taking a look at those might clear things up…

[d3x0r]

Ya... that's not going to help for windows. There are release and debug runtimes (ucrt and ucrtd basically) so even if the front end structures are the same, the end up calling a different runtime.

https://gist.github.com/d3x0r/f201f197ab017b643dcb941481b1bca4 This is a simple test. There is a 'download zip' button... although you can also just clone it git clone https://gist.github.com/d3x0r/f201f197ab017b643dcb941481b1bca4 testBackingStore

[d3x0r]

I cannot test/develop with only release mode code... how do I fix the debug allocator to not crash when releasing a backing store created by node and released by my library? (since node is release of course so it's using a different allocator than the one that gets linked)

I wonder why the decision to use some native (unportable) pointer container instead of any of the existing ones V8 uses...

Oh right; I was supposed to build a debug node and have everything take a long time to run...

[gireeshpunathil]

not sure if these are related, but linking those anyways: node-ffi-napi/ref-napi#54

[d3x0r]

This is more when the backing store is garbage collected than on the creation of the backing store.

[gireeshpunathil]

in your trace output, can you search and find out whether the backing store that has come up for deletion has a duplicate entry? that would indicate whether another entry came and got deleted gracefully, and in that process the current one also got deleted, due to matching keys?

[d3x0r]

I'm certain that only one was ever created so it certainly only exists once. This is mixed runtimes on visual studio (debug vs release) or msvcrtd.dll vs msvcrt.dll (ucrt); if Node is compiled with release runtime, than the allocator between ucrtd and ucrt are not compatible, and the release happens in the addon's linked runtime, and is allocated internal to node in release runtime.

[d3x0r]

This seems to not be an issue in V16, so seems is just v12-v14 (15?)

[d3x0r]

Since V16 this has not been an issue.