Taking snapshot crashes Worker thread when taken during bootstrap

[trevnorris]

• Version: v14.15.4, v15.6.0, 13ac5fb (master)
• Platform: Linux 5.8.0-7630-generic x86_64
• Subsystem: worker_threads

What steps will reproduce the bug?

Run this code with a debug build of node:

const { Worker, isMainThread } = require('worker_threads');

if (!isMainThread)
  require('v8').getHeapSnapshot();
else
  new Worker(__filename);

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

Every time with a debug build.

What is the expected behavior?

To not crash.

What do you see instead?

The process aborts. Here is the backtrace from v14.15.4 using gdb:

#0  v8::internal::ScopeInfo::FunctionContextSlotIndex (this=0x7ffff5235998, name=...) at ../deps/v8/src/objects/scope-info.cc:938
#1  0x0000000001af258d in v8::internal::V8HeapExplorer::ExtractContextReferences (this=0x7ffff5235b98, entry=0x7fffe82c4cf8, context=...) at ../deps/v8/src/profiler/heap-snapshot-generator.cc:993
#2  0x0000000001af6041 in v8::internal::V8HeapExplorer::IterateAndExtractReferences (this=0x7ffff5235b98, generator=<optimized out>) at ../deps/v8/src/profiler/heap-snapshot-generator.cc:1533
#3  0x0000000001af834e in v8::internal::HeapSnapshotGenerator::FillReferences (this=0x7ffff5235b80) at ../deps/v8/src/profiler/heap-snapshot-generator.cc:2147
#4  v8::internal::HeapSnapshotGenerator::GenerateSnapshot (this=0x7ffff5235b80) at ../deps/v8/src/profiler/heap-snapshot-generator.cc:2111
#5  0x0000000001ae80c6 in v8::internal::HeapProfiler::TakeSnapshot (this=0x7fffe812f200, control=<optimized out>, resolver=<optimized out>, treat_global_objects_as_roots=<optimized out>) at ../deps/v8/src/profiler/heap-profiler.cc:75
#6  0x0000000000fdbbde in node::heap::CreateHeapSnapshotStream (args=...) at ../src/heap_utils.cc:360
#7  0x00000000014369f5 in v8::internal::FunctionCallbackArguments::Call (this=0x7ffff5235eb0, handler=...) at ../deps/v8/src/api/api-arguments-inl.h:158
#8  0x000000000143545e in v8::internal::(anonymous namespace)::HandleApiCallHelper<false> (isolate=<optimized out>, function=..., new_target=..., fun_data=..., receiver=..., args=...) at ../deps/v8/src/builtins/builtins-api.cc:111
#9  0x0000000001433c0a in v8::internal::Builtin_Impl_HandleApiCall (args=..., isolate=0x7fffe8000d40) at ../deps/v8/src/builtins/builtins-api.cc:141
#10 0x0000000001433758 in v8::internal::Builtin_HandleApiCall (args_length=5, args_object=0x7ffff5236050, isolate=0x7fffe8000d40) at ../deps/v8/src/builtins/builtins-api.cc:129
#11 0x000000000229e000 in Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_BuiltinExit ()
#12 0x00000000020497a4 in Builtins_InterpreterEntryTrampoline ()

For some reason lldb gives a drastically different backtrace:

 * thread #8: tid = 1762687, 0x00000000018d70be node`v8::internal::ScopeInfo::FunctionContextSlotIndex(v8::internal::String) const [inlined] v8::base::Relaxed_Load(ptr=0xffffffffffffffff) at atomicops_internals_portable.h:189:10, name = 'node', stop reason = signal SIGSEGV: invalid address (fault address: 0xffffffffffffffff)
  * frame #0: 0x00000000018d70be node`v8::internal::ScopeInfo::FunctionContextSlotIndex(v8::internal::String) const [inlined] v8::base::Relaxed_Load(ptr=0xffffffffffffffff) at atomicops_internals_portable.h:189:10
    ...
    frame #12: 0x0000000001970ef6 node`v8::internal::HeapProfiler::TakeSnapshot(this=0x00007fffe40b6510, control=<unavailable>, resolver=<unavailable>, treat_global_objects_as_roots=<unavailable>) at heap-profiler.cc:75:20
    ...
    frame #19: 0x0000000001e8abe2 getHeapSnapshot(this=0x1ca3665d56c1:<Object: Object>) at v8.js:1:10 fn=0x00001ca3665d15a1
    ...
    frame #22: 0x0000000001e8abe2 Module._extensions..js(this=0x1ca3665cbe59:<Object: Object>, 0x1ca3665cfe41:<Object: Module>, 0x5d2937ff151:<String: "/tmp/snapshot-cr...">) at internal/modules/cjs/loader.js:1:10 fn=0x000005d2937f59b1
    ...
    frame #36: 0x0000000000e77e61 node`node::AsyncWrap::MakeCallback(this=0x00007fffe4122800, cb=(val_ = 0x00007fffe401e1f0), argc=2, argv=0x00007ffff5237f40) at async_wrap.cc:954:27
    frame #37: 0x0000000001005f80 node`node::worker::MessagePort::OnMessage(this=0x00007fffe4122800) at node_messaging.cc:775:9
    frame #38: 0x00000000010097f8 node`node::worker::MessagePort::MessagePort(this=0x00007fffe4122868, handle=0x00007fffe4122868)::$_1::operator()(uv_async_s*) const at node_messaging.cc:589:14
    frame #39: 0x00000000010097b5 node`node::worker::MessagePort::MessagePort(handle=0x00007fffe4122868)::$_1::__invoke(uv_async_s*) at node_messaging.cc:586:20
    frame #40: 0x0000000001e50ebc node`uv__async_io(loop=0x00007ffff523b900, w=0x00007ffff523bac8, events=1) at async.c:163:5
    frame #41: 0x0000000001e6c418 node`uv__io_poll(loop=0x00007ffff523b900, timeout=0) at linux-core.c:462:11
    frame #42: 0x0000000001e514dd node`uv_run(loop=0x00007ffff523b900, mode=UV_RUN_DEFAULT) at core.c:385:5
    frame #43: 0x00000000010bf289 node`node::worker::Worker::Run(this=0x00000000058da570) at node_worker.cc:347:11
    frame #44: 0x00000000010c1cfd node`node::worker::Worker::StartThread(this=0x00000000058da570, arg=0x00000000058da570)::$_3::operator()(void*) const at node_worker.cc:623:8

Additional information

This does not crash in v12.20.1.

I've also written a native module and called the C++ API directly from both the same thread and using an interrupt from a different thread. As long as the call is made during node::worker::Worker::StartThread() the process will crash.

It's also possible to crash the process when taking the snapshot from a different thread. Here's an example:

const { Worker, isMainThread, parentPort } = require('worker_threads');

if (!isMainThread) {
  parentPort.postMessage('hi');
  while (true);
} else {
  const worker = new Worker(__filename);
  worker.once('message', () => {
    require('v8').getHeapSnapshot();
    process.exit();
  });
}

It also crashes if the inspector API is used:

const { Worker, isMainThread, threadId, parentPort } =
  require('worker_threads');

if (!isMainThread) {
  parentPort.postMessage('hi');
  const t = Date.now();
  while (Date.now() - t < 100);
  return;
}

const inspector = require('inspector');
const session = new inspector.Session();
session.on('HeapProfiler.addHeapSnapshotChunk', (m) => { });
session.connect();

const worker = new Worker(__filename);
worker.once('message', (msg) => {
  session.post('HeapProfiler.takeHeapSnapshot', null, (err, r) => { });
});

[targos]

The crash comes from this DCHECK:

node/deps/v8/src/objects/scope-info.cc

Line 938 in 258d77a

DCHECK(name.IsInternalizedString());

[targos]

/cc @nodejs/workers

[trevnorris]

@targos Thanks. You brought to my attention that for some reason lldb and gdb are giving very different backtraces. I've updated the OP with both, just for reference.

[bgalek]

Hi, this problem also affects node v16

[melanholly]

I have The same issue in the main process of nodejs. I do not use worker threads but when I try to create a heap snapshot on windows in nodejs 14.17.3 the process crashes with this stack

:000> kp
 # Child-SP          RetAddr               Call Site
00 (Inline Function) --------`--------     node!v8::internal::TaggedImpl<1,unsigned __int64>::operator==(void) [c:\ws\deps\v8\src\objects\tagged-impl.h @ 48] 
01 (Inline Function) --------`--------     node!v8::internal::Object::IsUndefined(void) [c:\ws\deps\v8\src\objects\objects-inl.h @ 117] 
02 (Inline Function) --------`--------     node!v8::internal::HeapObject::IsUndefined(void) [c:\ws\deps\v8\src\objects\objects-inl.h @ 117] 
03 (Inline Function) --------`--------     node!v8::internal::HeapObject::IsUndefined(void)+0x9 [c:\ws\deps\v8\src\objects\objects-inl.h @ 117] 
04 (Inline Function) --------`--------     node!v8::internal::Context::has_extension(void)+0x2a [c:\ws\deps\v8\src\objects\contexts-inl.h @ 99] 
05 00000063`3ad1e760 00007ff6`26dffbcf     node!v8::internal::V8HeapExplorer::ExtractContextReferences(class v8::internal::HeapEntry * entry = 0x0000024e`53f81810, class v8::internal::Context context = class v8::internal::Context)+0x190 [c:\ws\deps\v8\src\profiler\heap-snapshot-generator.cc @ 1000] 
06 00000063`3ad1e7e0 00007ff6`26e01a5a     node!v8::internal::V8HeapExplorer::ExtractReferences(class v8::internal::HeapEntry * entry = 0x0000024e`53f81810, class v8::internal::HeapObject obj = class v8::internal::HeapObject)+0x4df [c:\ws\deps\v8\src\profiler\heap-snapshot-generator.cc @ 811] 
07 00000063`3ad1e830 00007ff6`26e006e0     node!v8::internal::V8HeapExplorer::IterateAndExtractReferences(class v8::internal::HeapSnapshotGenerator * generator = <Value unavailable error>)+0x32a [c:\ws\deps\v8\src\profiler\heap-snapshot-generator.cc @ 1517] 
08 (Inline Function) --------`--------     node!v8::internal::HeapSnapshotGenerator::FillReferences(void)+0xc [c:\ws\deps\v8\src\profiler\heap-snapshot-generator.cc @ 2094] 
09 00000063`3ad1e9d0 00007ff6`26e07de0     node!v8::internal::HeapSnapshotGenerator::GenerateSnapshot(void)+0x120 [c:\ws\deps\v8\src\profiler\heap-snapshot-generator.cc @ 2058] 
0a 00000063`3ad1ea40 00007ff6`2692af85     node!v8::internal::HeapProfiler::TakeSnapshot(class v8::ActivityControl * control = 0x00000000`00000000, class v8::HeapProfiler::ObjectNameResolver * resolver = 0x00000000`00000000, bool treat_global_objects_as_roots = true)+0x80 [c:\ws\deps\v8\src\profiler\heap-profiler.cc @ 75] 
0b 00000063`3ad1ec50 00007ff6`2716f2df     node!node::heap::CreateHeapSnapshotStream(class v8::FunctionCallbackInfo<v8::Value> * args = 0x00000063`3ad1eca0)+0x75 [c:\ws\src\heap_utils.cc @ 359] 
0c 00000063`3ad1ec80 00007ff6`2716e874     node!v8::internal::FunctionCallbackArguments::Call(class v8::internal::CallHandlerInfo handler = <Value unavailable error>)+0x14f [c:\ws\deps\v8\src\api\api-arguments-inl.h @ 159] 
0d 00000063`3ad1ed20 00007ff6`2716eb68     node!v8::internal::`anonymous namespace'::HandleApiCallHelper<0>(class v8::internal::Isolate * isolate = 0x0000024e`509f1d40, class v8::internal::Handle<v8::internal::HeapObject> function = class v8::internal::Handle<v8::internal::HeapObject>, class v8::internal::Handle<v8::internal::HeapObject> new_target = class v8::internal::Handle<v8::internal::HeapObject>, class v8::internal::Handle<v8::internal::FunctionTemplateInfo> fun_data = class v8::internal::Handle<v8::internal::FunctionTemplateInfo>, class v8::internal::Handle<v8::internal::Object> receiver = class v8::internal::Handle<v8::internal::Object>, class v8::internal::BuiltinArguments * args = 0x00000063`3ad1ee80)+0x254 [c:\ws\deps\v8\src\builtins\builtins-api.cc @ 113] 
0e 00000063`3ad1ee40 00007ff6`2716e9b3     node!v8::internal::Builtin_Impl_HandleApiCall(class v8::internal::BuiltinArguments * args = 0x00000063`3ad1eef0, class v8::internal::Isolate * isolate = 0x0000024e`509f1d40)+0x108 [c:\ws\deps\v8\src\builtins\builtins-api.cc @ 141] 
0f 00000063`3ad1eed0 00007ff6`2724b35d     node!v8::internal::Builtin_HandleApiCall(int args_length = <Value unavailable error>, unsigned int64 * args_object = <Value unavailable error>, class v8::internal::Isolate * isolate = <Value unavailable error>)+0x33 [c:\ws\deps\v8\src\builtins\builtins-api.cc @ 129] 
10 00000063`3ad1ef10 00007ff6`271e3722     node!Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_BuiltinExit(void)+0x3d [c:\ws\out\Release\obj\v8_snapshot\embedded.S @ 14831] 
11 00000063`3ad1ef60 00007ff6`271e3722     node!Builtins_InterpreterEntryTrampoline(void)+0xc2 [c:\ws\out\Release\obj\v8_snapshot\embedded.S @ 1225] 
12 00000063`3ad1efc8 00007ff6`271e3722     node!Builtins_InterpreterEntryTrampoline(void)+0xc2 [c:\ws\out\Release\obj\v8_snapshot\embedded.S @ 1225] 
13 00000063`3ad1f030 00007ff6`271dd359     node!Builtins_InterpreterEntryTrampoline(void)+0xc2 [c:\ws\out\Release\obj\v8_snapshot\embedded.S @ 1225] 
14 00000063`3ad1f0b0 000000d9`882d7aee     node!Builtins_ArgumentsAdaptorTrampoline(void)+0xb9 [c:\ws\out\Release\obj\v8_snapshot\embedded.S @ 343] 
15 00000063`3ad1f0f0 000000d9`882d45e0     0x000000d9`882d7aee
16 00000063`3ad1f1a0 00007ff6`271e13de     0x000000d9`882d45e0
17 00000063`3ad1f1f8 00007ff6`271e0fcc     node!Builtins_JSEntryTrampoline(void)+0x5e [c:\ws\out\Release\obj\v8_snapshot\embedded.S @ 934] 
18 00000063`3ad1f228 00007ff6`270b0be2     node!Builtins_JSEntry(void)+0xcc [c:\ws\out\Release\obj\v8_snapshot\embedded.S @ 895] 
19 (Inline Function) --------`--------     node!v8::internal::GeneratedCode<unsigned __int64,unsigned __int64,unsigned __int64,unsigned __int64,unsigned __int64,__int64,unsigned __int64 * *>::Call(int64 <args_4> = <Value unavailable error>)+0x16 [c:\ws\deps\v8\src\execution\simulator.h @ 142] 
1a 00000063`3ad1f340 00007ff6`270b044f     node!v8::internal::`anonymous namespace'::Invoke(class v8::internal::Isolate * isolate = 0x00000063`3ad1ef80, struct v8::internal::`anonymous-namespace'::InvokeParams * params = 0x000001ff`c16004a1)+0x482 [c:\ws\deps\v8\src\execution\execution.cc @ 369] 
1b 00000063`3ad1f450 00007ff6`2719c567     node!v8::internal::Execution::Call(class v8::internal::Isolate * isolate = 0x0000024e`509f1d40, class v8::internal::Handle<v8::internal::Object> callable = <Value unavailable error>, class v8::internal::Handle<v8::internal::Object> receiver = <Value unavailable error>, int argc = 0n1, class v8::internal::Handle<v8::internal::Object> * argv = 0x00000063`3ad1f680)+0xbf [c:\ws\deps\v8\src\execution\execution.cc @ 463] 
1c 00000063`3ad1f520 00007ff6`2694364c     node!v8::Function::Call(class v8::Local<v8::Context> context = <Value unavailable error>, class v8::Local<v8::Value> recv = class v8::Local<v8::Value>, int argc = 0n1, class v8::Local<v8::Value> * argv = 0x00000063`3ad1f680)+0x267 [c:\ws\deps\v8\src\api\api.cc @ 4875] 
1d 00000063`3ad1f650 00007ff6`269a53c4     node!node::Environment::RunTimers(struct uv_timer_s * handle = 0x0000024e`50a0bd78)+0x1cc [c:\ws\src\env.cc @ 841] 
1e 00000063`3ad1f790 00007ff6`269a1b42     node!uv__run_timers(struct uv_loop_s * loop = 0x00007ff6`29eecd70)+0x74 [c:\ws\deps\uv\src\timer.c @ 178] 
1f 00000063`3ad1f7c0 00007ff6`268a2bf5     node!uv_run(struct uv_loop_s * loop = 0x00007ff6`29eecd70, uv_run_mode mode = UV_RUN_DEFAULT (0n0))+0xc2 [c:\ws\deps\uv\src\win\core.c @ 609] 
20 00000063`3ad1f840 00007ff6`269170f7     node!node::NodeMainInstance::Run(void)+0x155 [c:\ws\src\node_main_instance.cc @ 132] 
21 00000063`3ad1f8d0 00007ff6`2677679c     node!node::Start(int argc = <Value unavailable error>, char ** argv = <Value unavailable error>)+0x137 [c:\ws\src\node.cc @ 1102] 
22 00000063`3ad1fa60 00007ff6`27740de8     node!wmain(int argc = 0n4, wchar_t ** wargv = 0x0000024e`5099da40)+0x1cc [c:\ws\src\node_main.cc @ 87] 
23 (Inline Function) --------`--------     node!invoke_main(void)+0x22 [d:\agent\_work\4\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 90] 
24 00000063`3ad1fc20 00007ffd`0c4f7034     node!__scrt_common_main_seh(void)+0x10c [d:\agent\_work\4\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 288] 
25 00000063`3ad1fc60 00007ffd`0c8a2651     kernel32!BaseThreadInitThunk+0x14
26 00000063`3ad1fc90 00000000`00000000     ntdll!RtlUserThreadStart+0x21

[sgallagher]

Possible duplicate: Red Hat Bugzilla #1992976

[richardlau]

I don't know if it's related but we've seen one instance of a crash in test-worker-take-heapsnapshot on master with a failed assertion about locks #39686

09:20:32     FATAL ERROR: HandleScope::HandleScope Entering the V8 API without proper locking in place

[benasher44]

Not sure if it's helpful, but me nor anyone else on my team is able to take heap snapshots in our app in node 14.16+ (up to latest node 14). Attached the crashlog. We're able to reliably reproduce it.

node_2021-08-18-091610_Bens-MacBook-Pro.crash.zip