diff --git a/nano/lib/thread_runner.cpp b/nano/lib/thread_runner.cpp index 62a7625cd1..c41ab5ceeb 100644 --- a/nano/lib/thread_runner.cpp +++ b/nano/lib/thread_runner.cpp @@ -51,26 +51,28 @@ nano::thread_runner::~thread_runner () void nano::thread_runner::run (boost::asio::io_context & io_ctx_a) { -#if NANO_ASIO_HANDLER_TRACKING == 0 - io_ctx_a.run (); -#else - nano::timer<> timer; - timer.start (); - while (true) + if constexpr (nano::asio_handler_tracking_threshold () == 0) { - timer.restart (); - // Run at most 1 completion handler and record the time it took to complete (non-blocking) - auto count = io_ctx_a.poll_one (); - if (count == 1 && timer.since_start ().count () >= NANO_ASIO_HANDLER_TRACKING) + io_ctx_a.run (); + } + else + { + nano::timer<> timer; + timer.start (); + while (true) { - auto timestamp = std::chrono::duration_cast (std::chrono::system_clock::now ().time_since_epoch ()).count (); - std::cout << (boost::format ("[%1%] io_thread held for %2%ms") % timestamp % timer.since_start ().count ()).str () << std::endl; + timer.restart (); + // Run at most 1 completion handler and record the time it took to complete (non-blocking) + auto count = io_ctx_a.poll_one (); + if (count == 1 && timer.since_start ().count () >= nano::asio_handler_tracking_threshold ()) + { + logger.warn (nano::log::type::system, "Async handler processing took too long: {}ms", timer.since_start ().count ()); + } + // Sleep for a bit to give more time slices to other threads + std::this_thread::sleep_for (std::chrono::milliseconds (5)); + std::this_thread::yield (); } - // Sleep for a bit to give more time slices to other threads - std::this_thread::sleep_for (std::chrono::milliseconds (5)); - std::this_thread::yield (); } -#endif } void nano::thread_runner::join () diff --git a/nano/lib/thread_runner.hpp b/nano/lib/thread_runner.hpp index 116a1aa65b..266ee6c48e 100644 --- a/nano/lib/thread_runner.hpp +++ b/nano/lib/thread_runner.hpp @@ -33,4 +33,13 @@ class thread_runner final private: void run (boost::asio::io_context &); }; + +constexpr unsigned asio_handler_tracking_threshold () +{ +#if NANO_ASIO_HANDLER_TRACKING == 0 + return 0; +#else + return NANO_ASIO_HANDLER_TRACKING; +#endif +} } // namespace nano diff --git a/nano/test_common/system.cpp b/nano/test_common/system.cpp index d5bc43b1d0..fda7ffbc8b 100644 --- a/nano/test_common/system.cpp +++ b/nano/test_common/system.cpp @@ -1,5 +1,6 @@ #include #include +#include #include #include #include @@ -335,22 +336,24 @@ void nano::test::system::deadline_set (std::chrono::duration std::error_code nano::test::system::poll (std::chrono::nanoseconds const & wait_time) { -#if NANO_ASIO_HANDLER_TRACKING == 0 - io_ctx->run_one_for (wait_time); -#else - nano::timer<> timer; - timer.start (); - auto count = io_ctx.poll_one (); - if (count == 0) + if constexpr (nano::asio_handler_tracking_threshold () == 0) { - std::this_thread::sleep_for (wait_time); + io_ctx->run_one_for (wait_time); } - else if (count == 1 && timer.since_start ().count () >= NANO_ASIO_HANDLER_TRACKING) + else { - auto timestamp = std::chrono::duration_cast (std::chrono::system_clock::now ().time_since_epoch ()).count (); - std::cout << (boost::format ("[%1%] io_thread held for %2%ms") % timestamp % timer.since_start ().count ()).str () << std::endl; + nano::timer<> timer; + timer.start (); + auto count = io_ctx->poll_one (); + if (count == 0) + { + std::this_thread::sleep_for (wait_time); + } + else if (count == 1 && timer.since_start ().count () >= nano::asio_handler_tracking_threshold ()) + { + logger.warn (nano::log::type::system, "Async handler processing took too long: {}ms", timer.since_start ().count ()); + } } -#endif std::error_code ec; if (std::chrono::steady_clock::now () > deadline)