DCHECK crash on !i_isolate->is_execution_terminating()

@targos

https://chromium-review.googlesource.com/c/v8/v8/+/3620285

was merged recently and causes a ton of failures in a variety of tests (~50 or so, parallel/test-worker-esm-exit as an example):

#
# Fatal error in ../../v8/src/api/api.cc, line 8345
# Debug check failed: !i_isolate->is_execution_terminating().
#
#
#
#FailureMessage Object: 0x700007e04e90
 1: 0x12e68e672 node::NodePlatform::GetStackTracePrinter()::$_3::__invoke() [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 2: 0x12ae43306 V8_Fatal(char const*, int, char const*, ...) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 3: 0x12ae42da5 v8::base::(anonymous namespace)::DefaultDcheckHandler(char const*, int, char const*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 4: 0x1263561c5 v8::Integer::NewFromUnsigned(v8::Isolate*, unsigned int) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 5: 0x12e568a24 node::InternalCallbackScope::Close()::$_1::operator()() const [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 6: 0x12e568843 node::InternalCallbackScope::Close() [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 7: 0x12e56826e node::InternalCallbackScope::~InternalCallbackScope() [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 8: 0x12e6183f4 node::fs::FileHandle::CloseReq::Resolve() [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 9: 0x12e62d7d9 node::fs::FileHandle::ClosePromise()::$_0::__invoke(uv_fs_s*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
10: 0x1248ab378 uv__work_done [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
11: 0x1248af2eb uv__async_io [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
12: 0x1248c21b8 uv__io_poll [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
13: 0x1248af705 uv_run [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
14: 0x12e65b25f node::SpinEventLoop(node::Environment*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
15: 0x12e6cff7f node::worker::Worker::Run() [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
16: 0x12e6d3543 node::worker::Worker::StartThread(v8::FunctionCallbackInfo<v8::Value> const&)::$_3::__invoke(void*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
17: 0x7ff80b5ad4e1 _pthread_start [/usr/lib/system/libsystem_pthread.dylib]
18: 0x7ff80b5a8f6b thread_start [/usr/lib/system/libsystem_pthread.dylib]
Command: /Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/MacOS/Electron /Users/codebytere/Developer/electron-gn/src/third_party/electron_node/test/parallel/test-worker-esm-exit.js
--- CRASHED (Signal: 5) ---
[00:00|% 100|+   0|-   1]: Done

I initially attempted to fix by adding in early returns in various places:

diff --git a/src/api/callback.cc b/src/api/callback.cc
index 1287eb466f..7ca10e35e7 100644
--- a/src/api/callback.cc
+++ b/src/api/callback.cc
@@ -102,6 +102,7 @@ void InternalCallbackScope::Close() {
 
   if (!env_->can_call_into_js()) return;
   auto perform_stopping_check = [&]() {
+    if (isolate->IsExecutionTerminating()) return;
     if (env_->is_stopping()) {
       MarkAsFailed();
       env_->async_hooks()->clear_async_id_stack();

but it ended up being a bit of a whac-a-mole game with new ones appearing with every early return I added so i'm not sure what the best approach is.

cc @targos and @camillobruni since you opened the CL :)

Thanks for opening this. It also affect V8 10.3: nodejs/node#43195 (comment)

Sorry for the inconvenience here :/.

I think V8 has been a bit too lenient on this in the past (and it led to a bunch of issues within chrome).
The general idea is really that you don't use V8 anymore after marking it for termination, and I'm aware of how painful it can be to track down those issues.

I think having simple accessors still available would make sense (and it might well be that I totally missed a use case present in node).

Example in CI: https://ci.nodejs.org/job/node-test-commit-arm-debug/2497/nodes=ubuntu1804-arm64/

Problematic code: https://github.com/nodejs/node/blob/6ac55fa337b57cecf36602d0acc3da25ee82a589/src/env-inl.h#L222-L237

/cc @nodejs/async_hooks

Adding if (env()->can_call_into_js()) { around this code solves the async hooks problem but it seems there are other similar places where JS code is called but no longer allowed.

@addaleax

@addaleax @jasnell @Qard, maybe you might want to chime in on this?

Adding if (env()->can_call_into_js()) { around this code solves the async hooks problem

I’m not sure what else to do besides doing this and being consistent about this.

Problem seems to be the perform_stopping_check() lambda in callback.cc Close method. It tries to clean up async_hooks reactively to the env stopping, but at that point it's no longer safe to create the HandleScope for setting the length field on js_execution_async_resources_. If the env is already in shutdown, it should be safe to just skip that though. 🤔

I suspect we're going to need to just play that game of whack-a-mole to get any of those post-shutdown stuff filtered out.

Alright - i can spin up a PR for that soon then!

Hey 👋

I tried to reproduce the bug, but I struggled a bit as I'm fairly new to the codebase.

I have two questions:

Should we checkout a specific branch to reproduce it? (like targos:v8-103)
How could we run a single test file like parallel/test-worker-esm-exit? The documentation points out make jstest but it executes all the tests. Maybe I miss it somewhere?

@tony-go

@tony-go tests can be run as a rule with just the node executable, so out/Debug/node /path/to/test/file. If you do want to use the test runner, you can also just do python3 tools/test.py test/parallel/test-worker-esm-exit.js (i personally prefer using the runner since it allows for much more customization)

@codebytere

Thanks, @codebytere 🙌

Finally found this: https://github.com/nodejs/node/blob/main/BUILDING.md#running-tests

@Flarna

@Flarna hmm - that's strange since theres a can_call_into_js() immediately prior: https://github.com/nodejs/node/blob/6932fb8bac3a4caf3f3fabee0a595a077f477f63/src/api/callback.cc#L103

There's a bunch of places within that function that the state can transition though, which is why it checks it several times. Probably another place it needs a check now or something...it's a complicated bit of code. 😐

@codebytere

@codebytere It's a while that I had this in my debugger so can't remember in detail. But as far as I remmeber it's as @Qard said the state changes after that check you refer to.

I know the microtask queue bits change it briefly. Forget if there were other cases, but basically these callback scopes can end up nested within each other and that can have some unexpected side effects if not handled carefully.

Here's the latest canary CI run in debug mode (green): https://ci.nodejs.org/job/node-test-commit-arm-debug/4183/nodes=ubuntu1804-arm64/

Maybe these crashes are only reproducible within Electron?

src: avoid using v8 on Isolate termination

Looks like it 🤔 at least, it looks like it's specific to embedded Node.js and i haven't been able to repro it on your canary branch

Tracked it down to https://github.com/electron/node/blob/3e6b3b22c5f687e170944a1cef51caa41a4caea1/src/node_task_queue.cc#L142-L143 - it's causing this error:

#
# Fatal error in ../../v8/src/execution/microtask-queue.cc, line 182
# Debug check failed: maybe_result.is_null().
#
#
#
#FailureMessage Object: 0x16d4f8b48
 1: 0x11e947804 node::NodePlatform::GetStackTracePrinter()::$_3::__invoke() [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 2: 0x11b8bbb74 V8_Fatal(char const*, int, char const*, ...) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 3: 0x11b8bb818 std::Cr::enable_if<!std::is_function<std::Cr::remove_pointer<unsigned char>::type>::value && !std::is_enum<unsigned char>::value && has_output_operator<unsigned char, v8::base::CheckMessageStream>::value, std::Cr::basic_string<char, std::Cr::char_traits<char>, std::Cr::allocator<char>>>::type v8::base::PrintCheckOperand<unsigned char>(unsigned char) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 4: 0x117ccfad4 v8::internal::MicrotaskQueue::RunMicrotasks(v8::internal::Isolate*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 5: 0x117ccf414 v8::internal::MicrotaskQueue::PerformCheckpointInternal(v8::Isolate*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 6: 0x11e8b4b14 node::loader::ModuleWrap::Evaluate(v8::FunctionCallbackInfo<v8::Value> const&) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 7: 0x117a45bd0 v8::internal::FunctionCallbackArguments::Call(v8::internal::CallHandlerInfo) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 8: 0x117a443e0 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::FunctionTemplateInfo>, v8::internal::Handle<v8::internal::Object>, unsigned long*, int) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
 9: 0x117a42754 v8::internal::Builtin_Impl_HandleApiCall(v8::internal::BuiltinArguments, v8::internal::Isolate*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
10: 0x117a420d4 v8::internal::Builtin_HandleApiCall(int, unsigned long*, v8::internal::Isolate*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
11: 0x12407ea510c
12: 0x12407e0fbe4
13: 0x12407e0fbe4
14: 0x12407e4b3a0
15: 0x12407f13a28
16: 0x12407e39024
17: 0x12407e0d7e8
18: 0x117c85224 v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
19: 0x117c8673c v8::internal::(anonymous namespace)::InvokeWithTryCatch(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
20: 0x117c86e28 v8::internal::Execution::TryRunMicrotasks(v8::internal::Isolate*, v8::internal::MicrotaskQueue*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
21: 0x117ccf6b0 v8::internal::MicrotaskQueue::RunMicrotasks(v8::internal::Isolate*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
22: 0x117ccf414 v8::internal::MicrotaskQueue::PerformCheckpointInternal(v8::Isolate*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
23: 0x117a45bd0 v8::internal::FunctionCallbackArguments::Call(v8::internal::CallHandlerInfo) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
24: 0x117a443e0 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::FunctionTemplateInfo>, v8::internal::Handle<v8::internal::Object>, unsigned long*, int) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
25: 0x117a42754 v8::internal::Builtin_Impl_HandleApiCall(v8::internal::BuiltinArguments, v8::internal::Isolate*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
26: 0x117a420d4 v8::internal::Builtin_HandleApiCall(int, unsigned long*, v8::internal::Isolate*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
27: 0x12407ea510c
28: 0x12407e0fbe4
29: 0x12407e0d90c
30: 0x12407e0d5a8
31: 0x117c851d8 v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
32: 0x117c842e0 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/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
33: 0x11798f3c0 v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
34: 0x11e84f554 node::InternalCallbackScope::Close() [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
35: 0x11e84f1ac node::InternalCallbackScope::~InternalCallbackScope() [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
36: 0x11e88f7ec node::StartExecution(node::Environment*, std::Cr::function<v8::MaybeLocal<v8::Value> (node::StartExecutionCallbackInfo const&)>) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
37: 0x11e8514a4 node::LoadEnvironment(node::Environment*, std::Cr::function<v8::MaybeLocal<v8::Value> (node::StartExecutionCallbackInfo const&)>) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
38: 0x11673ffd0 electron::NodeMain(int, char**) [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
39: 0x116566e1c ElectronInitializeICUandStartNode [/Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Electron Framework]
40: 0x102ca5088
Command: /Users/codebytere/Developer/electron-gn/src/out/Testing/Electron.app/Contents/MacOS/Electron --experimental-vm-modules /Users/codebytere/Developer/electron-gn/src/third_party/electron_node/test/sequential/test-vm-timeout-escape-promise-module-2.js
--- CRASHED (Signal: 5) ---

@santigimeno

@santigimeno i determined it's related to v8::Isolate::SafeForTerminationScope, which i think is missing somewhere for nested microtasks. Electron starts Node.js with only_terminate_in_safe_scope set to true, which triggers this error after https://chromium-review.googlesource.com/c/chromium/src/+/3620285

also cc @addaleax since this appears specific to timeouts with microtaskMode: 'afterEvaluate' and i also see you added nodejs/node#36344 to handle SIGINT interruptions. Any pointers would be appreciated 🙇🏻‍♀️

src: avoid using v8 on Isolate termination

Navigation Menu

DCHECK crash on `!i_isolate->is_execution_terminating()` #227

11 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

DCHECK crash on !i_isolate->is_execution_terminating() #227

Description

Activity

targos commented on May 31, 2022

camillobruni commented on May 31, 2022

targos commented on Jun 20, 2022

Flarna commented on Jun 20, 2022

mcollina commented on Aug 10, 2022

addaleax commented on Aug 10, 2022

Qard commented on Aug 10, 2022

codebytere commented on Aug 11, 2022

tony-go commented on Aug 21, 2022

codebytere commented on Aug 22, 2022

tony-go commented on Aug 22, 2022

codebytere commented on Aug 22, 2022

Qard commented on Aug 22, 2022

Flarna commented on Aug 28, 2022

Qard commented on Aug 28, 2022

11 remaining items

targos commented on Sep 26, 2022

codebytere commented on Sep 27, 2022

codebytere commented on Oct 3, 2022

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions

DCHECK crash on `!i_isolate->is_execution_terminating()` #227