envoyproxy/envoy

Race condition between Envoy's deferred deletion and cancelled gRPC response

Open

#34,489 建立於 2024年6月3日

在 GitHub 查看
 (9 留言) (0 反應) (0 負責人)C++ (5,373 fork)batch import
area/grpcbughelp wanted

倉庫指標

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:

  1. We are issuing a gRPC request using an Envoy::Grpc::AsyncRequestImpl object and Envoy::Grpc::AsyncRequestCallbacks for handling the callbacks
  2. Based on certain criteria, we decide to destroy the gRPC request for which we are still waiting on a response by calling cancel() on the Envoy::Grpc::AsyncRequestImpl in the destructor of the Envoy::Grpc::AsyncRequestCallbacks object. The cancel() 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_));
  }
}
  1. We receive the gRPC response that was sent in Step 1 but Envoy has not got to deleting the AsyncRequestImpl that 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

貢獻者指南