From 6ad5e6444219c7a88f704dd614fe8314b4ac8442 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Piotr=20W=C3=B3jcik?= <3044353+pwojcikdev@users.noreply.github.com> Date: Mon, 14 Apr 2025 16:04:48 +0200 Subject: [PATCH] Log stale election info (#4874) * Log stale election info * Workaround gcc bug --- nano/node/active_elections.cpp | 35 ++++++++++++++++++++++++++++------ nano/node/election.cpp | 25 +++++++++++++++++++++++- nano/node/election.hpp | 6 ++++++ 3 files changed, 59 insertions(+), 7 deletions(-) diff --git a/nano/node/active_elections.cpp b/nano/node/active_elections.cpp index f67a6c95e..1733bca16 100644 --- a/nano/node/active_elections.cpp +++ b/nano/node/active_elections.cpp @@ -302,6 +302,16 @@ void nano::active_elections::tick_elections (nano::unique_lock & lo for (auto const & election : stale_elections) { + node.logger.debug (nano::log::type::active_elections, "Bootstrapping account: {} with stale election with root: {}, blocks: {} (behavior: {}, state: {}, voters: {}, blocks: {}, duration: {}ms)", + election->account (), + election->qualified_root, + fmt::join (election->blocks_hashes (), ", "), // TODO: Lazy eval + to_string (election->behavior ()), + to_string (election->state ()), + election->voter_count (), + election->block_count (), + election->duration ().count ()); + node.bootstrap.prioritize (election->account ()); } } @@ -333,10 +343,14 @@ void nano::active_elections::cleanup_election (nano::unique_lock & node.logger.trace (nano::log::type::active_elections, nano::log::detail::active_stopped, nano::log::arg{ "election", election }); - node.logger.debug (nano::log::type::active_elections, "Erased election for blocks: {} (behavior: {}, state: {})", - fmt::join (std::views::keys (blocks_l), ", "), + node.logger.debug (nano::log::type::active_elections, "Erased election for root: {} with blocks: {} (behavior: {}, state: {}, voters: {}, blocks: {}, duration: {}ms)", + election->qualified_root, + fmt::join (election->blocks_hashes (), ", "), // TODO: Lazy eval to_string (election->behavior ()), - to_string (election->state ())); + to_string (election->state ()), + election->voter_count (), + election->block_count (), + election->duration ().count ()); lock_a.unlock (); @@ -444,8 +458,9 @@ nano::election_insertion_result nano::active_elections::insert (std::shared_ptr< nano::log::arg{ "behavior", election_behavior_a }, nano::log::arg{ "election", result.election }); - node.logger.debug (nano::log::type::active_elections, "Started new election for block: {} (behavior: {}, active immediately: {})", - hash, + node.logger.debug (nano::log::type::active_elections, "Started new election for root: {} with blocks: {} (behavior: {}, active immediately: {})", + root, + fmt::join (result.election->blocks_hashes (), ", "), // TODO: Lazy eval to_string (election_behavior_a), activate_immediately); } @@ -595,7 +610,15 @@ bool nano::active_elections::publish (std::shared_ptr const & block node.vote_cache_processor.trigger (block_a->hash ()); node.stats.inc (nano::stat::type::active, nano::stat::detail::election_block_conflict); - node.logger.debug (nano::log::type::active_elections, "Block was added to an existing election: {}", block_a->hash ()); + + node.logger.debug (nano::log::type::active_elections, "Block was added to an existing election: {} with root: {} (behavior: {}, state: {}, voters: {}, blocks: {}, duration: {}ms)", + block_a->hash (), + election->qualified_root, + to_string (election->behavior ()), + to_string (election->state ()), + election->voter_count (), + election->block_count (), + election->duration ().count ()); } } return result; diff --git a/nano/node/election.cpp b/nano/node/election.cpp index c9756b624..893b845c3 100644 --- a/nano/node/election.cpp +++ b/nano/node/election.cpp @@ -566,7 +566,7 @@ nano::vote_code nano::election::vote (nano::account const & rep, uint64_t timest nano::log::arg{ "vote_source", vote_source_a }, nano::log::arg{ "weight", weight }); - node.logger.debug (nano::log::type::election, "Vote received for: {} from: {} root: {} (final: {}, weight: {}, source: {})", + node.logger.debug (nano::log::type::election, "Vote received for hash: {} from: {} for root: {} (final: {}, weight: {}, source: {})", block_hash_a, rep, qualified_root, @@ -811,6 +811,17 @@ nano::account nano::election::account () const return status.winner->account (); } +std::unordered_set nano::election::blocks_hashes () const +{ + nano::lock_guard guard{ mutex }; + std::unordered_set hashes; + for (auto const & block : last_blocks) + { + hashes.emplace (block.first); + } + return hashes; +} + std::unordered_map> nano::election::blocks () const { nano::lock_guard guard{ mutex }; @@ -860,6 +871,18 @@ bool nano::election::contains (nano::block_hash const & hash) const return last_blocks.contains (hash); } +size_t nano::election::voter_count () const +{ + nano::lock_guard guard{ mutex }; + return last_votes.size (); +} + +size_t nano::election::block_count () const +{ + nano::lock_guard guard{ mutex }; + return last_blocks.size (); +} + void nano::election::operator() (nano::object_stream & obs) const { obs.write ("id", id); diff --git a/nano/node/election.hpp b/nano/node/election.hpp index 9dcb50419..0db4b7ac7 100644 --- a/nano/node/election.hpp +++ b/nano/node/election.hpp @@ -11,6 +11,8 @@ #include #include #include +#include +#include namespace nano { @@ -149,8 +151,12 @@ public: // Information std::unordered_map votes () const; std::unordered_map> blocks () const; + std::unordered_set blocks_hashes () const; bool contains (nano::block_hash const &) const; + size_t voter_count () const; + size_t block_count () const; + private: nano::tally_t tally_impl () const; bool confirmed_locked () const;