Stats & logs

nano/lib/stats_enums.hpp

@@ -112,7 +112,12 @@ enum class detail : uint8_t
 	representative_mismatch,
 	block_position,
 
-	// blockprocessor result
+	// blockprocessor
+	process_blocking,
+	process_blocking_timeout,
+	force,
+
+	// block source
 	live,
 	bootstrap,
 	bootstrap_legacy,

nano/node/blockprocessor.cpp

@@ -88,14 +88,22 @@ void nano::block_processor::add (std::shared_ptr<nano::block> const & block, blo
 		node.stats.inc (nano::stat::type::blockprocessor, nano::stat::detail::insufficient_work);
 		return;
 	}
+
+	node.stats.inc (nano::stat::type::blockprocessor, nano::stat::detail::process);
+	node.logger.debug (nano::log::type::blockprocessor, "Processing block (async): {} (source: {})", block->hash ().to_string (), to_string (source));
+
 	add_impl (block, context{ source });
 }
 
 std::optional<nano::process_return> nano::block_processor::add_blocking (std::shared_ptr<nano::block> const & block, block_source const source)
 {
+	node.stats.inc (nano::stat::type::blockprocessor, nano::stat::detail::process_blocking);
+	node.logger.debug (nano::log::type::blockprocessor, "Processing block (blocking): {} (source: {})", block->hash ().to_string (), to_string (source));
+
 	context ctx{ source };
 	auto future = ctx.get_future ();
 	add_impl (block, std::move (ctx));
+
 	try
 	{
 		auto status = future.wait_for (node.config.block_process_timeout);
@@ -107,10 +115,25 @@ std::optional<nano::process_return> nano::block_processor::add_blocking (std::sh
 	}
 	catch (std::future_error const &)
 	{
+		node.stats.inc (nano::stat::type::blockprocessor, nano::stat::detail::process_blocking_timeout);
+		node.logger.error (nano::log::type::blockprocessor, "Timeout processing block: {}", block->hash ().to_string ());
 	}
+
 	return std::nullopt;
 }
 
+void nano::block_processor::force (std::shared_ptr<nano::block> const & block_a)
+{
+	node.stats.inc (nano::stat::type::blockprocessor, nano::stat::detail::force);
+	node.logger.debug (nano::log::type::blockprocessor, "Forcing block: {}", block_a->hash ().to_string ());
+
+	{
+		nano::lock_guard<nano::mutex> lock{ mutex };
+		forced.emplace_back (entry{ block_a, context{ block_source::forced } });
+	}
+	condition.notify_all ();
+}
+
 void nano::block_processor::rollback_competitor (store::write_transaction const & transaction, nano::block const & block)
 {
 	auto hash = block.hash ();
@@ -143,15 +166,6 @@ void nano::block_processor::rollback_competitor (store::write_transaction const
 	}
 }
 
-void nano::block_processor::force (std::shared_ptr<nano::block> const & block_a)
-{
-	{
-		nano::lock_guard<nano::mutex> lock{ mutex };
-		forced.emplace_back (entry{ block_a, context{ block_source::forced } });
-	}
-	condition.notify_all ();
-}
-
 void nano::block_processor::process_blocks ()
 {
 	nano::unique_lock<nano::mutex> lock{ mutex };
@@ -415,6 +429,11 @@ std::unique_ptr<nano::container_info_component> nano::collect_container_info (bl
 	return composite;
 }
 
+std::string_view nano::to_string (nano::block_source source)
+{
+	return magic_enum::enum_name (source);
+}
+
 nano::stat::detail nano::to_stat_detail (nano::block_source type)
 {
 	auto value = magic_enum::enum_cast<nano::stat::detail> (magic_enum::enum_name (type));

nano/node/blockprocessor.hpp

@@ -31,6 +31,7 @@ enum class block_source
 	forced,
 };
 
+std::string_view to_string (nano::block_source);
 nano::stat::detail to_stat_detail (block_source);
 
 /**