Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

second pass phantom callback leads to infinite recursion #27577

Closed
hashseed opened this issue May 6, 2019 · 8 comments
Closed

second pass phantom callback leads to infinite recursion #27577

hashseed opened this issue May 6, 2019 · 8 comments
Labels
confirmed-bug Issues with confirmed bugs. inspector Issues and PRs related to the V8 inspector protocol v8 engine Issues and PRs related to the V8 dependency.

Comments

@hashseed
Copy link
Member

hashseed commented May 6, 2019

In my GN build, I'm observing this failure:

  • Run ./node test/parallel/test-repl-tab-complete.js
  • Observe assertion failure.
#
# Fatal error in ../../v8/src/execution.cc, line 224
# Check failed: AllowJavascriptExecution::IsAllowed(isolate).
#

The stack trace I get is this

[0 ] v8::base::OS::Abort()                                        ../../v8/src/base/platform/platform-posix.cc:400
[1 ] V8_Fatal(char const*, int, char const*, ...)                 ../../v8/src/base/logging.cc:171        
[2 ] v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) ../../v8/src/execution.cc:224           
[3 ] 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>*) ../../v8/src/execution.cc:358           
[4 ] v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) ../../v8/src/api.cc:4992                
[5 ] Emit                                                         ../../node/src/async_wrap.cc:122        
[6 ] node::AsyncWrap::EmitBefore(node::Environment*, double)      ../../node/src/async_wrap.cc:149        
[7 ] InternalCallbackScope                                        ../../node/src/api/callback.cc:65       
[8 ] InternalMakeCallback                                         ../../node/src/api/callback.cc:145      
[9 ] node::AsyncWrap::MakeCallback(v8::Local<v8::Function>, int, v8::Local<v8::Value>*) ../../node/src/async_wrap.cc:692        
[10] OnMessage                                                    ../../node/src/inspector_js_api.cc:75   
[11] SendMessageToFrontend                                        ../../node/src/inspector_js_api.cc:56   
[12] node::inspector::(anonymous namespace)::ChannelImpl::sendMessageToFrontend(v8_inspector::StringView const&) ../../node/src/inspector_agent.cc:280   
[13] node::inspector::(anonymous namespace)::ChannelImpl::sendNotification(std::__1::unique_ptr<v8_inspector::StringBuffer, std::__1::default_delete<v8_inspector::StringBuffer> >) ../../node/src/inspector_agent.cc:274   
[14] v8_inspector::V8InspectorSessionImpl::sendProtocolNotification(std::__1::unique_ptr<v8_inspector::protocol::Serializable, std::__1::default_delete<v8_inspector::protocol::Serializable> >) ../../v8/src/inspector/v8-inspector-session-impl.cc:182
[15] v8_inspector::protocol::Runtime::Frontend::executionContextDestroyed(int) gen/v8/src/inspector/protocol/Runtime.cpp:1337
[16] v8_inspector::V8RuntimeAgentImpl::reportExecutionContextDestroyed(v8_inspector::InspectedContext*) ../../v8/src/inspector/v8-runtime-agent-impl.cc:820
[17] v8_inspector::V8InspectorImpl::contextCollected(int, int)::$_1::operator()(v8_inspector::V8InspectorSessionImpl*) const ../../v8/src/inspector/v8-inspector-impl.cc:236
[18] std::__1::__invoke<v8_inspector::V8InspectorImpl::contextCollected(int, int)::$_1&, v8_inspector::V8InspectorSessionImpl*> ../../buildtools/third_party/libc++/trunk/include/type_traits:4399
[19] void std::__1::__invoke_void_return_wrapper<void>::__call<v8_inspector::V8InspectorImpl::contextCollected(int, int)::$_1&, v8_inspector::V8InspectorSessionImpl*>(v8_inspector::V8InspectorImpl::contextCollected(int, int)::$_1&, v8_inspector::V8InspectorSessionImpl*&&) ../../buildtools/third_party/libc++/trunk/include/__functional_base:348
[20] std::__1::__function::__alloc_func<v8_inspector::V8InspectorImpl::contextCollected(int, int)::$_1, std::__1::allocator<v8_inspector::V8InspectorImpl::contextCollected(int, int)::$_1>, void (v8_inspector::V8InspectorSessionImpl*)>::operator()(v8_inspector::V8InspectorSessionImpl*&&) ../../buildtools/third_party/libc++/trunk/include/functional:1531
[21] void std::__1::__function::__policy_invoker<void (v8_inspector::V8InspectorSessionImpl*)>::__call_impl<std::__1::__function::__alloc_func<v8_inspector::V8InspectorImpl::contextCollected(int, int)::$_1, std::__1::allocator<v8_inspector::V8InspectorImpl::contextCollected(int, int)::$_1>, void (v8_inspector::V8InspectorSessionImpl*)> >(std::__1::__function::__policy_storage const*, v8_inspector::V8InspectorSessionImpl*) ../../buildtools/third_party/libc++/trunk/include/functional:2014
[22] std::__1::__function::__policy_func<void (v8_inspector::V8InspectorSessionImpl*)>::operator()(v8_inspector::V8InspectorSessionImpl*&&) const ../../buildtools/third_party/libc++/trunk/include/functional:2127
[23] std::__1::function<void (v8_inspector::V8InspectorSessionImpl*)>::operator()(v8_inspector::V8InspectorSessionImpl*) const ../../buildtools/third_party/libc++/trunk/include/functional:2351
[24] v8_inspector::V8InspectorImpl::forEachSession(int, std::__1::function<void (v8_inspector::V8InspectorSessionImpl*)> const&) ../../v8/src/inspector/v8-inspector-impl.cc:392
[25] v8_inspector::V8InspectorImpl::contextCollected(int, int)    ../../v8/src/inspector/v8-inspector-impl.cc:235
[26] v8_inspector::InspectedContext::WeakCallbackData::callContextCollected(v8::WeakCallbackInfo<v8_inspector::InspectedContext::WeakCallbackData> const&) ../../v8/src/inspector/inspected-context.cc:38
[27] v8::internal::GlobalHandles::PendingPhantomCallback::Invoke(v8::internal::Isolate*, v8::internal::GlobalHandles::PendingPhantomCallback::InvocationType) ../../v8/src/global-handles.cc:1098     
[28] v8::internal::GlobalHandles::InvokeSecondPassPhantomCallbacks() ../../v8/src/global-handles.cc:968      
[29] v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) ../../v8/src/heap/heap.cc:1337          
[30] v8::internal::Heap::AllocateRawWithLightRetry(int, v8::internal::AllocationType, v8::internal::AllocationAlignment) ../../v8/src/heap/heap.cc:4514          
[31] v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationType, v8::internal::AllocationAlignment) ../../v8/src/heap/heap.cc:4528          
[32] v8::internal::Factory::AllocateRawWithImmortalMap(int, v8::internal::AllocationType, v8::internal::Map, v8::internal::AllocationAlignment) ../../v8/src/heap/factory.cc:136        
[33] v8::internal::Factory::NewRawOneByteString(int, v8::internal::AllocationType) ../../v8/src/heap/factory.cc:1000       
[34] v8::internal::Factory::NewStringFromTwoByte(unsigned short const*, int, v8::internal::AllocationType) ../../v8/src/heap/factory.cc:779        
[35] v8::internal::Factory::NewStringFromTwoByte(v8::internal::Vector<unsigned short const>, v8::internal::AllocationType) ../../v8/src/heap/factory.cc:796        
[36] v8::(anonymous namespace)::NewString(v8::internal::Factory*, v8::NewStringType, v8::internal::Vector<unsigned short const>) ../../v8/src/api.cc:6363                
[37] v8::String::NewFromTwoByte(v8::Isolate*, unsigned short const*, v8::NewStringType, int) ../../v8/src/api.cc:6428                
[38] SendMessageToFrontend                                        ../../node/src/inspector_js_api.cc:53   
[39] node::inspector::(anonymous namespace)::ChannelImpl::sendMessageToFrontend(v8_inspector::StringView const&) ../../node/src/inspector_agent.cc:280   
[40] node::inspector::(anonymous namespace)::ChannelImpl::sendNotification(std::__1::unique_ptr<v8_inspector::StringBuffer, std::__1::default_delete<v8_inspector::StringBuffer> >) ../../node/src/inspector_agent.cc:274   
[41] v8_inspector::V8InspectorSessionImpl::sendProtocolNotification(std::__1::unique_ptr<v8_inspector::protocol::Serializable, std::__1::default_delete<v8_inspector::protocol::Serializable> >) ../../v8/src/inspector/v8-inspector-session-impl.cc:182
[42] v8_inspector::protocol::Runtime::Frontend::executionContextDestroyed(int) gen/v8/src/inspector/protocol/Runtime.cpp:1337
[43] v8_inspector::V8RuntimeAgentImpl::reportExecutionContextDestroyed(v8_inspector::InspectedContext*) ../../v8/src/inspector/v8-runtime-agent-impl.cc:820
[44] v8_inspector::V8InspectorImpl::contextCollected(int, int)::$_1::operator()(v8_inspector::V8InspectorSessionImpl*) const ../../v8/src/inspector/v8-inspector-impl.cc:236
[45] std::__1::__invoke<v8_inspector::V8InspectorImpl::contextCollected(int, int)::$_1&, v8_inspector::V8InspectorSessionImpl*> ../../buildtools/third_party/libc++/trunk/include/type_traits:4399
[46] void std::__1::__invoke_void_return_wrapper<void>::__call<v8_inspector::V8InspectorImpl::contextCollected(int, int)::$_1&, v8_inspector::V8InspectorSessionImpl*>(v8_inspector::V8InspectorImpl::contextCollected(int, int)::$_1&, v8_inspector::V8InspectorSessionImpl*&&) ../../buildtools/third_party/libc++/trunk/include/__functional_base:348

I think the assertion failure is actually a red herring.

What actually happens is that during GC, we trigger a second-pass-phantom-callback. That sends a notification to the inspector, which in inspector_js_api.cc tries to allocate a string to pass that along. Only, allocating the string fails, because we are not done with GC yet. So we perform GC.

That triggers a recursion until we run out of stack, in which case things start to behave weirdly and we get this assertion failure. This weirdness does not reproduce on the regular Node build. The following patch helps with reproducing this on the regular Node build though:

diff --git a/deps/v8/src/heap/heap.cc b/deps/v8/src/heap/heap.cc
index e72269d40a..9e02bab258 100644
--- a/deps/v8/src/heap/heap.cc
+++ b/deps/v8/src/heap/heap.cc
@@ -1335,7 +1335,11 @@ bool Heap::CollectGarbage(AllocationSpace space,
   }
 
   // Ensure that all pending phantom callbacks are invoked.
-  isolate()->global_handles()->InvokeSecondPassPhantomCallbacks();
+  {
+    DCHECK(AllowHeapAllocation::IsAllowed());
+    DisallowHeapAllocation no_allocation_during_gc;
+    isolate()->global_handles()->InvokeSecondPassPhantomCallbacks();
+  }
 
   // The VM is in the GC state until exiting this function.
   VMState<GC> state(isolate());
@addaleax
Copy link
Member

addaleax commented May 6, 2019

@hashseed Just to verify – the PR description of #25992 is wrong in that the second pass callback is not a safe place to execute JS, right?

@addaleax addaleax added the inspector Issues and PRs related to the V8 inspector protocol label May 6, 2019
@hashseed
Copy link
Member Author

hashseed commented May 6, 2019

I'm wondering about this myself as well. My impression is that the second pass callback is safe to execute JS. But that could easily cause another GC, which would lead to this recursion.

@hashseed
Copy link
Member Author

hashseed commented May 6, 2019

I just cleared it up with the GC folks. The second pass callback is safe. It should run asynchronously, so that it would not lead to recursion.

Interestingly I can't reproduce this issue anymore after a clean rebuild.

@hashseed hashseed closed this as completed May 6, 2019
@addaleax
Copy link
Member

addaleax commented May 6, 2019

@hashseed I think this is a real bug, and not necessarily related to your GN build. I don’t know if it’s related to GC, but I can reproduce this with a standard Node.js debug build, but only a) consistently when run under valgrind or b) 2 out of 100 runs without valgrind.

@addaleax addaleax reopened this May 6, 2019
@addaleax addaleax added confirmed-bug Issues with confirmed bugs. v8 engine Issues and PRs related to the V8 dependency. labels May 6, 2019
@addaleax
Copy link
Member

addaleax commented May 6, 2019

Fully deterministic reproduction using a debug build:

// --gc-interval=10 --expose-gc
'use strict';
const vm = require('vm');
const inspector = require('inspector');

const session = new inspector.Session();
session.connect();
session.post('Runtime.enable');

const kContextCount = 3;  // kContextCount = 2 fails differently

let contexts = [];
for (let i = 0; i < kContextCount; i++)
  contexts.push(vm.runInNewContext('Object'));
contexts = null;

setImmediate(() => {
  global.gc();
});

I’ll try to work on a solution somewhere along these lines (but Debug builds reaaaally take forever for me so it might take a while just to confirm that it solves the issue and everything):

diff --git a/deps/v8/src/global-handles.cc b/deps/v8/src/global-handles.cc
index 350380b23ce6..58987926dc13 100644
--- a/deps/v8/src/global-handles.cc
+++ b/deps/v8/src/global-handles.cc
@@ -995,11 +995,19 @@ void GlobalHandles::InvokeSecondPassPhantomCallbacksFromTask() {
 }
 
 void GlobalHandles::InvokeSecondPassPhantomCallbacks() {
+  // The callbacks may execute JS, which in turn may lead to another GC run.
+  // If we are already processing the callbacks, we do not want to start over
+  // from within the inner GC.
+  if (running_second_pass_callbacks_) return;
+  running_second_pass_callbacks_ = true;
+
+  AllowJavascriptExecution allow_js(isolate());
   while (!second_pass_callbacks_.empty()) {
     auto callback = second_pass_callbacks_.back();
     second_pass_callbacks_.pop_back();
     callback.Invoke(isolate(), PendingPhantomCallback::kSecondPass);
   }
+  running_second_pass_callbacks_ = false;
 }
 
 size_t GlobalHandles::PostScavengeProcessing(unsigned post_processing_count) {
diff --git a/deps/v8/src/global-handles.h b/deps/v8/src/global-handles.h
index 8caa3c33ce72..f1abc9326974 100644
--- a/deps/v8/src/global-handles.h
+++ b/deps/v8/src/global-handles.h
@@ -231,6 +231,7 @@ class GlobalHandles final {
       traced_pending_phantom_callbacks_;
   std::vector<PendingPhantomCallback> second_pass_callbacks_;
   bool second_pass_callbacks_task_posted_ = false;
+  bool running_second_pass_callbacks_ = false;
 
   // Counter for recursive garbage collections during callback processing.
   unsigned post_gc_processing_count_ = 0;

@hashseed
Copy link
Member Author

hashseed commented May 7, 2019

That solution look alright to me :)

@addaleax
Copy link
Member

Finally got around to writing regression tests that reproduce this, CL is open at https://chromium-review.googlesource.com/c/v8/v8/+/1607762 :)

@evanlucas
Copy link
Contributor

evanlucas commented Apr 2, 2021

It looks like this was released in V8 7.6.173~2, which is included in >= Node 12.11.0.

Going to go ahead and close this, but feel free to re-open if closing is premature. Thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
confirmed-bug Issues with confirmed bugs. inspector Issues and PRs related to the V8 inspector protocol v8 engine Issues and PRs related to the V8 dependency.
Projects
None yet
Development

No branches or pull requests

3 participants