Repository navigation
Core dump with "double free detected in tcache 2" or assertion failure when using http2 client via @grpc/grpc-js #38964
Description
Activity
Any chance you could provide a repro that doesn't include npm dependencies (or downloading a potentially sketchy zip file 🙃)?
Indeed, I can reproduce on macOS 11.4 with node v15.5.1 (that's what I last had 🙂).
❯ npm run client > server@1.0.0 client > node client.js duplexEcho response: { message: 'Hello duplex world!' } unaryEcho response: { message: 'Hello unary world!' } duplexEcho error Error: 1 CANCELLED: Cancelled on client at Object.callErrorFromStatus (/Users/me/Downloads/repro-node-crash/node_modules/@grpc/grpc-js/build/src/call.js:31:26) at Object.onReceiveStatus (/Users/me/Downloads/repro-node-crash/node_modules/@grpc/grpc-js/build/src/client.js:390:49) at Object.onReceiveStatus (/Users/me/Downloads/repro-node-crash/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:299:181) at /Users/me/Downloads/repro-node-crash/node_modules/@grpc/grpc-js/build/src/call-stream.js:145:78 at processTicksAndRejections (node:internal/process/task_queues:75:11) duplexEcho status { code: 1, details: 'Cancelled on client', metadata: Metadata { internalRepr: Map(0) {}, options: {} } } node(48717,0x104f70e00) malloc: *** error for object 0x104b31db0: pointer being freed was not allocated node(48717,0x104f70e00) malloc: *** set a breakpoint in malloc_error_break to debug zsh: abort npm run client
I'll investigate some more and when I come to a conclusion, I'll pull in some guys.
@mdouglass is the problem (what's not expected) the error itselfNever mind, I see the core dump is the proble.duplexEcho error Error: 1 CANCELLED: Cancelled on client(and its stacktrace) or the core dump? Or both?It seems like a bug in HTTP2. cc @jasnell @addaleax because you're familiar with HTTP2 in node. I think the line that causes the abort is https://github.com/grpc/grpc-node/blob/663fe77e7286910da0ae067cde5622dd2036bb30/packages/grpc-js/src/call-stream.ts#L679
Any chance you could provide a repro that doesn't include npm dependencies (or downloading a potentially sketchy zip file upside_down_face)?
Apologies, I thought the zip of the repro would be most appropriate. I've posted the repo at https://github.com/mdouglass/repro-node-crash as well if you'd rather get it there.
I don't know enough about the @grpc/grpc-js internals to be able to create a repro without that lib quickly. If it turns out to be necessary to investigate it further, I can try to figure it out.
@mdouglass save yourself the time — I'm investigating right now
Reacted by Matthew DouglassIt seems like a bug in HTTP2. cc @jasnell @addaleax because you're familiar with HTTP2 in node. I think the line that causes the abort is https://github.com/grpc/grpc-node/blob/663fe77e7286910da0ae067cde5622dd2036bb30/packages/grpc-js/src/call-stream.ts#L679
That reminded me that I should have tried to run this with the grpc-node tracing turned on via:
export GRPC_TRACE=all export GRPC_VERBOSITY=DEBUGIf I do that, the last log line out is indeed the one immediately before https://github.com/grpc/grpc-node/blob/663fe77e7286910da0ae067cde5622dd2036bb30/packages/grpc-js/src/call-stream.ts#L679 that @bl-ue identified.
See https://gist.github.com/mdouglass/a4c521167daf8e5e0246bb862b419f36
Yep, I tried those vars too which is what got me that line.
I'm building node now with a bunch of debug params to see if I can spot anything obvious before digging in to the node source more:./configure --debug --debug-node --gdb --v8-non-optimized-debug --v8-enable-object-print --debug-nghttp2 --node-builtin-modules-path=$PWD/lib --enable-asan --debug-libSo, after the long (37min) build, I tried running the server which worked like normal, and the client eventually (this 393mb node takes an extraordinarily long time to start up 😄) started executing, and printed this error instead of the core dump or the assertion failure (both of which I've gotten earlier and got a bunch more on the next runs):
Assertion failed: (stream->dep_prev), function nghttp2_stream_dep_remove, file ../deps/nghttp2/lib/nghttp2_stream.c, line 777. zsh: abort npm run client@jasnell does that look like a real problem or some unrelated issue caused by debugging?
node/deps/nghttp2/lib/nghttp2_stream.c
Line 777 in e46c680
I just built with
./configure --debug --enable-asan. After that I do see an ASAN heap-use-after-free. See https://gist.github.com/mdouglass/18514a2667572d742ef2c2d38f45249cWow, that's a lot of cool output — I didn't get any of that 🤔
==2805953==ERROR: AddressSanitizer: heap-use-after-free on address 0x6110000b7e74 at pc 0x000006292f8b bp 0x7ffc581e67b0 sp 0x7ffc581e67a8 READ of size 1 at 0x6110000b7e74 thread T0 #0 0x6292f8a in nghttp2_session_close_stream ../deps/nghttp2/lib/nghttp2_session.c:1218 #1 0x6293def in nghttp2_session_close_stream_if_shut_rdwr ../deps/nghttp2/lib/nghttp2_session.c:1442 #2 0x629b653 in session_end_stream_headers_received ../deps/nghttp2/lib/nghttp2_session.c:3738 #3 0x629bc7f in session_after_header_block_received ../deps/nghttp2/lib/nghttp2_session.c:3826 #4 0x62a689e in nghttp2_session_mem_recv ../deps/nghttp2/lib/nghttp2_session.c:6277 #5 0x140f19d in node::http2::Http2Session::ConsumeHTTP2Data() ../src/node_http2.cc:798 #6 0x1418f2c in node::http2::Http2Session::OnStreamRead(long, uv_buf_t const&) ../src/node_http2.cc:1883 #7 0x12375c4 in node::StreamResource::EmitRead(long, uv_buf_t const&) ../src/stream_base-inl.h:104 #8 0x1720366 in node::LibuvStreamWrap::OnUvRead(long, uv_buf_t const*) ../src/stream_wrap.cc:276 #9 0x171fb08 in operator() ../src/stream_wrap.cc:198 #10 0x171fb38 in _FUN ../src/stream_wrap.cc:199 #11 0x523b8c5 in uv__read ../deps/uv/src/unix/stream.c:1239 #12 0x523bfa9 in uv__stream_io ../deps/uv/src/unix/stream.c:1306 #13 0x524e7d7 in uv__io_poll ../deps/uv/src/unix/linux-core.c:462 #14 0x520c612 in uv_run ../deps/uv/src/unix/core.c:385 #15 0x107ae80 in node::SpinEventLoop(node::Environment*) ../src/api/embed_helpers.cc:36 #16 0x14ca670 in node::NodeMainInstance::Run(node::EnvSerializeInfo const*) ../src/node_main_instance.cc:143 #17 0x12aa567 in node::Start(int, char**) ../src/node.cc:1125 #18 0x5e68beb in main ../src/node_main.cc:127 #19 0x7fa6c1feab74 in __libc_start_main (/lib64/libc.so.6+0x27b74) #20 0x106d18d in _start (/home/matthew/projects/node/out/Debug/node+0x106d18d)Hmm, that almost looks like a bug in nghttp2 — but I'm not experienced enough to say that.
ping @jasnell I just know you're the best to take a look at this :)
Adding a bit more context, I turned on the nghttp2 debug as well and got this: https://gist.github.com/mdouglass/fe9a159b6d9b167ac1da14386bf773a5.
I'm suspicious of this:
stream: stream(0x6110000b7ec8)=3 close unaryEcho response: { message: 'Hello unary world!' } calling stream.cancel ... stream: stream(0x6110000b7ec8)=3 closeI'm seeing that the same stream was closed twice and that the address of that stream is within a short distance of where the heap-use-after-free. The first close is right before I receive the unary response and the second close is right after I call cancel on the duplex stream. So to my eyes that looks like the two streams getting confused somehow. Will keep poking at it.
Continuing to poke at this as I can. I added logging at the top and bottom of
nghttp2_session_close_streamso I could see when we enter/exit calls to this method. In the working version of the repro, we enternghttp2_session_close_stream, exit it and then enter and exit it again.In the non-working version of the repro, we enter
nghttp2_session_close_streamand then re-enter it on the same thread:bad version:
stream: thread=140488664597056 stream(unknown)=3 request close <-- initial entry stream: thread=140488664597056 session(0x61e000009088) stream(0x6110000a9c88)=3 close CLIENT: Received unaryEcho result CLIENT: unaryEcho response: { message: 'Hello unary world!' } CLIENT: calling stream.cancel stream: stream=1 resume item=0x60e00002af28 flags=08 stream: stream=1 obq push cycle=0 stream: push stream 1 to stream 0 stream: adjusting kept idle streams num_idle_streams=0, max=100 send: next frame: payloadlen=4, type=3, flags=0x00, stream_id=3 send: start transmitting frame type=3, length=13 stream: thread=140488664597056 stream(unknown)=3 request close <-- re-entry! stream: thread=140488664597056 session(0x61e000009088) stream(0x6110000a9c88)=3 close stream: destroy closed stream(0x6110000a9c88)=3 stream: dep_remove stream(0x6110000a9c88)=3 stream: thread=140488664597056 session(0x61e000009088) stream(0x6110000a9c88)=3 normal return <-- exitThe second call never exits as it ultimately crashes with the use after free call seen above.
I tried reading through the nghttp2 docs to see if this is allowed and can't see if it is allowed or not. There is a comment that a single
nghttp2_sessionobject must be used by a single thread (which is why I logged threadid) but nothing about reentrancy.edit: Ignore the unknown in the request close line, I am logging that before retrieving the stream pointer since I wanted to make sure the log line was as early as possible.
28 remaining items
I'm afraid I don't have a script that I'm able to share, sorry (it's a loadtest of a non-open-source distributed system, I haven't been able to generate a minimal reproduction).
But if you have some debug flags I could turn on, or a custom build of node with extra logging or something that you'd like me to run the tests against to get more information when the crash happens, I'd be happy to do so.
@SimonWoolf I'm looking into this issue right now. Is there any chance you could run the tests against a build with ASAN? The stack trace provided by it would give us a better clue of where the problematic
freeis happening.Sure - unfortunately I'm about to go on holiday; I'll be back and hope to be able to get you that info on the 7th/8th of June.
Reacted by Facundo TuescaSorry for the delay; some other things came up (plus I had some trouble compiling the asan build).
Running the loadtest with asan build of node, most of the instances quickly died with the following stacktrace. This is a different error to the above; no idea of whether this is the same bug being exposed earlier by the asan build or whether this is some other issue, hopefully you do 🙂
FATAL ERROR: v8::HandleScope::CreateHandle() Cannot create a handle without a HandleScope 1: 0x55f7c9983faf node::PosixSymbolDebuggingContext::GetStackTrace(void**, int) [node] 2: 0x55f7c99810ad node::DumpBacktrace(_IO_FILE*) [node] 3: 0x55f7c9cd88a7 node::Abort() [node] 4: 0x55f7c9cd8db9 [node] 5: 0x55f7ca519edd v8::Utils::ReportApiFailure(char const*, char const*) [node] 6: 0x55f7cac75a91 v8::internal::HandleScope::Extend(v8::internal::Isolate*) [node] 7: 0x55f7ca521956 v8::HandleScope::CreateHandle(v8::internal::Isolate*, unsigned long) [node] 8: 0x55f7ca521b83 v8::EscapableHandleScope::EscapableHandleScope(v8::Isolate*) [node] 9: 0x55f7ca5b60a2 v8::ObjectTemplate::NewInstance(v8::Local<v8::Context>) [node] 10: 0x55f7c9d74499 node::http2::Http2Stream::New(node::http2::Http2Session*, int, nghttp2_headers_category, int) [node] 11: 0x55f7c9d64b13 node::http2::Http2Session::OnBeginHeadersCallback(nghttp2_session*, nghttp2_frame const*, void*) [node] 12: 0x55f7cd648908 [node] 13: 0x55f7cd6484d6 nghttp2_session_on_request_headers_received [node] 14: 0x55f7cd658947 [node] 15: 0x55f7cd650790 nghttp2_session_mem_recv [node] 16: 0x55f7c9d735bc node::http2::Http2Session::ConsumeHTTP2Data() [node] 17: 0x55f7c9d7ca38 node::http2::Http2Session::OnStreamAfterWrite(node::WriteWrap*, int) [node] 18: 0x55f7ca152868 node::StreamResource::EmitAfterWrite(node::WriteWrap*, int) [node] 19: 0x55f7ca14d4db node::WriteWrap::OnDone(int) [node] 20: 0x55f7c9b30a28 node::StreamReq::Done(int, char const*) [node] 21: 0x55f7ca3ec092 node::crypto::TLSWrap::InvokeQueued(int, char const*) [node] 22: 0x55f7ca3f311e node::crypto::TLSWrap::EncOut() [node] 23: 0x55f7ca3f4779 node::crypto::TLSWrap::OnStreamAfterWrite(node::WriteWrap*, int) [node] 24: 0x55f7ca40df36 [node] 25: 0x55f7ca40de48 [node] 26: 0x55f7c9a1d2dd [node] 27: 0x55f7c9a1b477 node::Environment::RunAndClearNativeImmediates(bool) [node] 28: 0x55f7c9a1998e node::Environment::CheckImmediate(uv_check_s*) [node] 29: 0x55f7cc8d4a0e [node] 30: 0x55f7cc8afd7f uv_run [node] 31: 0x55f7c982cefe node::SpinEventLoop(node::Environment*) [node] 32: 0x55f7c9e582af node::NodeMainInstance::Run(int*, node::Environment*) [node] 33: 0x55f7c9e56bcc node::NodeMainInstance::Run(node::EnvSerializeInfo const*) [node] 34: 0x55f7c9b6bbc7 node::Start(int, char**) [node] 35: 0x55f7cd114200 main [node] 36: 0x7ff600a60d90 [/lib/x86_64-linux-gnu/libc.so.6] 37: 0x7ff600a60e40 __libc_start_main [/lib/x86_64-linux-gnu/libc.so.6] 38: 0x55f7c9759715 _start [node] PID 1 received SIGSEGV for address: 0x0 node(__interceptor_backtrace+0x5b)[0x55f7c979524b] /opt/ably/node_modules/segfault-handler/build/Release/segfault-handler.node(+0x3745)[0x7ff600003745] /lib/x86_64-linux-gnu/libc.so.6(+0x42520)[0x7ff600a79520] /lib/x86_64-linux-gnu/libc.so.6(abort+0x178)[0x7ff600a5f898] node(+0x1ed88e4)[0x55f7c9cd88e4] node(+0x1ed8db9)[0x55f7c9cd8db9] node(_ZN2v85Utils16ReportApiFailureEPKcS2_+0xbd)[0x55f7ca519edd] node(_ZN2v88internal11HandleScope6ExtendEPNS0_7IsolateE+0xb1)[0x55f7cac75a91] node(_ZN2v811HandleScope12CreateHandleEPNS_8internal7IsolateEm+0x76)[0x55f7ca521956] node(_ZN2v820EscapableHandleScopeC1EPNS_7IsolateE+0x103)[0x55f7ca521b83] node(_ZN2v814ObjectTemplate11NewInstanceENS_5LocalINS_7ContextEEE+0x252)[0x55f7ca5b60a2] node(_ZN4node5http211Http2Stream3NewEPNS0_12Http2SessionEi24nghttp2_headers_categoryi+0x229)[0x55f7c9d74499] node(_ZN4node5http212Http2Session22OnBeginHeadersCallbackEP15nghttp2_sessionPK13nghttp2_framePv+0x3d3)[0x55f7c9d64b13] node(+0x5848908)[0x55f7cd648908] node(nghttp2_session_on_request_headers_received+0x856)[0x55f7cd6484d6] node(+0x5858947)[0x55f7cd658947] node(nghttp2_session_mem_recv+0x12a0)[0x55f7cd650790] node(_ZN4node5http212Http2Session16ConsumeHTTP2DataEv+0x6fc)[0x55f7c9d735bc] node(_ZN4node5http212Http2Session18OnStreamAfterWriteEPNS_9WriteWrapEi+0x518)[0x55f7c9d7ca38] node(_ZN4node14StreamResource14EmitAfterWriteEPNS_9WriteWrapEi+0x198)[0x55f7ca152868] node(_ZN4node9WriteWrap6OnDoneEi+0x2b)[0x55f7ca14d4db] node(_ZN4node9StreamReq4DoneEiPKc+0x628)[0x55f7c9b30a28] node(_ZN4node6crypto7TLSWrap12InvokeQueuedEiPKc+0x3a2)[0x55f7ca3ec092] node(_ZN4node6crypto7TLSWrap6EncOutEv+0xa7e)[0x55f7ca3f311e] node(_ZN4node6crypto7TLSWrap18OnStreamAfterWriteEPNS_9WriteWrapEi+0x749)[0x55f7ca3f4779] node(+0x260df36)[0x55f7ca40df36] node(+0x260de48)[0x55f7ca40de48] node(+0x1c1d2dd)[0x55f7c9a1d2dd] node(_ZN4node11Environment27RunAndClearNativeImmediatesEb+0x4e7)[0x55f7c9a1b477] node(_ZN4node11Environment14CheckImmediateEP10uv_check_s+0x2ce)[0x55f7c9a1998e] node(+0x4ad4a0e)[0x55f7cc8d4a0e] node(uv_run+0x11f)[0x55f7cc8afd7f]@facutuesca I have managed to reproduce with an ASAN build, see:
================================================================= ==1==ERROR: AddressSanitizer: heap-use-after-free on address 0xffff85539b9c at pc 0x0000030ac3b0 bp 0xffffdfed3f00 sp 0xffffdfed3ef8 READ of size 1 at 0xffff85539b9c thread T0 #0 0x30ac3ac in nghttp2_session_close_stream (/usr/local/bin/node+0x30ac3ac) #1 0x30bd030 in nghttp2_session_mem_recv (/usr/local/bin/node+0x30bd030) #2 0xd45fa4 in node::http2::Http2Session::ConsumeHTTP2Data() (/usr/local/bin/node+0xd45fa4) #3 0xd4f4d8 in node::http2::Http2Session::OnStreamRead(long, uv_buf_t const&) (/usr/local/bin/node+0xd4f4d8) #4 0xf74bdc in node::LibuvStreamWrap::OnUvRead(long, uv_buf_t const*) (/usr/local/bin/node+0xf74bdc) #5 0xf76140 in node::LibuvStreamWrap::ReadStart()::$_1::__invoke(uv_stream_s*, long, uv_buf_t const*) (/usr/local/bin/node+0xf76140) #6 0x279a5c4 in uv__read /node-v16.18.0/out/../deps/uv/src/unix/stream.c:1247:7 #7 0x279a5c4 in uv__stream_io /node-v16.18.0/out/../deps/uv/src/unix/stream.c:1315:5 #8 0x27aaac4 in uv__io_poll /node-v16.18.0/out/../deps/uv/src/unix/epoll.c:374:11 #9 0x277c788 in uv_run /node-v16.18.0/out/../deps/uv/src/unix/core.c:389:5 #10 0xaa8b48 in node::SpinEventLoop(node::Environment*) (/usr/local/bin/node+0xaa8b48) #11 0xda2ac0 in node::NodeMainInstance::Run(int*, node::Environment*) (/usr/local/bin/node+0xda2ac0) #12 0xda2014 in node::NodeMainInstance::Run() (/usr/local/bin/node+0xda2014) #13 0xc4555c in node::Start(int, char**) (/usr/local/bin/node+0xc4555c) #14 0xffffb5217e0c in __libc_start_main (/lib/aarch64-linux-gnu/libc.so.6+0x20e0c) #15 0xa0a6e8 in _start (/usr/local/bin/node+0xa0a6e8) 0xffff85539b9c is located 220 bytes inside of 224-byte region [0xffff85539ac0,0xffff85539ba0) freed by thread T0 here: #0 0xa77320 in free (/usr/local/bin/node+0xa77320) #1 0xd76a70 in node::mem::NgLibMemoryManager<node::http2::Http2Session, nghttp2_mem>::FreeImpl(void*, void*) (/usr/local/bin/node+0xd76a70) #2 0x30ac31c in nghttp2_session_close_stream (/usr/local/bin/node+0x30ac31c) #3 0x30b17a8 in session_after_frame_sent1 (/usr/local/bin/node+0x30b17a8) #4 0x30ad090 in nghttp2_session_mem_send (/usr/local/bin/node+0x30ad090) #5 0xd43c04 in node::http2::Http2Session::SendPendingData() (/usr/local/bin/node+0xd43c04) #6 0xd4785c in node::http2::Http2Stream::SubmitRstStream(unsigned int) (/usr/local/bin/node+0xd4785c) #7 0xd5a454 in node::http2::Http2Stream::RstStream(v8::FunctionCallbackInfo<v8::Value> const&) (/usr/local/bin/node+0xd5a454) #8 0x12fae78 in v8::internal::FunctionCallbackArguments::Call(v8::internal::CallHandlerInfo) (/usr/local/bin/node+0x12fae78) #9 0x12f9e24 in 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+0x12f9e24) #10 0x12f87b8 in v8::internal::Builtin_HandleApiCall(int, unsigned long*, v8::internal::Isolate*) (/usr/local/bin/node+0x12f87b8) #11 0x282ada8 in Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_BuiltinExit (/usr/local/bin/node+0x282ada8) #12 0xffffa3333114 (<unknown module>) #13 0xffffa33394a8 (<unknown module>) #14 0xffffa3203a98 (<unknown module>) #15 0xffffa3336ba4 (<unknown module>) #16 0xffffa33326f8 (<unknown module>) #17 0xffffa33320d4 (<unknown module>) #18 0xffffa3333864 (<unknown module>) #19 0xffffa3334914 (<unknown module>) #20 0xffffa3337fb4 (<unknown module>) #21 0xffffa3334cb4 (<unknown module>) #22 0xffffa3334f2c (<unknown module>) #23 0xffffa333512c (<unknown module>) #24 0xffffa35ca540 (<unknown module>) #25 0xffffa33354ec (<unknown module>) #26 0xffffa3399d60 (<unknown module>) #27 0xffffa338d224 (<unknown module>) #28 0xffffa3522978 (<unknown module>) #29 0xffffa35277a0 (<unknown module>) previously allocated by thread T0 here: #0 0xa7787c in realloc (/usr/local/bin/node+0xa7787c) #1 0xd76c08 in node::mem::NgLibMemoryManager<node::http2::Http2Session, nghttp2_mem>::ReallocImpl(void*, unsigned long, void*) (/usr/local/bin/node+0xd76c08) #2 0x30aae38 in nghttp2_session_open_stream (/usr/local/bin/node+0x30aae38) #3 0x30ae228 in nghttp2_session_mem_send_internal (/usr/local/bin/node+0x30ae228) #4 0x30ad060 in nghttp2_session_mem_send (/usr/local/bin/node+0x30ad060) #5 0xd43ca4 in node::http2::Http2Session::SendPendingData() (/usr/local/bin/node+0xd43ca4) #6 0xd46140 in node::http2::Http2Session::ConsumeHTTP2Data() (/usr/local/bin/node+0xd46140) #7 0xd4f4d8 in node::http2::Http2Session::OnStreamRead(long, uv_buf_t const&) (/usr/local/bin/node+0xd4f4d8) #8 0xf74bdc in node::LibuvStreamWrap::OnUvRead(long, uv_buf_t const*) (/usr/local/bin/node+0xf74bdc) #9 0xf76140 in node::LibuvStreamWrap::ReadStart()::$_1::__invoke(uv_stream_s*, long, uv_buf_t const*) (/usr/local/bin/node+0xf76140) #10 0x279a5c4 in uv__read /node-v16.18.0/out/../deps/uv/src/unix/stream.c:1247:7 #11 0x279a5c4 in uv__stream_io /node-v16.18.0/out/../deps/uv/src/unix/stream.c:1315:5 #12 0x27aaac4 in uv__io_poll /node-v16.18.0/out/../deps/uv/src/unix/epoll.c:374:11 #13 0x277c788 in uv_run /node-v16.18.0/out/../deps/uv/src/unix/core.c:389:5 #14 0xaa8b48 in node::SpinEventLoop(node::Environment*) (/usr/local/bin/node+0xaa8b48) #15 0xda2ac0 in node::NodeMainInstance::Run(int*, node::Environment*) (/usr/local/bin/node+0xda2ac0) #16 0xda2014 in node::NodeMainInstance::Run() (/usr/local/bin/node+0xda2014) #17 0xc4555c in node::Start(int, char**) (/usr/local/bin/node+0xc4555c) #18 0xffffb5217e0c in __libc_start_main (/lib/aarch64-linux-gnu/libc.so.6+0x20e0c) #19 0xa0a6e8 in _start (/usr/local/bin/node+0xa0a6e8) SUMMARY: AddressSanitizer: heap-use-after-free (/usr/local/bin/node+0x30ac3ac) in nghttp2_session_close_stream Shadow bytes around the buggy address: 0x200ff0aa7320: fd fd fd fd fd fd fd fd fa fa fa fa fa fa fa fa 0x200ff0aa7330: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x200ff0aa7340: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x200ff0aa7350: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd 0x200ff0aa7360: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd =>0x200ff0aa7370: fd fd fd[fd]fa fa fa fa fa fa fa fa fa fa fa fa 0x200ff0aa7380: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0x200ff0aa7390: 00 00 00 00 00 00 00 00 00 00 00 00 fa fa fa fa 0x200ff0aa73a0: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd 0x200ff0aa73b0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x200ff0aa73c0: fd fd fd fd fd fd fd fd fa fa fa fa fa fa fa fa Shadow byte legend (one shadow byte represents 8 application bytes): Addressable: 00 Partially addressable: 01 02 03 04 05 06 07 Heap left redzone: fa Freed heap region: fd Stack left redzone: f1 Stack mid redzone: f2 Stack right redzone: f3 Stack after return: f5 Stack use after scope: f8 Global redzone: f9 Global init order: f6 Poisoned by user: f7 Container overflow: fc Array cookie: ac Intra object redzone: bb ASan internal: fe Left alloca redzone: ca Right alloca redzone: cb Shadow gap: cc ==1==ABORTING@Matt-Esch any possibility of having code that reproduces the issue?
@santigimeno I can only reproduce this on a large proprietary codebase, I've not been able to isolate this to a simple repro unfortunately. I do think the stack traces give us a lot of context. My feeling is that the stream should have been removed from the session in the first close call, the second call to close (on incoming RST) should not have been possible. So either the close callback is re-entrant (nghttp2 says explicitly not to do that) or the stream is not removed from that session, which would raise the question why is the session not removed on RST even if the underlying data is freed.
Looking over the
nghttp2_session_close_streamcode, there are a few places where stream-related memory can be freed but the stream not removed from the list, for example https://github.com/nodejs/node/blob/v16.18.0/deps/nghttp2/lib/nghttp2_session.c#L1210I am going to instrument these points to see if they are the root cause.
Logs from nghttp2 when segfault occurs on stream 65:
send: available window=16384 send: padlen = 0, nothing to do stream: stream=65 obq resched cycle=19232 send: next frame: DATA send: start transmitting frame type=0, length=9 stream: stream=65 detach item=0xffff7b76e288 stream: remove stream 65 from stream 0 stream: adjusting kept idle streams num_idle_streams=0, max=100 send: end transmission of a frame send: reset nghttp2_active_outbound_item send: aob->item = 0xffff7b76e288Looks like the transmission of a frame completes after the stream has already been closed.
- added a commit that references this issue
on May 22, 2026 This issue has been marked as stale due to 210 days of inactivity.
It will be automatically closed in 30 days if no further activity occurs. If this is still relevant, please leave a comment or update it to keep it open.This issue has been automatically closed after 30 days of inactivity following its stale status (no activity for a total of 120 days).
If this is still relevant, feel free to reopen it or leave a comment with additional details so we can continue the discussion.
What steps will reproduce the bug?
repro-node-crash.zip
Run the following steps on the same machine:
npm cinpm run servernpm run clientHow often does it reproduce? Is there a required condition?
On my machine this is 100% reproducible in node v16.0 and up. I have not tried previous pre-v16 versions.
What is the expected behavior?
It is expected that the client process runs to completion without error.
What do you see instead?
The client process dies with a core dump or an assertion failure:
Additional information
This is related to grpc/grpc-node#1464.
There is a workaround available in my example client.js if you comment out line 45 and comment in line 46 (delaying
stream.cancelvia the use ofsetImmediate).It seems to require this particular pattern of calls in the @grpc/grpc-js library as well: