infra, node, sentry, sync: thread name in log traces for async_thread (…

…#1426)

cmd/dev/backend_kv_server.cpp

@@ -243,11 +243,11 @@ int main(int argc, char* argv[]) {
                 auto stop = [&state_changes_timer]() {
                     state_changes_timer.cancel();
                 };
-                co_await concurrency::async_thread(std::move(run), std::move(stop));
+                co_await concurrency::async_thread(std::move(run), std::move(stop), "state-c-sim");
             };
-            tasks = state_changes_simulator() && server.async_run();
+            tasks = state_changes_simulator() && server.async_run("bekv-server");
         } else {
-            tasks = server.async_run();
+            tasks = server.async_run("bekv-server");
         }
 
         ShutdownSignal shutdown_signal{context_pool.next_io_context()};

silkworm/infra/concurrency/active_component.hpp

@@ -29,21 +29,17 @@
 
 namespace silkworm {
 
-/*
- * Abstract interface for active components
- * i.e. component that have an infinite loop and need a dedicated thread to run the loop (if the application
- * has also other things to do).
- * Here we prefer not to provide a thread facility and let the user provide one more suitable to the context,
- * so perhaps a better name is LongRunningComponent.
- */
+//! Abstract interface for active components i.e. components that have an infinite loop and need a dedicated thread
+//! to run the loop (if the application has also other things to do).
 class ActiveComponent : public Stoppable {
   public:
     virtual void execution_loop() = 0;
 
-    boost::asio::awaitable<void> async_run(std::optional<std::size_t> stack_size = {}) {
+    //! This adapter method makes ActiveComponent suitable to be used as asynchronous task
+    boost::asio::awaitable<void> async_run(const char* thread_name, std::optional<std::size_t> stack_size = {}) {
         auto run = [this] { this->execution_loop(); };
         auto stop = [this] { this->stop(); };
-        co_await concurrency::async_thread(std::move(run), std::move(stop), stack_size);
+        co_await concurrency::async_thread(std::move(run), std::move(stop), thread_name, stack_size);
     }
 };
 

silkworm/infra/concurrency/async_thread.cpp

@@ -29,7 +29,8 @@
 
 namespace silkworm::concurrency {
 
-boost::asio::awaitable<void> async_thread(std::function<void()> run, std::function<void()> stop, std::optional<std::size_t> stack_size) {
+boost::asio::awaitable<void> async_thread(std::function<void()> run, std::function<void()> stop,
+                                          const char* name, std::optional<std::size_t> stack_size) {
     std::exception_ptr run_exception;
 
     auto executor = co_await boost::asio::this_coro::executor;
@@ -39,9 +40,13 @@ boost::asio::awaitable<void> async_thread(std::function<void()> run, std::functi
     if (stack_size) {
         attributes.set_stack_size(*stack_size);
     }
-    boost::thread thread{attributes, [run = std::move(run), &run_exception, &thread_finished_notifier] {
+
+    boost::thread thread{attributes, [run = std::move(run), name = name, &run_exception, &thread_finished_notifier] {
+                             log::set_thread_name(name);
                              try {
+                                 log::Info() << "Async thread [" << name << "] run started";
                                  run();
+                                 log::Info() << "Async thread [" << name << "] run completed";
                              } catch (...) {
                                  run_exception = std::current_exception();
                              }

silkworm/infra/concurrency/async_thread.hpp

@@ -34,10 +34,11 @@ namespace silkworm::concurrency {
  *
  * @param run thread procedure
  * @param stop a callback to signal the thread procedure to exit
+ * @param name the name appearing in log traces for the created thread
  * @param stack_size optional custom stack size for the created thread
  * @return an awaitable that is pending until the thread finishes
  */
 boost::asio::awaitable<void> async_thread(std::function<void()> run, std::function<void()> stop,
-                                          std::optional<std::size_t> stack_size = {});
+                                          const char* name, std::optional<std::size_t> stack_size = {});
 
 }  // namespace silkworm::concurrency

silkworm/infra/grpc/client/reconnect.cpp

@@ -45,7 +45,7 @@ boost::asio::awaitable<void> reconnect_channel(grpc::Channel& channel) {
         is_stopped = true;
     };
 
-    co_await concurrency::async_thread(std::move(run), std::move(stop));
+    co_await concurrency::async_thread(std::move(run), std::move(stop), "channel-rec");
 }
 
 }  // namespace silkworm::rpc

silkworm/infra/grpc/server/server.hpp

@@ -131,13 +131,13 @@ class Server {
         SILK_TRACE << "Server::shutdown " << this << " END";
     }
 
-    boost::asio::awaitable<void> async_run() {
+    boost::asio::awaitable<void> async_run(const char* thread_name) {
         auto run = [this] {
             this->build_and_start();
             this->join();
         };
         auto stop = [this] { this->shutdown(); };
-        co_await concurrency::async_thread(std::move(run), std::move(stop));
+        co_await concurrency::async_thread(std::move(run), std::move(stop), thread_name);
     }
 
     //! Returns the number of server contexts.

silkworm/node/node.cpp

@@ -133,7 +133,7 @@ Task<void> NodeImpl::run_tasks() {
 
 Task<void> NodeImpl::start_execution_server() {
     // Thread running block execution requires custom stack size because of deep EVM call stacks
-    return execution_server_.async_run(/*stack_size=*/kExecutionThreadStackSize);
+    return execution_server_.async_run("exec-engine", /*stack_size=*/kExecutionThreadStackSize);
 }
 
 Task<void> NodeImpl::start_backend_kv_grpc_server() {
@@ -144,7 +144,7 @@ Task<void> NodeImpl::start_backend_kv_grpc_server() {
     auto stop = [this]() {
         backend_kv_rpc_server_->shutdown();
     };
-    co_await concurrency::async_thread(std::move(run), std::move(stop));
+    co_await concurrency::async_thread(std::move(run), std::move(stop), "bekv-server");
 }
 
 Task<void> NodeImpl::start_bittorrent_client() {
@@ -155,7 +155,7 @@ Task<void> NodeImpl::start_bittorrent_client() {
         auto stop = [this]() {
             bittorrent_client_->stop();
         };
-        co_await concurrency::async_thread(std::move(run), std::move(stop));
+        co_await concurrency::async_thread(std::move(run), std::move(stop), "bit-torrent");
     }
 }
 
@@ -169,13 +169,13 @@ Task<void> NodeImpl::start_execution_log_timer() {
     auto asio_guard = std::make_unique<asio_guard_type>(settings_.asio_context.get_executor());
 
     auto run = [this] {
-        log::set_thread_name("asio_ctx_timer");
+        log::set_thread_name("ctx-log-tmr");
         log::Trace("Asio Timers", {"state", "started"});
         settings_.asio_context.run();
         log::Trace("Asio Timers", {"state", "stopped"});
     };
     auto stop = [&asio_guard] { asio_guard.reset(); };
-    co_await silkworm::concurrency::async_thread(std::move(run), std::move(stop));
+    co_await silkworm::concurrency::async_thread(std::move(run), std::move(stop), "ctx-log-tmr");
 }
 
 Node::Node(Settings& settings, SentryClientPtr sentry_client, mdbx::env& chaindata_db)

silkworm/sentry/grpc/server/server.cpp

@@ -117,7 +117,7 @@ Server::~Server() {
 }
 
 Task<void> Server::async_run() {
-    return p_impl_->async_run();
+    return p_impl_->async_run("sentry-gsrv");
 }
 
 }  // namespace silkworm::sentry::grpc::server

silkworm/sync/block_exchange.cpp

@@ -68,7 +68,6 @@ void BlockExchange::receive_message(std::shared_ptr<InboundMessage> message) {
 void BlockExchange::execution_loop() {
     using namespace std::chrono;
     using namespace std::chrono_literals;
-    log::set_thread_name("block-exchg");
 
     auto announcement_receiving_callback = [this](std::shared_ptr<InboundMessage> msg) {
         statistics_.nonsolic_msgs++;

silkworm/sync/sync.cpp

@@ -90,7 +90,7 @@ boost::asio::awaitable<void> Sync::start_sync_sentry_client() {
 }
 
 boost::asio::awaitable<void> Sync::start_block_exchange() {
-    return block_exchange_.async_run();
+    return block_exchange_.async_run("block-exchg");
 }
 
 boost::asio::awaitable<void> Sync::start_chain_sync() {
@@ -113,7 +113,9 @@ boost::asio::awaitable<void> Sync::start_engine_rpc_server() {
         auto engine_rpc_server_stop = [this]() {
             engine_rpc_server_->stop();
         };
-        co_await concurrency::async_thread(std::move(engine_rpc_server_run), std::move(engine_rpc_server_stop));
+        co_await concurrency::async_thread(std::move(engine_rpc_server_run),
+                                           std::move(engine_rpc_server_stop),
+                                           "eng-api-srv");
     }
 }
 

silkworm/sync/sync_pow.cpp

@@ -29,7 +29,7 @@ namespace silkworm::chainsync {
 PoWSync::PoWSync(BlockExchange& be, execution::Client& ee) : ChainSync(be, ee) {}
 
 asio::awaitable<void> PoWSync::async_run() {
-    return ActiveComponent::async_run();
+    return ActiveComponent::async_run("pow-sync-ex");
 }
 
 auto PoWSync::resume() -> NewHeight {  // find the point (head) where we left off