Log election activity

nano/lib/stats_enums.hpp

@@ -284,6 +284,7 @@ enum class detail
 	broadcast_block_repeat,
 	confirm_once,
 	confirm_once_failed,
+	confirmation_request,
 
 	// election types
 	manual,

nano/node/election.cpp

@@ -168,12 +168,24 @@ std::chrono::milliseconds nano::election::confirm_req_time () const
 
 void nano::election::send_confirm_req (nano::confirmation_solicitor & solicitor_a)
 {
+	debug_assert (!mutex.try_lock ());
+
 	if (confirm_req_time () < (std::chrono::steady_clock::now () - last_req))
 	{
 		if (!solicitor_a.add (*this))
 		{
 			last_req = std::chrono::steady_clock::now ();
 			++confirmation_request_count;
+
+			node.stats.inc (nano::stat::type::election, nano::stat::detail::confirmation_request);
+			node.logger.debug (nano::log::type::election, "Sent confirmation request for root: {} (behavior: {}, state: {}, voters: {}, blocks: {}, duration: {}ms, confirmation requests: {})",
+			qualified_root.to_string (),
+			to_string (behavior_m),
+			to_string (state_m),
+			status.voter_count,
+			status.block_count,
+			duration ().count (),
+			confirmation_request_count.load ());
 		}
 	}
 }
@@ -196,9 +208,10 @@ bool nano::election::transition_priority ()
 	behavior_m = nano::election_behavior::priority;
 	last_vote = std::chrono::steady_clock::time_point{}; // allow new outgoing votes immediately
 
-	node.logger.debug (nano::log::type::election, "Transitioned election behavior to priority from {} for root: {}",
+	node.logger.debug (nano::log::type::election, "Transitioned election behavior to priority from {} for root: {} (duration: {}ms)",
 	to_string (behavior_m),
-	qualified_root.to_string ());
+	qualified_root.to_string (),
+	duration ().count ());
 
 	return true;
 }
@@ -252,10 +265,18 @@ void nano::election::broadcast_block (nano::confirmation_solicitor & solicitor_a
 	{
 		if (!solicitor_a.broadcast (*this))
 		{
-			node.stats.inc (nano::stat::type::election, last_block_hash.is_zero () ? nano::stat::detail::broadcast_block_initial : nano::stat::detail::broadcast_block_repeat);
-
 			last_block = std::chrono::steady_clock::now ();
 			last_block_hash = status.winner->hash ();
+
+			node.stats.inc (nano::stat::type::election, last_block_hash.is_zero () ? nano::stat::detail::broadcast_block_initial : nano::stat::detail::broadcast_block_repeat);
+			node.logger.debug (nano::log::type::election, "Broadcasting current winner: {} for root: {} (behavior: {}, state: {}, voters: {}, blocks: {}, duration: {}ms)",
+			status.winner->hash ().to_string (),
+			qualified_root.to_string (),
+			to_string (behavior_m),
+			to_string (state_m),
+			status.voter_count,
+			status.block_count,
+			duration ().count ());
 		}
 	}
 }

nano/node/vote_router.cpp

@@ -11,16 +11,6 @@
 
 using namespace std::chrono_literals;
 
-nano::stat::detail nano::to_stat_detail (nano::vote_code code)
-{
-	return nano::enum_util::cast<nano::stat::detail> (code);
-}
-
-nano::stat::detail nano::to_stat_detail (nano::vote_source source)
-{
-	return nano::enum_util::cast<nano::stat::detail> (source);
-}
-
 nano::vote_router::vote_router (nano::vote_cache & vote_cache_a, nano::recently_confirmed_cache & recently_confirmed_a) :
 	vote_cache{ vote_cache_a },
 	recently_confirmed{ recently_confirmed_a }
@@ -201,3 +191,27 @@ nano::container_info nano::vote_router::container_info () const
 	info.put ("elections", elections);
 	return info;
 }
+
+/*
+ *
+ */
+
+nano::stat::detail nano::to_stat_detail (nano::vote_code code)
+{
+	return nano::enum_util::cast<nano::stat::detail> (code);
+}
+
+std::string_view nano::to_string (nano::vote_code code)
+{
+	return nano::enum_util::name (code);
+}
+
+nano::stat::detail nano::to_stat_detail (nano::vote_source source)
+{
+	return nano::enum_util::cast<nano::stat::detail> (source);
+}
+
+std::string_view nano::to_string (nano::vote_source source)
+{
+	return nano::enum_util::name (source);
+}

nano/node/vote_router.hpp

@@ -21,6 +21,7 @@ enum class vote_code
 };
 
 nano::stat::detail to_stat_detail (vote_code);
+std::string_view to_string (vote_code);
 
 enum class vote_source
 {
@@ -30,6 +31,7 @@ enum class vote_source
 };
 
 nano::stat::detail to_stat_detail (vote_source);
+std::string_view to_string (vote_source);
 
 // This class routes votes to their associated election
 // This class holds a weak_ptr as this container does not own the elections