Constexpr check NANO_ASIO_HANDLER_TRACKING (#4562)

This commit is contained in:
Piotr Wójcik 2024-04-15 10:04:52 +02:00 committed by GitHub
commit 2b6ee636ca
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
3 changed files with 47 additions and 33 deletions

View file

@ -24,7 +24,7 @@ nano::thread_runner::thread_runner (std::shared_ptr<boost::asio::io_context> io_
try try
{ {
logger.debug (nano::log::type::thread_runner, "Thread #{} ({}) started", i, to_string (role)); logger.debug (nano::log::type::thread_runner, "Thread #{} ({}) started", i, to_string (role));
run (*io_ctx); run ();
logger.debug (nano::log::type::thread_runner, "Thread #{} ({}) stopped", i, to_string (role)); logger.debug (nano::log::type::thread_runner, "Thread #{} ({}) stopped", i, to_string (role));
} }
catch (std::exception const & ex) catch (std::exception const & ex)
@ -49,28 +49,30 @@ nano::thread_runner::~thread_runner ()
join (); join ();
} }
void nano::thread_runner::run (boost::asio::io_context & io_ctx_a) void nano::thread_runner::run ()
{ {
#if NANO_ASIO_HANDLER_TRACKING == 0 if constexpr (nano::asio_handler_tracking_threshold () == 0)
io_ctx_a.run ();
#else
nano::timer<> timer;
timer.start ();
while (true)
{ {
timer.restart (); io_ctx->run ();
// Run at most 1 completion handler and record the time it took to complete (non-blocking) }
auto count = io_ctx_a.poll_one (); else
if (count == 1 && timer.since_start ().count () >= NANO_ASIO_HANDLER_TRACKING) {
{ nano::timer<> timer;
auto timestamp = std::chrono::duration_cast<std::chrono::microseconds> (std::chrono::system_clock::now ().time_since_epoch ()).count (); timer.start ();
std::cout << (boost::format ("[%1%] io_thread held for %2%ms") % timestamp % timer.since_start ().count ()).str () << std::endl; while (true)
} {
// Sleep for a bit to give more time slices to other threads timer.restart ();
std::this_thread::sleep_for (std::chrono::milliseconds (5)); // Run at most 1 completion handler and record the time it took to complete (non-blocking)
std::this_thread::yield (); auto count = io_ctx->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 ();
}
} }
#endif
} }
void nano::thread_runner::join () void nano::thread_runner::join ()

View file

@ -31,6 +31,15 @@ private:
std::vector<boost::thread> threads; std::vector<boost::thread> threads;
private: private:
void run (boost::asio::io_context &); void run ();
}; };
constexpr unsigned asio_handler_tracking_threshold ()
{
#if NANO_ASIO_HANDLER_TRACKING == 0
return 0;
#else
return NANO_ASIO_HANDLER_TRACKING;
#endif
}
} // namespace nano } // namespace nano

View file

@ -1,5 +1,6 @@
#include <nano/crypto_lib/random_pool.hpp> #include <nano/crypto_lib/random_pool.hpp>
#include <nano/lib/blocks.hpp> #include <nano/lib/blocks.hpp>
#include <nano/lib/thread_runner.hpp>
#include <nano/node/active_transactions.hpp> #include <nano/node/active_transactions.hpp>
#include <nano/node/common.hpp> #include <nano/node/common.hpp>
#include <nano/node/transport/tcp_listener.hpp> #include <nano/node/transport/tcp_listener.hpp>
@ -335,22 +336,24 @@ void nano::test::system::deadline_set (std::chrono::duration<double, std::nano>
std::error_code nano::test::system::poll (std::chrono::nanoseconds const & wait_time) std::error_code nano::test::system::poll (std::chrono::nanoseconds const & wait_time)
{ {
#if NANO_ASIO_HANDLER_TRACKING == 0 if constexpr (nano::asio_handler_tracking_threshold () == 0)
io_ctx->run_one_for (wait_time);
#else
nano::timer<> timer;
timer.start ();
auto count = io_ctx.poll_one ();
if (count == 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::microseconds> (std::chrono::system_clock::now ().time_since_epoch ()).count (); nano::timer<> timer;
std::cout << (boost::format ("[%1%] io_thread held for %2%ms") % timestamp % timer.since_start ().count ()).str () << std::endl; 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; std::error_code ec;
if (std::chrono::steady_clock::now () > deadline) if (std::chrono::steady_clock::now () > deadline)