Segfault Creating Node Environments in v12.16.2

[frutiger]

• Version: 12.16.2
• Platform: Darwin 18.7.0 (macOS 10.14.6)
• Subsystem: Node C++ API

What steps will reproduce the bug?

I have a program that manages its own V8 Isolate, UV Event Loop and Node Environments. In Node 12.13.1, it was possible to initialize a V8 Platform via node::InitializeV8Platform(...) that would provide all that was expected of Node Contexts. I am trying to upgrade to Node 12.16.2, but this function was removed in d77a1b0.

I am looking for a minimal example that allows successful creation of a Node Environment object. To reproduce:

1. Checkout v12.16.2
2. Do a configure then make
3. Create this sample program named test.cc (I omitted cleanup for brevity):

// test.cc
#include <node.h>
#include <uv.h>
#include <v8.h>
#include <libplatform/libplatform.h>

int main()
{
    auto platform = v8::platform::NewDefaultPlatform();
    v8::V8::InitializePlatform(platform.get());

    v8::V8::Initialize();

    v8::Isolate::CreateParams isolateParams;
    isolateParams.array_buffer_allocator =
        v8::ArrayBuffer::Allocator::NewDefaultAllocator();

    auto *isolate = v8::Isolate::Allocate();
    v8::Isolate::Initialize(isolate, isolateParams);
    v8::HandleScope scope(isolate);

    auto *isolateData = node::CreateIsolateData(isolate, uv_default_loop());

    v8::Global<v8::Context> context(isolate, node::NewContext(isolate));

    auto *environment = node::CreateEnvironment(isolateData,
                                                context.Get(isolate),
                                                0, nullptr,
                                                0, nullptr);
}

4. Compile with the following command (assuming you cloned the repo to the current directory):

$ c++ -g -std=c++17 -Inode/{src,deps/v8/include,deps/uv} test.cc -lv8_libplatform -lv8_libbase -rpath node/out/Release -Lnode/out/Release -lnode.72

5. Run the program in lldb; you should see the following segfault:

* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1, address=0x490)
  * frame #0: 0x000000010039265b libnode.72.dylib`node::tracing::TraceEventHelper::GetTracingController() [inlined] std::__1::unique_ptr<node::tracing::TracingController, std::__1::default_delete<node::tracing::TracingController> >::get(this=<unavailable>) const at memory:2621:19 [opt]
    frame #1: 0x000000010039265b libnode.72.dylib`node::tracing::TraceEventHelper::GetTracingController() [inlined] node::tracing::Agent::GetTracingController(this=0x0000000000000000) at agent.h:90 [opt]
    frame #2: 0x000000010039265b libnode.72.dylib`node::tracing::TraceEventHelper::GetTracingController() at trace_event.cc:17 [opt]
    frame #3: 0x0000000100340024 libnode.72.dylib`node::performance::performance_state::Mark(this=<unavailable>, milestone=NODE_PERFORMANCE_MILESTONE_ENVIRONMENT, ts=821035848887086) at node_perf.cc:50:3 [opt]
    frame #4: 0x00000001002a09a7 libnode.72.dylib`node::Environment::Environment(this=0x0000000105003200, isolate_data=0x0000000107824a00, context=<unavailable>, args=size=0, exec_args=<unavailable>, flags=7, thread_id=18446744073709551615) at env.cc:353:23 [opt]
    frame #5: 0x000000010026fe1b libnode.72.dylib`node::CreateEnvironment(isolate_data=<unavailable>, context=<unavailable>, argc=<unavailable>, argv=0x0000000000000000, exec_argc=<unavailable>, exec_argv=<unavailable>) at environment.cc:307:26 [opt]
    frame #6: 0x000000010000159a a.out`main at test.cc:25:25
    frame #7: 0x00007fff5dfb93d5 libdyld.dylib`start + 1

This is happening because the tracing controller has not been set; as far as I can see, this is only possible to set via the public APIs using a method such as node::Start, but that is not very friendly for programs that wish to create multiple environments. It's very likely that I have missed something in how to properly create these environments, any pointers are appreciated.

---

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

This should be a universal issue when attempting to create environments against Node v12.16.2.

What is the expected behavior?

I would expect the environment to be created, and the context to be usable to execute JavaScript.

What do you see instead?

A segmentation fault.

[bnoordhuis]

this function was removed in d77a1b0

fe1ac49, the preceding commit, cleans up the code base to handle a nullptr TracingController.

It's possible I missed something or that something went wrong during back-porting. However, EXC_BAD_ACCESS (code=1, address=0x490) suggests it's not tracing_controller_ but g_agent that's nullptr:

node/src/tracing/trace_event.cc

Lines 16 to 18 in 3443e3a

	TracingController* TraceEventHelper::GetTracingController() {
	return g_agent->GetTracingController();
	}

Can you check if it works for you when you rewrite that method to this?

TracingController* TraceEventHelper::GetTracingController() {
  if (g_agent == nullptr) return nullptr;
  return g_agent->GetTracingController();
}

[frutiger]

That gets a bit further but crashes when accessing the tracing controller

(lldb) run
Process 86888 launched: '/Users/masud/node-env/a.out' (x86_64)
libnode.72.dylib was compiled with optimization - stepping may behave oddly; variables may not be available.
Process 86888 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1, address=0x0)
    frame #0: 0x0000000100340024 libnode.72.dylib`node::performance::performance_state::Mark(this=<unavailable>, milestone=NODE_PERFORMANCE_MILESTONE_ENVIRONMENT, ts=822061714079593) at node_perf.cc:50:3 [opt]
   47  	void performance_state::Mark(enum PerformanceMilestone milestone,
   48  	                             uint64_t ts) {
   49  	  this->milestones[milestone] = ts;
-> 50  	  TRACE_EVENT_INSTANT_WITH_TIMESTAMP0(
   51  	      TRACING_CATEGORY_NODE1(bootstrap),
   52  	      GetPerformanceMilestoneName(milestone),
   53  	      TRACE_EVENT_SCOPE_THREAD, ts / 1000);
Target 0: (a.out) stopped.
(lldb) thr backt
* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1, address=0x0)
  * frame #0: 0x0000000100340024 libnode.72.dylib`node::performance::performance_state::Mark(this=<unavailable>, milestone=NODE_PERFORMANCE_MILESTONE_ENVIRONMENT, ts=822061714079593) at node_perf.cc:50:3 [opt]
    frame #1: 0x00000001002a09a7 libnode.72.dylib`node::Environment::Environment(this=0x0000000120034a00, isolate_data=0x0000000120022a00, context=<unavailable>, args=size=0, exec_args=<unavailable>, flags=7, thread_id=18446744073709551615) at env.cc:353:23 [opt]
    frame #2: 0x000000010026fe1b libnode.72.dylib`node::CreateEnvironment(isolate_data=<unavailable>, context=<unavailable>, argc=<unavailable>, argv=0x0000000000000000, exec_argc=<unavailable>, exec_argv=<unavailable>) at environment.cc:307:26 [opt]
    frame #3: 0x000000010000159a a.out`main at test.cc:25:25
    frame #4: 0x00007fff5dfb93d5 libdyld.dylib`start + 1

[addaleax]

I think

node/src/tracing/trace_event.h

Lines 490 to 494 in 278aae2

	v8::TracingController* controller =
	node::tracing::TraceEventHelper::GetTracingController();
	return controller->AddTraceEventWithTimestamp(
	phase, category_group_enabled, name, scope, id, bind_id, num_args,
	arg_names, arg_types, arg_values, arg_convertables, flags, timestamp);

would need a nullptr check, along with a number of other places in the tracing code.

I’ll put a PR together, but if you are looking for a somewhat straightforward workaround, you should be able to create a NodePlatform instance instead of the v8::platform::NewDefaultPlatform(), which should work here (along the lines of what is documented in https://nodejs.org/api/embedding.html).

[addaleax]

@frutiger Can you try this patch and see if it works for you?

diff --git a/src/tracing/trace_event.h b/src/tracing/trace_event.h
index be2276a9e276..2a79c5bc05b5 100644
--- a/src/tracing/trace_event.h
+++ b/src/tracing/trace_event.h
@@ -70,8 +70,7 @@ enum CategoryGroupEnabledFlags {
 // const uint8_t*
 //     TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(const char* category_group)
 #define TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED              \
-  node::tracing::TraceEventHelper::GetTracingController()       \
-      ->GetCategoryGroupEnabled
+  node::tracing::TraceEventHelper::GetCategoryGroupEnabled
 
 // Get the number of times traces have been recorded. This is used to implement
 // the TRACE_EVENT_IS_NEW_TRACE facility.
@@ -115,9 +114,10 @@ enum CategoryGroupEnabledFlags {
 //     const uint8_t* category_group_enabled,
 //     const char* name,
 //     uint64_t id)
-#define TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION             \
-  node::tracing::TraceEventHelper::GetTracingController()       \
-      ->UpdateTraceEventDuration
+#define TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION                           \
+  if (auto controller =                                                       \
+         node::tracing::TraceEventHelper::GetTracingController())             \
+      controller->UpdateTraceEventDuration
 
 // Adds a metadata event to the trace log. The |AppendValueAsTraceFormat| method
 // on the convertable value will be called at flush time.
@@ -319,6 +319,13 @@ class NODE_EXTERN TraceEventHelper {
 
   static Agent* GetAgent();
   static void SetAgent(Agent* agent);
+
+  static inline const uint8_t* GetCategoryGroupEnabled(const char* group) {
+    v8::TracingController* controller = GetTracingController();
+    static const uint8_t disabled = 0;
+    if (UNLIKELY(controller == nullptr)) return &disabled;
+    return controller->GetCategoryGroupEnabled(group);
+  }
 };
 
 // TraceID encapsulates an ID that can either be an integer or pointer. Pointers
@@ -467,6 +474,7 @@ static inline uint64_t AddTraceEventImpl(
   // DCHECK(num_args, 2);
   v8::TracingController* controller =
       node::tracing::TraceEventHelper::GetTracingController();
+  if (controller == nullptr) return 0;
   return controller->AddTraceEvent(phase, category_group_enabled, name, scope, id,
                                    bind_id, num_args, arg_names, arg_types,
                                    arg_values, arg_convertibles, flags);
@@ -489,6 +497,7 @@ static V8_INLINE uint64_t AddTraceEventWithTimestampImpl(
   // DCHECK_LE(num_args, 2);
   v8::TracingController* controller =
       node::tracing::TraceEventHelper::GetTracingController();
+  if (controller == nullptr) return 0;
   return controller->AddTraceEventWithTimestamp(
       phase, category_group_enabled, name, scope, id, bind_id, num_args,
       arg_names, arg_types, arg_values, arg_convertables, flags, timestamp);

[addaleax]

Also, based on #28724 Electron has run into this problem as well, so it might make sense to provide an official API for explicitly setting the TracingController* manually.

[frutiger]

@frutiger Can you try this patch and see if it works for you?

Thanks @addaleax that seems to work for me. I had to tweak the patch a tiny bit as it did not cleanly apply on v12.16.2 3443e3a, but otherwise it worked (along with the patch from @bnoordhuis).

Would this make sense to include in a release, or should I patch my builds of NodeJS?

[addaleax]

@frutiger Great! I’ve opened a PR: #33815