Assertion `(env_->execution_async_id()) == (0)' failed

I managed to trigger an assertion.

undici$ node --version
v15.13.0

test/client-connect.js 2> /Users/ronagy/.nvm/versions/node/v15.13.0/bin/node[49832]: ../src/api/callback.cc:125:void node::InternalCallbackScope::Close(): Assertion `(env_->execution_async_id()) == (0)' failed.
test/client-connect.js 2>  1: 0x1013990c5 node::Abort() (.cold.1) [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2>  2: 0x1000c6c89 node::Abort() [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2>  3: 0x1000c6af1 node::Assert(node::AssertionInfo const&) [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2>  4: 0x100001cdd node::InternalCallbackScope::Close() [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2>  5: 0x10000228a 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/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2>  6: 0x10001a7e8 node::AsyncWrap::MakeCallback(v8::Local<v8::Function>, int, v8::Local<v8::Value>*) [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2>  7: 0x100183821 node::StreamBase::CallJSOnreadMethod(long, v8::Local<v8::ArrayBuffer>, unsigned long, node::StreamBase::StreamBaseJSChecks) [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2>  8: 0x100185787 node::EmitToJSStreamListener::OnStreamRead(long, uv_buf_t const&) [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2>  9: 0x10018a61b node::LibuvStreamWrap::OnUvRead(long, uv_buf_t const*) [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2> 10: 0x100a63a8e uv__stream_io [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2> 11: 0x100a6c45c uv__io_poll [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2> 12: 0x100a58d51 uv_run [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2> 13: 0x100002e74 node::SpinEventLoop(node::Environment*) [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2> 14: 0x100107a64 node::NodeMainInstance::Run(node::EnvSerializeInfo const*) [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2> 15: 0x1000949c4 node::Start(int, char**) [/Users/ronagy/.nvm/versions/node/v15.13.0/bin/node]
test/client-connect.js 2> 16: 0x7fff20386621 start [/usr/lib/system/libdyld.dylib]

@addaleax

@addaleax is this supposed to be possible?

@ronag

@ronag no, hence the assertion

@ronag

@ronag Do you have a reproducer? I doubt this happens just by calling node --version :o)

Sorry. Happened while debugging another issue and haven’t happened since.

@Flarna

@Flarna @addaleax If you clone this https://github.com/nodejs/undici/tree/native-assert and run tap test/tls-session-reuse.js you should get the assertion.

I did a fast try but failed to reproduce the crash. Should it happen always or only every now and then?
Any dependecy to nodejs version or OS?

Node v15.5.1, OSX 11.2.3.

It should happen every time.

Stack trace on my mac:

/Users/targos/git/nodejs/node/out/Debug/node[16113]: ../../src/api/callback.cc:125:void node::InternalCallbackScope::Close(): Assertion `(env_->execution_async_id()) == (0)' failed.
 1: 0x1024e3b38 node::DumpBacktrace(__sFILE*) [/Users/targos/git/nodejs/node/out/Debug/node]
 2: 0x10262bf90 node::Abort() [/Users/targos/git/nodejs/node/out/Debug/node]
 3: 0x10262bc18 node::AppendExceptionLine(node::Environment*, v8::Local<v8::Value>, v8::Local<v8::Message>, node::ErrorHandlingMode) [/Users/targos/git/nodejs/node/out/Debug/node]
 4: 0x1024627fc node::InternalCallbackScope::Close() [/Users/targos/git/nodejs/node/out/Debug/node]
 5: 0x1024625b4 node::InternalCallbackScope::~InternalCallbackScope() [/Users/targos/git/nodejs/node/out/Debug/node]
 6: 0x102461dcc node::InternalCallbackScope::~InternalCallbackScope() [/Users/targos/git/nodejs/node/out/Debug/node]
 7: 0x102513d70 node::Environment::RunAndClearNativeImmediates(bool) [/Users/targos/git/nodejs/node/out/Debug/node]
 8: 0x10251352c node::Environment::CheckImmediate(uv_check_s*) [/Users/targos/git/nodejs/node/out/Debug/node]
 9: 0x10365256c uv__run_check [/Users/targos/git/nodejs/node/out/Debug/node]
10: 0x103647f60 uv_run [/Users/targos/git/nodejs/node/out/Debug/node]
11: 0x10246791c node::SpinEventLoop(node::Environment*) [/Users/targos/git/nodejs/node/out/Debug/node]
12: 0x1026c3594 node::NodeMainInstance::Run(node::EnvSerializeInfo const*) [/Users/targos/git/nodejs/node/out/Debug/node]
13: 0x1025a0724 node::Start(int, char**) [/Users/targos/git/nodejs/node/out/Debug/node]
14: 0x103e4f3d4 main [/Users/targos/git/nodejs/node/out/Debug/node]
15: 0x195131f34 start [/usr/lib/system/libdyld.dylib]

node/src/api/callback.cc

Lines 122 to 127 in e46c680

    
           // Make sure the stack unwound properly. If there are nested MakeCallback's 
        
           // then it should return early and not reach this code. 
        
           if (env_->async_hooks()->fields()[AsyncHooks::kTotals]) { 
        
             CHECK_EQ(env_->execution_async_id(), 0); 
        
             CHECK_EQ(env_->trigger_async_id(), 0); 
        
           }

I think it's that assert?

Till now I failed to reproduce on windows or WSL. Found no time yet to test on linux. I have no access to a mac.

Tried on linux and can't reproduce there with 15.14.0. The test just fails with JS exceptions:

 FAIL  test/tls-session-reuse.js 5 failed of 5 142.07ms
 ✖ Cannot convert undefined or null to object
 ✖ should be equal
 ✖ Cannot read property 'toString' of undefined
 ✖ Cannot read property 'reuseSessions' of undefined
 ✖ connect ECONNREFUSED 127.0.0.1:33543

Either I'm doing something wrong here or it effects only MacOs.

It's easy to reproduce but as said above I doubt it's a nodejs issue.

Or was there any change regarding the testsetup to no longer use async-hook-domain?

I doubt it's a nodejs issue.

An assertion should never happen when running user code. IMHO it's a node issue.

@ronag

@ronag That's true only for user code that doesn't touch internal APIs. For example, it's not a node issue if someone triggers an assertion by directly calling process.binding('fs').chmod().
If this assertion is triggered because async-hook-domain has a bug in its custom implementation of process._fatalException, then it's an async-hook-domain issue

@targos

@targos Yes. But I'm more referring to @szmarczak's repro.

That repro doesn't crash if I comment out this line:
https://github.com/tapjs/async-hook-domain/blob/master/index.js#L31

That repro doesn't crash if I comment out this line:
https://github.com/tapjs/async-hook-domain/blob/master/index.js#L31

Ah, I didn't realize that was relevant there as well.

Does anyone have a solution to this issue? Or is there is anything we could do to fix this issue?
Is it something that https://github.com/tapjs/async-hook-domain should fix or is it on the Node.js side?

I can't reproduce the issue locally on my Ubuntu 21.10, but somehow the issue appears when using ubuntu-latest on the GitHub Actions (using tap test runner), using macos-latest instead and there is no issue.
Is this issue related to the Linux kernel or some low-level stuff?
Does anyone have an explanation of why there is no problem on my local computer with Ubuntu 21.10, but there is this issue on GitHub Actions using ubuntu-latest, so latest should be 20.04 I guess.

has there been found a solution to this issue? I'm experiencing the same problem and have changed node version several times, nothing helps :(

I have a situation where this issue does occur, but it does not if I use --inspect-brk.

To be more precise, this script starts an express server, among other things, and for some reason it doesn't fail if I manage to attach the debugger before the end of some initialization steps.

So I can either start the process and quickly attach the debugger, or just use --inspect-brk, which is easier to make sure I can attach before the end of those initializations.

Unfortunately I can't share this project because it doesn't belong to me and it is not public.
But I guess this can be a useful workaround for people out there.

Heya, I've hit the same problem; I've created a repro here.

@delvedor

@delvedor Thanks for your repo. But again it uses tap which internally uses async-hook-domain which is likely doing something wrong by monkeypatching node internal. See above comments.

Seems latest versions of async-hook-domain no longer monkey path process._fatalException (see here).

Is this problem still occurring anywhere with latest version of async-hook-domain used?

@Flarna

@Flarna i haven't seen the issue lately, no.

closing as it seem problem is solved by latest version of async-hook-domain. Feel free to reopen or create a new issue if it is reproducible without 3rd party dependencies.

Navigation Menu

Repository navigation

Assertion `(env_->execution_async_id()) == (0)' failed #38155

12 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

	// Make sure the stack unwound properly. If there are nested MakeCallback's
	// then it should return early and not reach this code.
	if (env_->async_hooks()->fields()[AsyncHooks::kTotals]) {
	CHECK_EQ(env_->execution_async_id(), 0);
	CHECK_EQ(env_->trigger_async_id(), 0);
	}

Assertion `(env_->execution_async_id()) == (0)' failed #38155

Description

Activity

ronag commented on Apr 8, 2021

addaleax commented on Apr 9, 2021

Flarna commented on Apr 9, 2021

ronag commented on Apr 9, 2021

ronag commented on Apr 22, 2021

Flarna commented on Apr 22, 2021

ronag commented on Apr 22, 2021

targos commented on Apr 23, 2021

targos commented on Apr 23, 2021

Flarna commented on Apr 23, 2021

Flarna commented on Apr 23, 2021

12 remaining items

Flarna commented on Sep 14, 2021

ronag commented on Sep 14, 2021

targos commented on Sep 14, 2021

ronag commented on Sep 14, 2021

targos commented on Sep 14, 2021

ronag commented on Sep 14, 2021

theoludwig commented on Mar 20, 2022

margaritluch commented on May 10, 2022

fterradev commented on Aug 11, 2022

delvedor commented on Nov 5, 2022

Flarna commented on Nov 5, 2022

Flarna commented on Nov 2, 2023

isaacs commented on Nov 3, 2023

Flarna commented on Nov 6, 2023

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions