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.

Sign up for GitHub

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

Jump to bottom

crash when stopping next to immediates #8

Open
mcollina opened this issue Jul 26, 2022 · 1 comment · May be fixed by #9 or #10
Open

crash when stopping next to immediates #8

mcollina opened this issue Jul 26, 2022 · 1 comment · May be fixed by #9 or #10

Comments

@mcollina
Copy link 

  it('properly handles immediates when FreeEnvironment() is called on a shared event loop', async() => {
    const w = new SynchronousWorker({
      sharedEventLoop: true,
      sharedMicrotaskQueue: true
    });

    setImmediate(() => {
      console.log('first immediate')
      setImmediate(() => {
        console.log('second immediate')
        setImmediate(() => {
          console.log('third immediate');
        });
      });
    });
    await w.stop();
  });

Generates the following error:

FATAL ERROR: v8::ToLocalChecked Empty MaybeLocal.
 1: 0x104b7fedc node::Abort() [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
 2: 0x104b80064 node::ModifyCodeGenerationFromStrings(v8::Local<v8::Context>, v8::Local<v8::Value>, bool) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
 3: 0x104cd4a5c v8::api_internal::ToLocalEmpty() [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
 4: 0x104b28544 node::Environment::CheckImmediate(uv_check_s*) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
 5: 0x1054a4f48 uv__run_check [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
 6: 0x10549eca4 uv_run [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
 7: 0x109ae2314 synchronous_worker::Worker::Stop(bool) [/Users/matteo/Repositories/synchronous-worker/build/Release/synchronous_worker.node]
 8: 0x104d434d0 v8::internal::FunctionCallbackArguments::Call(v8::internal::CallHandlerInfo) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
 9: 0x104d42fcc v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<false>(v8::internal::Isolate*, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::FunctionTemplateInfo>, v8::internal::Handle<v8::internal::Object>, v8::internal::BuiltinArguments) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
10: 0x104d427f8 v8::internal::Builtin_HandleApiCall(int, unsigned long*, v8::internal::Isolate*) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
11: 0x10553518c Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_BuiltinExit [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
12: 0x1054c0198 Builtins_InterpreterEntryTrampoline [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
13: 0x10a2c8864
14: 0x1054be4d0 Builtins_JSEntryTrampoline [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
15: 0x1054be164 Builtins_JSEntry [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
16: 0x104dff164 v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
17: 0x104dfe698 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>*) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
18: 0x104ceebd8 v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
19: 0x104acd3a0 node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
20: 0x104acd774 node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
21: 0x104b28510 node::Environment::CheckImmediate(uv_check_s*) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
22: 0x1054a4f48 uv__run_check [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
23: 0x10549eca4 uv_run [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
24: 0x104acdccc node::SpinEventLoop(node::Environment*) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
25: 0x104bbaa30 node::NodeMainInstance::Run(int*, node::Environment*) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
26: 0x104bba708 node::NodeMainInstance::Run() [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
27: 0x104b531d4 node::Start(int, char**) [/Users/matteo/.nvm/versions/node/v18.6.0/bin/node]
28: 0x109b4d08c

Which I patched in Node.js with:

diff --git a/src/env.cc b/src/env.cc
index e775474306..865a012e50 100644
--- a/src/env.cc
+++ b/src/env.cc
@@ -1405,12 +1405,18 @@ void Environment::CheckImmediate(uv_check_t* handle) {
     return;

   do {
-    MakeCallback(env->isolate(),
-                 env->process_object(),
-                 env->immediate_callback_function(),
-                 0,
-                 nullptr,
-                 {0, 0}).ToLocalChecked();
+    v8::MaybeLocal<v8::Value> value = MakeCallback(env->isolate(),
+        env->process_object(),
+        env->immediate_callback_function(),
+        0,
+        nullptr,
+        {0, 0});
+    if (!value.IsEmpty()) {
+      value.ToLocalChecked();
+    }
   } while (env->immediate_info()->has_outstanding() && env->can_call_into_js());

Which generates an infinite loop that I fixed in Node.js with the following patch:

diff --git a/lib/internal/timers.js b/lib/internal/timers.js
index a2a1c1e387..d6d4a7af77 100644
--- a/lib/internal/timers.js
+++ b/lib/internal/timers.js
@@ -447,6 +447,10 @@ function getTimerCallbacks(runNextTicks) {
       // the next tick queue above, which means we need to use the previous
       // Immediate's _idleNext which is guaranteed to not have been cleared.
       if (immediate._destroyed) {
+        if (prevImmediate === undefined) {
+          outstandingQueue.head = null;
+          return
+        }
         outstandingQueue.head = immediate = prevImmediate._idleNext;
         continue;
       }
diff --git a/src/env.cc b/src/env.cc
index e775474306..865a012e50 100644
--- a/src/env.cc
+++ b/src/env.cc
@@ -1405,12 +1405,18 @@ void Environment::CheckImmediate(uv_check_t* handle) {
     return;
 
   do {
-    MakeCallback(env->isolate(),
-                 env->process_object(),
-                 env->immediate_callback_function(),
-                 0,
-                 nullptr,
-                 {0, 0}).ToLocalChecked();
+    v8::MaybeLocal<v8::Value> value = MakeCallback(env->isolate(),
+        env->process_object(),
+        env->immediate_callback_function(),
+        0,
+        nullptr,
+        {0, 0});
+    if (!value.IsEmpty()) {
+      value.ToLocalChecked();
+    }
+    printf("immediate_info()->count(): %d\n", env->immediate_info()->count());
+    printf("immediate_info()->ref_count(): %d\n", env->immediate_info()->ref_count());
+    printf("has_outstanding: %d\n", env->immediate_info()->has_outstanding());
   } while (env->immediate_info()->has_outstanding() && env->can_call_into_js());
 
   if (env->immediate_info()->ref_count() == 0)

Which unfortunately generates an 'illegal access' error with:

* thread #1, queue = 'com.apple.main-thread', stop reason = breakpoint 1.1
    frame #0: 0x0000000100351110 node`v8::internal::Isolate::ThrowIllegalOperation(this=0x0000000110028000) at isolate.cc:2270:7 [opt]
   2267 }
   2268
   2269 Object Isolate::ThrowIllegalOperation() {
-> 2270   if (FLAG_stack_trace_on_illegal) PrintStack(stdout);
   2271   return Throw(ReadOnlyRoots(heap()).illegal_access_string());
   2272 }
   2273
Target 0: (node) stopped.
(lldb) bt
* thread #1, queue = 'com.apple.main-thread', stop reason = breakpoint 1.1
  * frame #0: 0x0000000100351110 node`v8::internal::Isolate::ThrowIllegalOperation(this=0x0000000110028000) at isolate.cc:2270:7 [opt]
    frame #1: 0x000000010033d344 node`v8::internal::(anonymous namespace)::Invoke(isolate=0x0000000110028000, params=0x000000016fdfdc10)::InvokeParams const&) at execution.cc:370:14 [opt]
    frame #2: 0x000000010033c9c0 node`v8::internal::Execution::Call(isolate=0x0000000110028000, callable=<unavailable>, receiver=<unavailable>, argc=0, argv=0x0000000000000000) at execution.cc:523:10 [opt]
    frame #3: 0x0000000100225520 node`v8::Function::Call(this=0x0000000106983ac0, context=<unavailable>, recv=(val_ = 0x0000000106983ba0), argc=0, argv=0x0000000000000000) at api.cc:5255:7 [opt]
    frame #4: 0x0000000100004fc8 node`node::InternalMakeCallback(env=0x000000010695f400, resource=(val_ = 0x0000000106983ba0), recv=(val_ = 0x0000000106983ba0), callback=(val_ = 0x0000000106983ac0), argc=0, argv=0x0000000000000000, asyncContext=(async_id = 0, trigger_async_id = 0)) at callback.cc:211:21 [opt]
    frame #5: 0x00000001000052ec node`node::MakeCallback(isolate=0x0000000110028000, recv=(val_ = 0x0000000106983ba0), callback=(val_ = 0x0000000106983ac0), argc=0, argv=0x0000000000000000, asyncContext=<unavailable>) at callback.cc:282:7 [opt]
    frame #6: 0x000000010006a008 node`node::Environment::CheckImmediate(handle=<unavailable>) at env.cc:1408:39 [opt]
    frame #7: 0x0000000100a18ae0 node`uv__run_check(loop=0x0000000103a4e380) at loop-watcher.c:67:1 [opt]
    frame #8: 0x0000000100a12594 node`uv_run(loop=0x0000000103a4e380, mode=UV_RUN_ONCE) at core.c:398:5 [opt]
    frame #9: 0x000000010006a460 node`node::Environment::CleanupHandles(this=0x000000010781e000) at env.cc:1114:5 [opt]
    frame #10: 0x000000010006aa84 node`node::Environment::RunCleanup(this=0x000000010781e000) at env.cc:1165:3 [opt]
    frame #11: 0x00000001000084f0 node`node::FreeEnvironment(env=0x000000010781e000) at environment.cc:399:10 [opt]
    frame #12: 0x000000010516e358 synchronous_worker.node`synchronous_worker::Worker::Stop(this=0x0000000107832600, may_throw=<unavailable>) at binding.cc:313:5 [opt]
    frame #13: 0x000000010027c018 node`v8::internal::FunctionCallbackArguments::Call(this=0x000000016fdfe538, handler=<unavailable>) at api-arguments-inl.h:147:3 [opt]
    frame #14: 0x000000010027bb90 node`v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<false>(isolate=0x0000000110028000, function=Handle<v8::internal::HeapObject> @ x24, new_target=Handle<v8::internal::HeapObject> @ x23, fun_data=<unavailable>, receiver=Handle<v8::internal::Object> @ x20, args=BuiltinArguments @ 0x000060000399db20) at builtins-api.cc:112:36 [opt]
    frame #15: 0x000000010027b3ec node`v8::internal::Builtin_HandleApiCall(int, unsigned long*, v8::internal::Isolate*) at builtins-api.cc:142:5 [opt]
    frame #16: 0x000000010027b3d4 node`v8::internal::Builtin_HandleApiCall(args_length=<unavailable>, args_object=0x000000016fdfe6b0, isolate=0x0000000110028000) at builtins-api.cc:130:1 [opt]
    frame #17: 0x0000000100aa918c node`Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_BuiltinExit + 108
    frame #18: 0x0000000100a34198 node`Builtins_InterpreterEntryTrampoline + 248
    frame #19: 0x000000011846a44c
    frame #20: 0x0000000100a324d0 node`Builtins_JSEntryTrampoline + 176
    frame #21: 0x0000000100a32164 node`Builtins_JSEntry + 164
    frame #22: 0x000000010033d484 node`v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) [inlined] v8::internal::GeneratedCode<unsigned long, unsigned long, unsigned long, unsigned long, unsigned long, long, unsigned long**>::Call(args=<unavailable>, args=<unavailable>, args=<unavailable>, args=<unavailable>, args=<unavailable>, args=<unavailable>) at simulator.h:156:12 [opt]
    frame #23: 0x000000010033d480 node`v8::internal::(anonymous namespace)::Invoke(isolate=0x0000000110028000, params=0x000000016fdfea20)::InvokeParams const&) at execution.cc:425:33 [opt]
    frame #24: 0x000000010033c9c0 node`v8::internal::Execution::Call(isolate=0x0000000110028000, callable=<unavailable>, receiver=<unavailable>, argc=0, argv=0x0000000000000000) at execution.cc:523:10 [opt]
    frame #25: 0x0000000100225520 node`v8::Function::Call(this=0x0000000106983ac0, context=<unavailable>, recv=(val_ = 0x0000000106983ba0), argc=0, argv=0x0000000000000000) at api.cc:5255:7 [opt]
    frame #26: 0x0000000100004fc8 node`node::InternalMakeCallback(env=0x000000010695f400, resource=(val_ = 0x0000000106983ba0), recv=(val_ = 0x0000000106983ba0), callback=(val_ = 0x0000000106983ac0), argc=0, argv=0x0000000000000000, asyncContext=(async_id = 0, trigger_async_id = 0)) at callback.cc:211:21 [opt]
    frame #27: 0x00000001000052ec node`node::MakeCallback(isolate=0x0000000110028000, recv=(val_ = 0x0000000106983ba0), callback=(val_ = 0x0000000106983ac0), argc=0, argv=0x0000000000000000, asyncContext=<unavailable>) at callback.cc:282:7 [opt]
    frame #28: 0x000000010006a008 node`node::Environment::CheckImmediate(handle=<unavailable>) at env.cc:1408:39 [opt]
    frame #29: 0x0000000100a18ae0 node`uv__run_check(loop=0x0000000103a4e380) at loop-watcher.c:67:1 [opt]
    frame #30: 0x0000000100a12594 node`uv_run(loop=0x0000000103a4e380, mode=UV_RUN_DEFAULT) at core.c:398:5 [opt]
    frame #31: 0x0000000100005724 node`node::SpinEventLoop(env=0x000000010695f400) at embed_helpers.cc:37:7 [opt]
    frame #32: 0x00000001000f9a14 node`node::NodeMainInstance::Run(this=<unavailable>, exit_code=0x000000016fdff014, env=0x000000010695f400) at node_main_instance.cc:139:18 [opt]
    frame #33: 0x00000001000f96f8 node`node::NodeMainInstance::Run(this=<unavailable>) at node_main_instance.cc:131:3 [opt]
    frame #34: 0x0000000100092798 node`node::Start(argc=<unavailable>, argv=<unavailable>) at node.cc:1198:38 [opt]
    frame #35: 0x0000000104f3908c dyld`start + 520

Which I fixed by spinning the event loop for as many times as there are setImmediates:

diff --git a/src/binding.cc b/src/binding.cc
index e0ab488..ddd1f1e 100644
--- a/src/binding.cc
+++ b/src/binding.cc
@@ -300,6 +300,10 @@ void Worker::Stop(bool may_throw) {
     try_catch.SetVerbose(true);
     SealHandleScope seal_handle_scope(isolate_);
     uv_run(GetCurrentEventLoop(isolate_), UV_RUN_NOWAIT);
+    // Needed to avoid an 'illegal access' error thrown by V8
+    // This is the max number of immediates in the queue that we support.
+    uv_run(GetCurrentEventLoop(isolate_), UV_RUN_NOWAIT);
+    uv_run(GetCurrentEventLoop(isolate_), UV_RUN_NOWAIT);
   }
   if (env_ != nullptr) {
     if (!signaled_stop_) {

However the following does not look like a good fix.

Have you got any ideas?
@mcollina
Copy link
Author

Found a fix! PR coming soon.

@mcollina mcollina linked a pull request Jul 26, 2022 that will close this issue
Open
addaleax added a commit that referenced this issue Aug 19, 2022
@addaleax @mcollina
Use custom setImmediate to avoid conflict with Node.js immediate loop
1861548 
Co-authored-by: Matteo Collina <[email protected]>
Fixes: #8
Fixes: #9
@addaleax addaleax linked a pull request Aug 19, 2022 that will close this issue
Open
@RaisinTen RaisinTen mentioned this issue Oct 16, 2022
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
1 participant
@mcollina