Race condition between Envoy's deferred deletion and cancelled gRPC response
#34,489 建立於 2024年6月3日
倉庫指標
- Star
- (27,997 star)
- PR 合併指標
- (平均合併 8天) (30 天內合併 378 個 PR)
描述
This is a follow up of https://github.com/envoyproxy/envoy/issues/27999, which was closed due to inactivity. I am unable to reopen that issue, so raising a new issue.
We are hitting the crash mentioned in https://github.com/envoyproxy/envoy/issues/27999 more frequent with the upgrade of envoy from v1.20.7 to v1.29.0. To add a bit more context and details on the issue. The sequence of events are as follows:
- We are issuing a gRPC request using an
Envoy::Grpc::AsyncRequestImplobject andEnvoy::Grpc::AsyncRequestCallbacksfor handling the callbacks - Based on certain criteria, we decide to destroy the gRPC request for which we are still waiting on a response by calling
cancel()on theEnvoy::Grpc::AsyncRequestImplin the destructor of theEnvoy::Grpc::AsyncRequestCallbacksobject. Thecancel()call chain is as follows where the request is appended to the deferred deletion list. Everything on our side including callbacks are deleted after this point as we don’t expect Envoy to invoke the callback on the gRPC request whose response is still pending.
void AsyncRequestImpl::cancel() {
current_span_->setTag(Tracing::Tags::get().Status, Tracing::Tags::get().Canceled);
current_span_->finishSpan();
this->resetStream();
}
void AsyncStreamImpl::resetStream() { cleanup(); }
void AsyncStreamImpl::cleanup() {
if (!http_reset_) {
http_reset_ = true;
stream_->reset();
}
// This will destroy us, but only do so if we are actually in a list. This does not happen in
// the immediate failure case.
if (LinkedObject<AsyncStreamImpl>::inserted()) {
ASSERT(dispatcher_->isThreadSafe());
dispatcher_->deferredDelete(
LinkedObject<AsyncStreamImpl>::removeFromList(parent_.active_streams_));
}
}
- We receive the gRPC response that was sent in Step 1 but Envoy has not got to deleting the
AsyncRequestImplthat was on the deferred deletion list yet, so the callback is called by Envoy and we hit a crash with the following call stack since everything is freed on our side.
"message": "#27: Envoy::Thread::ThreadImplPosix::ThreadImplPosix()::{lambda()#1}::__invoke()",
"message": "#26: Envoy::Server::WorkerImpl::threadRoutine()",
"message": "#25: event_base_loop"
"message": "#24: event_process_active_single_queue"
"message": "#23: Envoy::Event::FileEventImpl::assignEvents()::$_1::__invoke()",
"message": "#22: std::_Function_handler<>::_M_invoke()"
"message": "#21: Envoy::Network::ConnectionImpl::onFileEvent()",
"message": "#20: Envoy::Network::ConnectionImpl::onReadReady()",
"message": "#19: Envoy::Network::FilterManagerImpl::onContinueReading()",
"message": "#18: Envoy::Http::CodecClient::CodecReadFilter::onData()",
"message": "#17: Envoy::Http::CodecClient::onData()"
"message": "#16: Envoy::Http::Http2::ConnectionImpl::dispatch()",
"message": "#15: Envoy::Http::Http2::ConnectionImpl::dispatch()",
"message": "#14: http2::adapter::NgHttp2Adapter::ProcessBytes()"
"message": "#13: nghttp2_session_mem_recv",
"message": "#12: http2::adapter::callbacks::OnFrameReceived()",
"message": "#11: http2::adapter::CallbackVisitor::OnEndHeadersForStream()",
"message": "#10: Envoy::Http::Http2::ConnectionImpl::Http2Callbacks::Http2Callbacks()::$_29::__invoke()"
"message": "#9: Envoy::Http::Http2::ConnectionImpl::onFrameReceived()",
"message": "#8: Envoy::Http::ResponseDecoderWrapper::decodeTrailers()",
"message": "#7: Envoy::Router::UpstreamRequest::decodeTrailers()"
"message": "#6: Envoy::Http::AsyncStreamImpl::encodeTrailers()",
"message": "#5: Envoy::Grpc::AsyncStreamImpl::onTrailers()",
"message": "#4: Envoy::Grpc::AsyncRequestImpl::onRemoteClose()"
"message": "#3: Envoy::Grpc::AsyncRequestCallbacks<>::onSuccessRaw()"
Essentially, there is a race between Envoy deleting the deferred AsyncRequestImpl object and the gRPC response for the cancelled AsyncRequestImpl request. In the core, we are able to see that the AsyncRequestImpl is still in the deferred deletion list and treated as an active stream.
From frame "message": "#9: Envoy::Http::Http2::ConnectionImpl::onFrameReceived()",
(gdb) p *frame
$96 = {
hd = {
length = 1,
stream_id = 31928399,
type = 1 '\001', <——— NGHTTP2_HEADERS
flags = 5 '\005', <——— NGHTTP2_FLAG_END_STREAM, NGHTTP2_FLAG_END_HEADERS
reserved = 0 '\000'
},
data = {
hd = {
length = 1,
stream_id = 31928399,
type = 1 '\001',
flags = 5 '\005',
reserved = 0 '\000'
},
padlen = 0
},
headers = {
hd = {
length = 1,
stream_id = 31928399,
type = 1 '\001',
flags = 5 '\005',
reserved = 0 '\000'
},
padlen = 0,
pri_spec = {
stream_id = 0,
weight = 0,
exclusive = 0 '\000'
},
nva = 0x0,
nvlen = 0,
cat = NGHTTP2_HCAT_HEADERS
},
priority = {
hd = {
length = 1,
stream_id = 31928399,
type = 1 '\001',
flags = 5 '\005',
reserved = 0 '\000'
},
pri_spec = {
stream_id = 0,
weight = 0,
exclusive = 0 '\000'
}
},
rst_stream = {
hd = {
length = 1,
stream_id = 31928399,
type = 1 '\001',
flags = 5 '\005',
reserved = 0 '\000'
},
error_code = 0
},
settings = {
hd = {
length = 1,
stream_id = 31928399,
type = 1 '\001',
flags = 5 '\005',
reserved = 0 '\000'
},
niv = 0,
iv = 0x0
},
push_promise = {
hd = {
length = 1,
stream_id = 31928399,
type = 1 '\001',
flags = 5 '\005',
reserved = 0 '\000'
},
padlen = 0,
nva = 0x0,
nvlen = 0,
promised_stream_id = 0,
reserved = 0 '\000'
},
ping = {
hd = {
length = 1,
stream_id = 31928399,
type = 1 '\001',
flags = 5 '\005',
reserved = 0 '\000'
},
opaque_data = "\000\000\000\000\000\000\000"
},
goaway = {
hd = {
length = 1,
stream_id = 31928399,
type = 1 '\001',
flags = 5 '\005',
reserved = 0 '\000'
},
last_stream_id = 0,
error_code = 0,
opaque_data = 0x0,
opaque_data_len = 0,
reserved = 0 '\000'
},
window_update = {
hd = {
length = 1,
stream_id = 31928399,
type = 1 '\001',
flags = 5 '\005',
reserved = 0 '\000'
},
window_size_increment = 0,
reserved = 0 '\000'
},
ext = {
hd = {
length = 1,
stream_id = 31928399,
type = 1 '\001',
flags = 5 '\005',
reserved = 0 '\000'
},
payload = 0x0
}
}
(gdb) p active_streams_
$97 = {
<std::__cxx11::_List_base<std::unique_ptr<Envoy::Http::Http2::ConnectionImpl::StreamImpl, std::default_delete<Envoy::Http::Http2::ConnectionImpl::StreamImpl> >, std::allocator<std::unique_ptr<Envoy::Http::Http2::ConnectionImpl::StreamImpl, std::default_delete<Envoy::Http::Http2::ConnectionImpl::StreamImpl> > > >> = {
_M_impl = {
<std::allocator<std::_List_node<std::unique_ptr<Envoy::Http::Http2::ConnectionImpl::StreamImpl, std::default_delete<Envoy::Http::Http2::ConnectionImpl::StreamImpl> > > >> = {
<__gnu_cxx::new_allocator<std::_List_node<std::unique_ptr<Envoy::Http::Http2::ConnectionImpl::StreamImpl, std::default_delete<Envoy::Http::Http2::ConnectionImpl::StreamImpl> > > >> = {<No data fields>}, <No data fields>},
members of std::__cxx11::_List_base<std::unique_ptr<Envoy::Http::Http2::ConnectionImpl::StreamImpl, std::default_delete<Envoy::Http::Http2::ConnectionImpl::StreamImpl> >, std::allocator<std::unique_ptr<Envoy::Http::Http2::ConnectionImpl::StreamImpl, std::default_delete<Envoy::Http::Http2::ConnectionImpl::StreamImpl> > > >::_List_impl:
_M_node = {
<std::__detail::_List_node_base> = {
_M_next = 0x55ddcb3d4f40,
_M_prev = 0x55dda734eb60
},
members of std::__detail::_List_node_header:
_M_size = 32
}
}
}, <No data fields>}
(gdb) set $n = active_streams_._M_impl._M_node._M_next
(gdb) set $i = 0
(gdb) while $i < 32
>set $p = ((Envoy::Http::Http2::ConnectionImpl::StreamImpl*)((void**)$n)[2])
>p $p->stream_id_
>set $n = $n->_M_next
>set $i = $i + 1
>end
$98 = 31928467
$99 = 31928465
$100 = 31928463
$101 = 31928461
$102 = 31928459
$103 = 31928457
$104 = 31928455
$105 = 31928453
$106 = 31928451
$107 = 31928449
$108 = 31928447
$109 = 31928445
$110 = 31928443
$111 = 31928441
$112 = 31928439
$113 = 31928437
$114 = 31928435
$115 = 31928433
$116 = 31928431
$117 = 31928429
$118 = 31928427
$119 = 31928425
$120 = 31928423
$121 = 31928421
$122 = 31928419
$123 = 31928417
$124 = 31928415
$125 = 31928413
$126 = 31928411
$127 = 31928409
$128 = 31928399 <—————— stream that we got the trailer on
$129 = 31928395