Debug log cemented blocks

nano/core_test/confirming_set.cpp

@@ -20,14 +20,14 @@ TEST (confirming_set, construction)
 {
 	auto ctx = nano::test::ledger_empty ();
 	nano::confirming_set_config config{};
-	nano::confirming_set confirming_set{ config, ctx.ledger (), ctx.stats () };
+	nano::confirming_set confirming_set{ config, ctx.ledger (), ctx.stats (), ctx.logger () };
 }
 
 TEST (confirming_set, add_exists)
 {
 	auto ctx = nano::test::ledger_send_receive ();
 	nano::confirming_set_config config{};
-	nano::confirming_set confirming_set{ config, ctx.ledger (), ctx.stats () };
+	nano::confirming_set confirming_set{ config, ctx.ledger (), ctx.stats (), ctx.logger () };
 	auto send = ctx.blocks ()[0];
 	confirming_set.add (send->hash ());
 	ASSERT_TRUE (confirming_set.contains (send->hash ()));
@@ -37,7 +37,7 @@ TEST (confirming_set, process_one)
 {
 	auto ctx = nano::test::ledger_send_receive ();
 	nano::confirming_set_config config{};
-	nano::confirming_set confirming_set{ config, ctx.ledger (), ctx.stats () };
+	nano::confirming_set confirming_set{ config, ctx.ledger (), ctx.stats (), ctx.logger () };
 	std::atomic<int> count = 0;
 	std::mutex mutex;
 	std::condition_variable condition;
@@ -54,7 +54,7 @@ TEST (confirming_set, process_multiple)
 {
 	auto ctx = nano::test::ledger_send_receive ();
 	nano::confirming_set_config config{};
-	nano::confirming_set confirming_set{ config, ctx.ledger (), ctx.stats () };
+	nano::confirming_set confirming_set{ config, ctx.ledger (), ctx.stats (), ctx.logger () };
 	std::atomic<int> count = 0;
 	std::mutex mutex;
 	std::condition_variable condition;

nano/lib/logging_enums.hpp

@@ -82,6 +82,7 @@ enum class type
 	message_processor,
 	local_block_broadcaster,
 	monitor,
+	confirming_set,
 
 	// bootstrap
 	bulk_pull_client,

nano/lib/stats_enums.hpp

@@ -505,6 +505,7 @@ enum class detail
 	already_cemented,
 	cementing,
 	cemented_hash,
+	cementing_failed,
 
 	// election_state
 	passive,

nano/node/confirming_set.cpp

@@ -1,3 +1,4 @@
+#include <nano/lib/logging.hpp>
 #include <nano/lib/thread_roles.hpp>
 #include <nano/node/confirming_set.hpp>
 #include <nano/secure/ledger.hpp>
@@ -6,10 +7,11 @@
 #include <nano/store/component.hpp>
 #include <nano/store/write_queue.hpp>
 
-nano::confirming_set::confirming_set (confirming_set_config const & config_a, nano::ledger & ledger_a, nano::stats & stats_a) :
+nano::confirming_set::confirming_set (confirming_set_config const & config_a, nano::ledger & ledger_a, nano::stats & stats_a, nano::logger & logger_a) :
 	config{ config_a },
 	ledger{ ledger_a },
 	stats{ stats_a },
+	logger{ logger_a },
 	notification_workers{ 1, nano::thread_role::name::confirmation_height_notifications }
 {
 	batch_cemented.add ([this] (auto const & cemented) {
@@ -177,6 +179,8 @@ void nano::confirming_set::run_batch (std::unique_lock<std::mutex> & lock)
 		auto transaction = ledger.tx_begin_write (nano::store::writer::confirmation_height);
 		for (auto const & [hash, election] : batch)
 		{
+			size_t cemented_count = 0;
+			bool success = false;
 			do
 			{
 				transaction.refresh_if_needed ();
@@ -208,6 +212,7 @@ void nano::confirming_set::run_batch (std::unique_lock<std::mutex> & lock)
 					{
 						cemented.push_back ({ block, hash, election });
 					}
+					cemented_count += added.size ();
 				}
 				else
 				{
@@ -215,9 +220,20 @@ void nano::confirming_set::run_batch (std::unique_lock<std::mutex> & lock)
 					already.push_back (hash);
 					debug_assert (ledger.confirmed.block_exists (transaction, hash));
 				}
-			} while (!ledger.confirmed.block_exists (transaction, hash));
 
-			stats.inc (nano::stat::type::confirming_set, nano::stat::detail::cemented_hash);
+				success = ledger.confirmed.block_exists (transaction, hash);
+			} while (!success);
+
+			if (success)
+			{
+				stats.inc (nano::stat::type::confirming_set, nano::stat::detail::cemented_hash);
+				logger.debug (nano::log::type::confirming_set, "Cemented block: {} (total cemented: {})", hash.to_string (), cemented_count);
+			}
+			else
+			{
+				stats.inc (nano::stat::type::confirming_set, nano::stat::detail::cementing_failed);
+				logger.debug (nano::log::type::confirming_set, "Failed to cement block: {}", hash.to_string ());
+			}
 		}
 	}
 

nano/node/confirming_set.hpp

@@ -45,7 +45,7 @@ class confirming_set final
 	friend class confirmation_height_pruned_source_Test;
 
 public:
-	confirming_set (confirming_set_config const &, nano::ledger &, nano::stats &);
+	confirming_set (confirming_set_config const &, nano::ledger &, nano::stats &, nano::logger &);
 	~confirming_set ();
 
 	void start ();
@@ -76,6 +76,7 @@ private: // Dependencies
 	confirming_set_config const & config;
 	nano::ledger & ledger;
 	nano::stats & stats;
+	nano::logger & logger;
 
 private:
 	struct entry

nano/node/node.cpp

@@ -115,7 +115,7 @@ nano::node::node (std::shared_ptr<boost::asio::io_context> io_ctx_a, std::filesy
 	port_mapping_impl{ std::make_unique<nano::port_mapping> (*this) },
 	port_mapping{ *port_mapping_impl },
 	block_processor (*this),
-	confirming_set_impl{ std::make_unique<nano::confirming_set> (config.confirming_set, ledger, stats) },
+	confirming_set_impl{ std::make_unique<nano::confirming_set> (config.confirming_set, ledger, stats, logger) },
 	confirming_set{ *confirming_set_impl },
 	active_impl{ std::make_unique<nano::active_elections> (*this, confirming_set, block_processor) },
 	active{ *active_impl },

nano/test_common/ledger_context.cpp

@@ -4,8 +4,8 @@
 #include <nano/test_common/ledger_context.hpp>
 
 nano::test::ledger_context::ledger_context (std::deque<std::shared_ptr<nano::block>> && blocks) :
-	store_m{ nano::make_store (logger, nano::unique_path (), nano::dev::constants) },
+	store_m{ nano::make_store (logger_m, nano::unique_path (), nano::dev::constants) },
-	stats_m{ logger },
+	stats_m{ logger_m },
 	ledger_m{ *store_m, stats_m, nano::dev::constants },
 	blocks_m{ blocks },
 	pool_m{ nano::dev::network_params.network, 1 }
@@ -35,6 +35,11 @@ nano::stats & nano::test::ledger_context::stats ()
 	return stats_m;
 }
 
+nano::logger & nano::test::ledger_context::logger ()
+{
+	return logger_m;
+}
+
 std::deque<std::shared_ptr<nano::block>> const & nano::test::ledger_context::blocks () const
 {
 	return blocks_m;

nano/test_common/ledger_context.hpp

@@ -16,12 +16,13 @@ public:
 	ledger_context (std::deque<std::shared_ptr<nano::block>> && blocks = std::deque<std::shared_ptr<nano::block>>{});
 	nano::ledger & ledger ();
 	nano::store::component & store ();
-	nano::stats & stats ();
 	std::deque<std::shared_ptr<nano::block>> const & blocks () const;
 	nano::work_pool & pool ();
+	nano::stats & stats ();
+	nano::logger & logger ();
 
 private:
-	nano::logger logger;
+	nano::logger logger_m;
 	std::unique_ptr<nano::store::component> store_m;
 	nano::stats stats_m;
 	nano::ledger ledger_m;