Strange exit after updated to node 8.0.0

[adrai]

• Version: 8.0.0
• Platform: Darwin Raianos-MacBook-Pro.local 16.5.0 Darwin Kernel Version 16.5.0: Fri Mar 3 16:52:33 PST 2017; root:xnu-3789.51.2~3/RELEASE_X86_64 x86_64
• Subsystem:

Right now I don't know exactly what is causing the problem.... (I guess posting a http request to some endpoints)

The process exits with this:

/usr/local/bin/node[27084]: ../src/env-inl.h:131:void node::Environment::AsyncHooks::push_ids(double, double): Assertion `(trigger_id) >= (0)' failed.
 1: node::Abort() [/usr/local/bin/node]
 2: node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, char const*, int, v8::Local<v8::Value>*, double, double) [/usr/local/bin/node]
 3: node::AsyncWrap::PopAsyncIds(v8::FunctionCallbackInfo<v8::Value> const&) [/usr/local/bin/node]
 4: v8::internal::FunctionCallbackArguments::Call(void (*)(v8::FunctionCallbackInfo<v8::Value> const&)) [/usr/local/bin/node]
 5: 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) [/usr/local/bin/node]
 6: v8::internal::Builtin_Impl_HandleApiCall(v8::internal::BuiltinArguments, v8::internal::Isolate*) [/usr/local/bin/node]
 7: 0x528d1b8437d
[1]    27084 abort      node server.js

Any guess?

[mscdex]

/cc @addaleax @trevnorris @AndreasMadsen ?

[addaleax]

Any chance you could provide a core dump, or code to reproduce?

[adrai]

right now not... not so easy but will try in a couple of hours

[adrai]

Ok seems I have a core dump 1.49 GB and 264 MB zipped
Where should I upload it?

[addaleax]

Wherever you want – if you don’t want to share it with everyone (i.e. because your program contains non-public code or data), you can also send it or a link to it to my email address that’s listed in the readme (I’ll take a look at that in a few hours then).

[adrai]

Thanks a lot... I've sent you an email.

[addaleax]

Hmm … maybe somebody from @nodejs/platform-macos would be able to take a look, too? Right now I don’t have the tooling to deal with macos core dumps beyond pretty trivial things.

A full disassembly of the 8.0.0 macos executable might be helpful as well; the stack trace as it is shown in the original issue should not really be possible, because I don’t see any way for AsyncWrap::PopAsyncIds to call MakeCallback in such a way that it shows up like this (so there’s definitely sth weird going on).

[bnoordhuis]

@adrai Where did you install your node binary from?

[adrai]

from https://github.com/tj/n
https://twitter.com/adrirai/status/869645398016765952 ;-)

[joyeecheung]

I have got the coredump from @addaleax (who got this from @adrai) and opened it. I am not familiar with the async hooks enough to know why the assertion failed but there could be an overflow which caused triggered_id to be -1..I guess?

See the stacktrace

(lldb) v8 bt
 * thread #1: tid = 0x0000, 0x00007fffd5dd0d42 libsystem_kernel.dylib`__pthread_kill + 10, stop reason = signal SIGSTOP
  * frame #0: 0x00007fffd5dd0d42 libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x00007fffd5ebe5bf libsystem_pthread.dylib`pthread_kill + 90
    frame #2: 0x00007fffd5d36420 libsystem_c.dylib`abort + 129
    frame #3: 0x0000000100a741cd node`node::Abort() + 34
    frame #4: 0x0000000100a7308b node`node::Assert(char const* const (*) [4]) + 251
    frame #5: 0x0000000100a636b8 node`node::AsyncWrap::PushAsyncIds(v8::FunctionCallbackInfo<v8::Value> const&) + 296
    frame #7: 0x000013fe250e74cb nextTickEmitBefore(this=0x0000138933582311:<undefined>, 0x0000232e2b4be931:<Number: 942.000000>, 0x0000232e2b4be941:<Number: -1.000000>) at internal/process/next_tick.js:117:30 fn=0x00001a29492b0959
    frame #8: 0x000013fe24ffe4d7 _tickCallback(this=0x00003e642f80d441:<Object: process>) at internal/process/next_tick.js:133:25 fn=0x00003e642f810151
    frame #11: 0x0000000100558e36 node`v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, bool, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*, v8::internal::Handle<v8::internal::Object>, v8::internal::Execution::MessageHandling) + 742
    frame #12: 0x0000000100558a93 node`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>*) + 179
    frame #13: 0x00000001001611ff node`v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) + 559
    frame #14: 0x0000000100a658e5 node`node::AsyncWrap::MakeCallback(v8::Local<v8::Function>, int, v8::Local<v8::Value>*) + 789
    frame #15: 0x0000000100ac24ae node`node::StreamBase::EmitData(long, v8::Local<v8::Object>, v8::Local<v8::Object>) + 214
    frame #16: 0x0000000100ac4820 node`node::StreamWrap::OnReadImpl(long, uv_buf_t const*, uv_handle_type, void*) + 524
    frame #17: 0x0000000100ac4d29 node`node::StreamWrap::OnReadCommon(uv_stream_s*, long, uv_buf_t const*, uv_handle_type) + 127
    frame #18: 0x0000000100be21b4 node`uv__stream_io + 1261
    frame #19: 0x0000000100be99d1 node`uv__io_poll + 1621
    frame #20: 0x0000000100bda85b node`uv_run + 321
    frame #21: 0x0000000100a81999 node`node::Start(v8::Isolate*, node::IsolateData*, int, char const* const*, int, char const* const*) + 741
    frame #22: 0x0000000100a7cd67 node`node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) + 462
    frame #23: 0x0000000100a7c35a node`node::Start(int, char**) + 331
    frame #24: 0x0000000100000d34 node`start + 52

[bnoordhuis]

@joyeecheung If you're feeling adventurous give https://github.com/nodejs/llnode a try:

1. clone the repo (because of Release llnode#88)
2. ./gyp_llnode && make -C out BUILDTYPE=Release && make install-osx
3. v8 bt in lldb to get a stack trace with JS frames (including arguments)

[joyeecheung]

@bnoordhuis Yeah I've been using it, frame #6-10 in the stacktrace above are patched with v8 info.

[bnoordhuis]

Thanks, now we now it's the second argument on this line: https://github.com/nodejs/node/blob/v8.0.0/lib/internal/process/next_tick.js#L145

cc @AndreasMadsen @trevnorris (we don't have a async-hooks group yet, right?)