From 24cf920bc3eceea194bbd3ac3ab9cce64b693557 Mon Sep 17 00:00:00 2001 From: canepat <16927169+canepat@users.noreply.github.com> Date: Wed, 22 May 2024 19:00:35 +0200 Subject: [PATCH 1/3] sentry: add exception handling for main tasks --- silkworm/sentry/discovery/discovery.cpp | 11 +++- silkworm/sentry/rlpx/peer.cpp | 27 +++++++- silkworm/sentry/rlpx/server.cpp | 13 +++- silkworm/sentry/sentry.cpp | 82 ++++++++++++++++++++----- silkworm/sentry/status_manager.cpp | 15 ++++- 5 files changed, 128 insertions(+), 20 deletions(-) diff --git a/silkworm/sentry/discovery/discovery.cpp b/silkworm/sentry/discovery/discovery.cpp index 36c36d651b..ca2d6b1ea8 100644 --- a/silkworm/sentry/discovery/discovery.cpp +++ b/silkworm/sentry/discovery/discovery.cpp @@ -238,7 +238,16 @@ Discovery::~Discovery() { } Task Discovery::run() { - return p_impl_->run(); + try { + return p_impl_->run(); + } catch (const boost::system::system_error& se) { + if (se.code() == boost::system::errc::operation_canceled) { + log::Critical("sentry") << "Discovery::run unexpected end [operation_canceled]"; + } else { + log::Critical("sentry") << "Discovery::run unexpected end [" + std::string{se.what()} + "]"; + } + throw se; + } } Task> Discovery::request_peer_candidates( diff --git a/silkworm/sentry/rlpx/peer.cpp b/silkworm/sentry/rlpx/peer.cpp index 3f73843512..65e25b57e4 100644 --- a/silkworm/sentry/rlpx/peer.cpp +++ b/silkworm/sentry/rlpx/peer.cpp @@ -216,6 +216,27 @@ Task Peer::handle() { } log::Error("sentry") << "Peer::handle system_error: " << ex.what(); throw; + } catch (const std::nested_exception& ex) { + try { + ex.rethrow_nested(); + } catch (const DisconnectedError&) { + log::Debug("sentry") << "Peer::handle nested disconnection error"; + auto reason = disconnect_reason_.get().value_or(DisconnectReason::DisconnectRequested); + disconnect_reason_.set({reason}); + co_return; + } catch (const boost::system::system_error& ex) { + if (is_fatal_network_error(ex)) { + log::Debug("sentry") << "Peer::handle nested network error: " << ex.what(); + auto reason = disconnect_reason_.get().value_or(DisconnectReason::NetworkError); + disconnect_reason_.set({reason}); + co_return; + } else if (ex.code() == boost::system::errc::operation_canceled) { + log::Debug("sentry") << "Peer::handle nested cancellation"; + co_return; + } + log::Error("sentry") << "Peer::handle nested system_error: " << ex.what(); + throw; + } } catch (const std::exception& ex) { log::Error("sentry") << "Peer::handle exception: " << ex.what(); throw; @@ -313,7 +334,11 @@ void Peer::close() { } void Peer::post_message(const std::shared_ptr& peer, const Message& message) { - peer->send_message_tasks_.spawn(peer->strand_, Peer::send_message(peer, message)); + try { + peer->send_message_tasks_.spawn(peer->strand_, Peer::send_message(peer, message)); + } catch (const concurrency::TaskGroup::SpawnAfterCloseError&) { + log::Warning("sentry") << "Peer::post_message cannot spawn send_message after close"; + } } Task Peer::send_message(std::shared_ptr peer, Message message) { diff --git a/silkworm/sentry/rlpx/server.cpp b/silkworm/sentry/rlpx/server.cpp index 1675bd815c..b3d428714f 100644 --- a/silkworm/sentry/rlpx/server.cpp +++ b/silkworm/sentry/rlpx/server.cpp @@ -76,7 +76,18 @@ Task Server::run( while (acceptor.is_open()) { auto client_executor = executor_pool.any_executor(); SocketStream stream{client_executor}; - co_await acceptor.async_accept(stream.socket(), use_awaitable); + try { + co_await acceptor.async_accept(stream.socket(), use_awaitable); + } catch (const boost::system::system_error& ex) { + if (ex.code() == boost::system::errc::invalid_argument) { + log::Error("sentry") << "Sentry RLPx server got invalid_argument on accept port=" << port_; + // throw std::runtime_error("Sentry RLPx server got invalid_argument on accept " + std::to_string(port_)); + continue; + } else { + log::Critical("sentry") << "Sentry RLPx server unexpected end [" + std::string{ex.what()} + "]"; + throw; + } + } auto remote_endpoint = stream.socket().remote_endpoint(); log::Debug("sentry") << "rlpx::Server client connected from " << remote_endpoint; diff --git a/silkworm/sentry/sentry.cpp b/silkworm/sentry/sentry.cpp index b615b9f2cb..23572560fe 100644 --- a/silkworm/sentry/sentry.cpp +++ b/silkworm/sentry/sentry.cpp @@ -189,15 +189,24 @@ Task SentryImpl::run_tasks() { co_await status_manager_.wait_for_status(); log::Info("sentry") << "Sentry received initial status message"; - co_await ( - run_status_manager() && - run_server() && - run_discovery() && - run_peer_manager() && - run_message_sender() && - run_message_receiver() && - run_peer_manager_api() && - run_peer_discovery_feedback()); + try { + co_await ( + run_status_manager() && + run_server() && + run_discovery() && + run_peer_manager() && + run_message_sender() && + run_message_receiver() && + run_peer_manager_api() && + run_peer_discovery_feedback()); + } catch (const boost::system::system_error& se) { + if (se.code() == boost::system::errc::operation_canceled) { + log::Critical("sentry") << "Sentry run_tasks unexpected end [operation_canceled]"; + } else { + log::Critical("sentry") << "Sentry run_tasks unexpected end [" + std::string{se.what()} + "]"; + } + throw se; + } } std::unique_ptr SentryImpl::make_protocol() { @@ -234,23 +243,68 @@ Task SentryImpl::run_discovery() { } Task SentryImpl::run_peer_manager() { - return peer_manager_.run(rlpx_server_, discovery_, make_protocol(), client_factory()); + try { + return peer_manager_.run(rlpx_server_, discovery_, make_protocol(), client_factory()); + } catch (const boost::system::system_error& se) { + if (se.code() == boost::system::errc::operation_canceled) { + log::Critical("sentry") << "run_peer_manager unexpected end [operation_canceled]"; + } else { + log::Critical("sentry") << "run_peer_manager unexpected end [" + std::string{se.what()} + "]"; + } + throw se; + } } Task SentryImpl::run_message_sender() { - return message_sender_.run(peer_manager_); + try { + return message_sender_.run(peer_manager_); + } catch (const boost::system::system_error& se) { + if (se.code() == boost::system::errc::operation_canceled) { + log::Critical("sentry") << "run_message_sender unexpected end [operation_canceled]"; + } else { + log::Critical("sentry") << "run_message_sender unexpected end [" + std::string{se.what()} + "]"; + } + throw se; + } } Task SentryImpl::run_message_receiver() { - return MessageReceiver::run(message_receiver_, peer_manager_); + try { + return MessageReceiver::run(message_receiver_, peer_manager_); + } catch (const boost::system::system_error& se) { + if (se.code() == boost::system::errc::operation_canceled) { + log::Critical("sentry") << "run_message_receiver unexpected end [operation_canceled]"; + } else { + log::Critical("sentry") << "run_message_receiver unexpected end [" + std::string{se.what()} + "]"; + } + throw se; + } } Task SentryImpl::run_peer_manager_api() { - return PeerManagerApi::run(peer_manager_api_); + try { + return PeerManagerApi::run(peer_manager_api_); + } catch (const boost::system::system_error& se) { + if (se.code() == boost::system::errc::operation_canceled) { + log::Critical("sentry") << "run_peer_manager_api unexpected end [operation_canceled]"; + } else { + log::Critical("sentry") << "run_peer_manager_api unexpected end [" + std::string{se.what()} + "]"; + } + throw se; + } } Task SentryImpl::run_peer_discovery_feedback() { - return PeerDiscoveryFeedback::run(peer_discovery_feedback_, peer_manager_, discovery_); + try { + return PeerDiscoveryFeedback::run(peer_discovery_feedback_, peer_manager_, discovery_); + } catch (const boost::system::system_error& se) { + if (se.code() == boost::system::errc::operation_canceled) { + log::Critical("sentry") << "run_peer_discovery_feedback unexpected end [operation_canceled]"; + } else { + log::Critical("sentry") << "run_peer_discovery_feedback unexpected end [" + std::string{se.what()} + "]"; + } + throw se; + } } Task SentryImpl::run_grpc_server() { diff --git a/silkworm/sentry/status_manager.cpp b/silkworm/sentry/status_manager.cpp index 716182acc0..8f2fe4b2e8 100644 --- a/silkworm/sentry/status_manager.cpp +++ b/silkworm/sentry/status_manager.cpp @@ -27,9 +27,18 @@ Task StatusManager::wait_for_status() { } Task StatusManager::run() { - // loop until wait_for_status() throws a cancelled exception - while (true) { - co_await wait_for_status(); + try { + // loop until wait_for_status() throws a cancelled exception + while (true) { + co_await wait_for_status(); + } + } catch (const boost::system::system_error& se) { + if (se.code() == boost::system::errc::operation_canceled) { + log::Critical("sentry") << "StatusManager::run unexpected end [operation_canceled]"; + } else { + log::Critical("sentry") << "StatusManager::run unexpected end [" + std::string{se.what()} + "]"; + } + throw se; } } From 593cec7fc62af932d8453fa2a04fd2be3bfba9e1 Mon Sep 17 00:00:00 2001 From: canepat <16927169+canepat@users.noreply.github.com> Date: Wed, 22 May 2024 21:19:56 +0200 Subject: [PATCH 2/3] demote log verbosity for operation canceled --- silkworm/sentry/discovery/discovery.cpp | 2 +- silkworm/sentry/rlpx/server.cpp | 1 - silkworm/sentry/sentry.cpp | 12 ++++++------ silkworm/sentry/status_manager.cpp | 2 +- 4 files changed, 8 insertions(+), 9 deletions(-) diff --git a/silkworm/sentry/discovery/discovery.cpp b/silkworm/sentry/discovery/discovery.cpp index ca2d6b1ea8..2cdb662a01 100644 --- a/silkworm/sentry/discovery/discovery.cpp +++ b/silkworm/sentry/discovery/discovery.cpp @@ -242,7 +242,7 @@ Task Discovery::run() { return p_impl_->run(); } catch (const boost::system::system_error& se) { if (se.code() == boost::system::errc::operation_canceled) { - log::Critical("sentry") << "Discovery::run unexpected end [operation_canceled]"; + log::Debug("sentry") << "Discovery::run unexpected end [operation_canceled]"; } else { log::Critical("sentry") << "Discovery::run unexpected end [" + std::string{se.what()} + "]"; } diff --git a/silkworm/sentry/rlpx/server.cpp b/silkworm/sentry/rlpx/server.cpp index b3d428714f..a715b54bed 100644 --- a/silkworm/sentry/rlpx/server.cpp +++ b/silkworm/sentry/rlpx/server.cpp @@ -81,7 +81,6 @@ Task Server::run( } catch (const boost::system::system_error& ex) { if (ex.code() == boost::system::errc::invalid_argument) { log::Error("sentry") << "Sentry RLPx server got invalid_argument on accept port=" << port_; - // throw std::runtime_error("Sentry RLPx server got invalid_argument on accept " + std::to_string(port_)); continue; } else { log::Critical("sentry") << "Sentry RLPx server unexpected end [" + std::string{ex.what()} + "]"; diff --git a/silkworm/sentry/sentry.cpp b/silkworm/sentry/sentry.cpp index 23572560fe..04341b6d72 100644 --- a/silkworm/sentry/sentry.cpp +++ b/silkworm/sentry/sentry.cpp @@ -201,7 +201,7 @@ Task SentryImpl::run_tasks() { run_peer_discovery_feedback()); } catch (const boost::system::system_error& se) { if (se.code() == boost::system::errc::operation_canceled) { - log::Critical("sentry") << "Sentry run_tasks unexpected end [operation_canceled]"; + log::Debug("sentry") << "Sentry run_tasks unexpected end [operation_canceled]"; } else { log::Critical("sentry") << "Sentry run_tasks unexpected end [" + std::string{se.what()} + "]"; } @@ -247,7 +247,7 @@ Task SentryImpl::run_peer_manager() { return peer_manager_.run(rlpx_server_, discovery_, make_protocol(), client_factory()); } catch (const boost::system::system_error& se) { if (se.code() == boost::system::errc::operation_canceled) { - log::Critical("sentry") << "run_peer_manager unexpected end [operation_canceled]"; + log::Debug("sentry") << "run_peer_manager unexpected end [operation_canceled]"; } else { log::Critical("sentry") << "run_peer_manager unexpected end [" + std::string{se.what()} + "]"; } @@ -260,7 +260,7 @@ Task SentryImpl::run_message_sender() { return message_sender_.run(peer_manager_); } catch (const boost::system::system_error& se) { if (se.code() == boost::system::errc::operation_canceled) { - log::Critical("sentry") << "run_message_sender unexpected end [operation_canceled]"; + log::Debug("sentry") << "run_message_sender unexpected end [operation_canceled]"; } else { log::Critical("sentry") << "run_message_sender unexpected end [" + std::string{se.what()} + "]"; } @@ -273,7 +273,7 @@ Task SentryImpl::run_message_receiver() { return MessageReceiver::run(message_receiver_, peer_manager_); } catch (const boost::system::system_error& se) { if (se.code() == boost::system::errc::operation_canceled) { - log::Critical("sentry") << "run_message_receiver unexpected end [operation_canceled]"; + log::Debug("sentry") << "run_message_receiver unexpected end [operation_canceled]"; } else { log::Critical("sentry") << "run_message_receiver unexpected end [" + std::string{se.what()} + "]"; } @@ -286,7 +286,7 @@ Task SentryImpl::run_peer_manager_api() { return PeerManagerApi::run(peer_manager_api_); } catch (const boost::system::system_error& se) { if (se.code() == boost::system::errc::operation_canceled) { - log::Critical("sentry") << "run_peer_manager_api unexpected end [operation_canceled]"; + log::Debug("sentry") << "run_peer_manager_api unexpected end [operation_canceled]"; } else { log::Critical("sentry") << "run_peer_manager_api unexpected end [" + std::string{se.what()} + "]"; } @@ -299,7 +299,7 @@ Task SentryImpl::run_peer_discovery_feedback() { return PeerDiscoveryFeedback::run(peer_discovery_feedback_, peer_manager_, discovery_); } catch (const boost::system::system_error& se) { if (se.code() == boost::system::errc::operation_canceled) { - log::Critical("sentry") << "run_peer_discovery_feedback unexpected end [operation_canceled]"; + log::Debug("sentry") << "run_peer_discovery_feedback unexpected end [operation_canceled]"; } else { log::Critical("sentry") << "run_peer_discovery_feedback unexpected end [" + std::string{se.what()} + "]"; } diff --git a/silkworm/sentry/status_manager.cpp b/silkworm/sentry/status_manager.cpp index 8f2fe4b2e8..eced6bd7a4 100644 --- a/silkworm/sentry/status_manager.cpp +++ b/silkworm/sentry/status_manager.cpp @@ -34,7 +34,7 @@ Task StatusManager::run() { } } catch (const boost::system::system_error& se) { if (se.code() == boost::system::errc::operation_canceled) { - log::Critical("sentry") << "StatusManager::run unexpected end [operation_canceled]"; + log::Debug("sentry") << "StatusManager::run unexpected end [operation_canceled]"; } else { log::Critical("sentry") << "StatusManager::run unexpected end [" + std::string{se.what()} + "]"; } From df3c0f20743a2ccbf782947510d0e461b9f559d8 Mon Sep 17 00:00:00 2001 From: canepat <16927169+canepat@users.noreply.github.com> Date: Wed, 22 May 2024 21:22:09 +0200 Subject: [PATCH 3/3] fix shadowing --- silkworm/sentry/rlpx/peer.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/silkworm/sentry/rlpx/peer.cpp b/silkworm/sentry/rlpx/peer.cpp index 65e25b57e4..b29b24fc21 100644 --- a/silkworm/sentry/rlpx/peer.cpp +++ b/silkworm/sentry/rlpx/peer.cpp @@ -216,9 +216,9 @@ Task Peer::handle() { } log::Error("sentry") << "Peer::handle system_error: " << ex.what(); throw; - } catch (const std::nested_exception& ex) { + } catch (const std::nested_exception& ne) { try { - ex.rethrow_nested(); + ne.rethrow_nested(); } catch (const DisconnectedError&) { log::Debug("sentry") << "Peer::handle nested disconnection error"; auto reason = disconnect_reason_.get().value_or(DisconnectReason::DisconnectRequested);