From e38d9bf96d269e10ecd341686e077e4eb329ca27 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Piotr=20Wo=CC=81jcik?= <3044353+pwojcikdev@users.noreply.github.com> Date: Tue, 21 Jan 2025 17:39:17 +0100 Subject: [PATCH] Lazy log formatting --- nano/lib/CMakeLists.txt | 2 + nano/lib/common.hpp | 2 + nano/lib/formatting.cpp | 1 + nano/lib/formatting.hpp | 61 +++++++++++++++++++++++ nano/lib/logging.hpp | 1 + nano/lib/numbers.hpp | 39 --------------- nano/node/active_elections.cpp | 4 +- nano/node/bootstrap/bootstrap_service.cpp | 16 +++--- nano/node/bounded_backlog.cpp | 2 +- nano/node/confirming_set.cpp | 4 +- nano/node/distributed_work.cpp | 56 +++++++++------------ nano/node/election.cpp | 29 ++++++----- nano/node/epoch_upgrader.cpp | 2 +- nano/node/local_block_broadcaster.cpp | 2 +- nano/node/node.cpp | 2 +- nano/node/repcrawler.cpp | 16 +++--- nano/node/request_aggregator.cpp | 11 ++-- nano/node/scheduler/priority.cpp | 2 +- nano/node/transport/tcp_listener.cpp | 26 ++++------ 19 files changed, 144 insertions(+), 134 deletions(-) create mode 100644 nano/lib/formatting.cpp create mode 100644 nano/lib/formatting.hpp diff --git a/nano/lib/CMakeLists.txt b/nano/lib/CMakeLists.txt index c05152a28..3e4d9a236 100644 --- a/nano/lib/CMakeLists.txt +++ b/nano/lib/CMakeLists.txt @@ -55,6 +55,8 @@ add_library( errors.cpp files.hpp files.cpp + formatting.hpp + formatting.cpp fwd.hpp id_dispenser.hpp interval.hpp diff --git a/nano/lib/common.hpp b/nano/lib/common.hpp index 1e54097d0..990aab302 100644 --- a/nano/lib/common.hpp +++ b/nano/lib/common.hpp @@ -2,6 +2,7 @@ namespace boost::asio::ip { +class address; class tcp; template class basic_endpoint; @@ -9,6 +10,7 @@ class basic_endpoint; namespace nano { +using ip_address = boost::asio::ip::address; using endpoint = boost::asio::ip::basic_endpoint; using tcp_endpoint = endpoint; } diff --git a/nano/lib/formatting.cpp b/nano/lib/formatting.cpp new file mode 100644 index 000000000..d103a1589 --- /dev/null +++ b/nano/lib/formatting.cpp @@ -0,0 +1 @@ +#include diff --git a/nano/lib/formatting.hpp b/nano/lib/formatting.hpp new file mode 100644 index 000000000..fc16806a0 --- /dev/null +++ b/nano/lib/formatting.hpp @@ -0,0 +1,61 @@ +#pragma once + +#include +#include + +#include + +template <> +struct fmt::formatter : fmt::ostream_formatter +{ +}; +template <> +struct fmt::formatter : fmt::ostream_formatter +{ +}; + +template <> +struct fmt::formatter : fmt::ostream_formatter +{ +}; +template <> +struct fmt::formatter : fmt::ostream_formatter +{ +}; +template <> +struct fmt::formatter : fmt::ostream_formatter +{ +}; + +template <> +struct fmt::formatter : fmt::ostream_formatter +{ +}; +template <> +struct fmt::formatter : fmt::ostream_formatter +{ +}; +template <> +struct fmt::formatter : fmt::ostream_formatter +{ +}; +template <> +struct fmt::formatter : fmt::ostream_formatter +{ +}; +template <> +struct fmt::formatter : fmt::formatter +{ +}; +template <> +struct fmt::formatter : fmt::formatter +{ +}; +template <> +struct fmt::formatter : fmt::formatter +{ +}; +template <> +struct fmt::formatter : fmt::formatter +{ +}; diff --git a/nano/lib/logging.hpp b/nano/lib/logging.hpp index ae9563300..2e6d60173 100644 --- a/nano/lib/logging.hpp +++ b/nano/lib/logging.hpp @@ -1,5 +1,6 @@ #pragma once +#include #include #include #include diff --git a/nano/lib/numbers.hpp b/nano/lib/numbers.hpp index 728947d27..5702413c1 100644 --- a/nano/lib/numbers.hpp +++ b/nano/lib/numbers.hpp @@ -617,42 +617,3 @@ struct hash<::nano::uint512_union>; template <> struct hash<::nano::qualified_root>; } - -/* - * Formatters - */ - -template <> -struct fmt::formatter : fmt::ostream_formatter -{ -}; - -template <> -struct fmt::formatter : fmt::ostream_formatter -{ -}; - -template <> -struct fmt::formatter : fmt::ostream_formatter -{ -}; - -template <> -struct fmt::formatter : fmt::ostream_formatter -{ -}; - -template <> -struct fmt::formatter : fmt::formatter -{ -}; - -template <> -struct fmt::formatter : fmt::formatter -{ -}; - -template <> -struct fmt::formatter : fmt::formatter -{ -}; diff --git a/nano/node/active_elections.cpp b/nano/node/active_elections.cpp index 5bd27fdc5..bf099c4f8 100644 --- a/nano/node/active_elections.cpp +++ b/nano/node/active_elections.cpp @@ -440,7 +440,7 @@ nano::election_insertion_result nano::active_elections::insert (std::shared_ptr< nano::log::arg{ "election", result.election }); node.logger.debug (nano::log::type::active_elections, "Started new election for block: {} (behavior: {}, active immediately: {})", - hash.to_string (), + hash, to_string (election_behavior_a), activate_immediately); } @@ -578,7 +578,7 @@ 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 ().to_string ()); + node.logger.debug (nano::log::type::active_elections, "Block was added to an existing election: {}", block_a->hash ()); } } return result; diff --git a/nano/node/bootstrap/bootstrap_service.cpp b/nano/node/bootstrap/bootstrap_service.cpp index 2e8bd7425..e69b3d5c2 100644 --- a/nano/node/bootstrap/bootstrap_service.cpp +++ b/nano/node/bootstrap/bootstrap_service.cpp @@ -542,8 +542,8 @@ bool nano::bootstrap_service::request (nano::account account, size_t count, std: tag.hash = info->head; logger.debug (nano::log::type::bootstrap, "Requesting blocks for {} starting from account frontier: {} (optimistic: {})", - account.to_account (), // TODO: Lazy eval - tag.start.to_string (), // TODO: Lazy eval + account, + tag.start, optimistic_reuest); } else // Pessimistic (safe) request case @@ -557,8 +557,8 @@ bool nano::bootstrap_service::request (nano::account account, size_t count, std: tag.hash = conf_info->height; logger.debug (nano::log::type::bootstrap, "Requesting blocks for {} starting from confirmation frontier: {} (optimistic: {})", - account.to_account (), // TODO: Lazy eval - tag.start.to_string (), // TODO: Lazy eval + account, + tag.start, optimistic_reuest); } else @@ -567,7 +567,7 @@ bool nano::bootstrap_service::request (nano::account account, size_t count, std: tag.start = account; logger.debug (nano::log::type::bootstrap, "Requesting blocks for {} starting from account root (optimistic: {})", - account.to_account (), // TODO: Lazy eval + account, optimistic_reuest); } } @@ -579,7 +579,7 @@ bool nano::bootstrap_service::request (nano::account account, size_t count, std: tag.type = query_type::blocks_by_account; tag.start = account; - logger.debug (nano::log::type::bootstrap, "Requesting blocks for {}", account.to_account ()); // TODO: Lazy eval + logger.debug (nano::log::type::bootstrap, "Requesting blocks for {}", account); } } @@ -594,7 +594,7 @@ bool nano::bootstrap_service::request_info (nano::block_hash hash, std::shared_p tag.start = hash; tag.hash = hash; - logger.debug (nano::log::type::bootstrap, "Requesting account info for: {}", hash.to_string ()); // TODO: Lazy eval + logger.debug (nano::log::type::bootstrap, "Requesting account info for: {}", hash); return send (channel, tag); } @@ -606,7 +606,7 @@ bool nano::bootstrap_service::request_frontiers (nano::account start, std::share tag.source = source; tag.start = start; - logger.debug (nano::log::type::bootstrap, "Requesting frontiers starting from: {}", start.to_account ()); // TODO: Lazy eval + logger.debug (nano::log::type::bootstrap, "Requesting frontiers starting from: {}", start); return send (channel, tag); } diff --git a/nano/node/bounded_backlog.cpp b/nano/node/bounded_backlog.cpp index 8f9e9f833..41ec17210 100644 --- a/nano/node/bounded_backlog.cpp +++ b/nano/node/bounded_backlog.cpp @@ -292,7 +292,7 @@ std::deque nano::bounded_backlog::perform_rollbacks (std::dequ // Here we check that the block is still OK to rollback, there could be a delay between gathering the targets and performing the rollbacks if (auto block = ledger.any.block_get (transaction, hash)) { - logger.debug (nano::log::type::bounded_backlog, "Rolling back: {}, account: {}", hash.to_string (), block->account ().to_account ()); + logger.debug (nano::log::type::bounded_backlog, "Rolling back: {}, account: {}", hash, block->account ()); std::deque> rollback_list; bool error = ledger.rollback (transaction, hash, rollback_list); diff --git a/nano/node/confirming_set.cpp b/nano/node/confirming_set.cpp index e08082e5d..2347dc933 100644 --- a/nano/node/confirming_set.cpp +++ b/nano/node/confirming_set.cpp @@ -263,12 +263,12 @@ void nano::confirming_set::run_batch (std::unique_lock & lock) 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); + logger.debug (nano::log::type::confirming_set, "Cemented block: {} (total cemented: {})", hash, 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 ()); + logger.debug (nano::log::type::confirming_set, "Failed to cement block: {}", hash); // Requeue failed blocks for processing later // Add them to the deferred set while still holding the exclusive database write transaction to avoid block processor races diff --git a/nano/node/distributed_work.cpp b/nano/node/distributed_work.cpp index a7cb40598..aa9498375 100644 --- a/nano/node/distributed_work.cpp +++ b/nano/node/distributed_work.cpp @@ -96,7 +96,8 @@ void nano::distributed_work::start () } else { - this_l->node.logger.error (nano::log::type::distributed_work, "Error resolving work peer: {}:{} ({})", peer.first, peer.second, ec.message ()); + this_l->node.logger.error (nano::log::type::distributed_work, "Error resolving work peer: {}:{} ({})", + peer.first, peer.second, ec.message ()); this_l->failure (); } @@ -169,9 +170,8 @@ void nano::distributed_work::do_request (nano::tcp_endpoint const & endpoint_a) } else if (ec) { - this_l->node.logger.error (nano::log::type::distributed_work, "Work peer responded with an error {}:{} ({})", - nano::util::to_str (connection->endpoint.address ()), - connection->endpoint.port (), + this_l->node.logger.error (nano::log::type::distributed_work, "Work peer responded with an error {} ({})", + connection->endpoint, ec.message ()); this_l->add_bad_peer (connection->endpoint); @@ -187,9 +187,8 @@ void nano::distributed_work::do_request (nano::tcp_endpoint const & endpoint_a) } else if (ec && ec != boost::system::errc::operation_canceled) { - this_l->node.logger.error (nano::log::type::distributed_work, "Unable to write to work peer {}:{} ({})", - nano::util::to_str (connection->endpoint.address ()), - connection->endpoint.port (), + this_l->node.logger.error (nano::log::type::distributed_work, "Unable to write to work peer {} ({})", + connection->endpoint, ec.message ()); this_l->add_bad_peer (connection->endpoint); @@ -199,9 +198,8 @@ void nano::distributed_work::do_request (nano::tcp_endpoint const & endpoint_a) } else if (ec && ec != boost::system::errc::operation_canceled) { - this_l->node.logger.error (nano::log::type::distributed_work, "Unable to connect to work peer {}:{} ({})", - nano::util::to_str (connection->endpoint.address ()), - connection->endpoint.port (), + this_l->node.logger.error (nano::log::type::distributed_work, "Unable to connect to work peer {} ({})", + connection->endpoint, ec.message ()); this_l->add_bad_peer (connection->endpoint); @@ -234,9 +232,8 @@ void nano::distributed_work::do_cancel (nano::tcp_endpoint const & endpoint_a) [this_l, peer_cancel, cancelling_l] (boost::system::error_code const & ec, std::size_t bytes_transferred) { if (ec && ec != boost::system::errc::operation_canceled) { - this_l->node.logger.error (nano::log::type::distributed_work, "Unable to send work cancel to work peer {}:{} ({})", - nano::util::to_str (cancelling_l->endpoint.address ()), - cancelling_l->endpoint.port (), + this_l->node.logger.error (nano::log::type::distributed_work, "Unable to send work cancel to work peer {} ({})", + cancelling_l->endpoint, ec.message ()); } })); @@ -265,27 +262,24 @@ void nano::distributed_work::success (std::string const & body_a, nano::tcp_endp } else { - node.logger.error (nano::log::type::distributed_work, "Incorrect work response from {}:{} for root {} with difficulty {}: {}", - nano::util::to_str (endpoint_a.address ()), - endpoint_a.port (), - request.root.to_string (), + node.logger.error (nano::log::type::distributed_work, "Incorrect work response from {} for root {} with difficulty {}: {}", + endpoint_a, + request.root, nano::to_string_hex (request.difficulty), work_text); } } else { - node.logger.error (nano::log::type::distributed_work, "Work response from {}:{} wasn't a number: {}", - nano::util::to_str (endpoint_a.address ()), - endpoint_a.port (), + node.logger.error (nano::log::type::distributed_work, "Work response from {} wasn't a number: {}", + endpoint_a, work_text); } } catch (...) { - node.logger.error (nano::log::type::distributed_work, "Work response from {}:{} wasn't parsable: {}", - nano::util::to_str (endpoint_a.address ()), - endpoint_a.port (), + node.logger.error (nano::log::type::distributed_work, "Work response from {} wasn't parsable: {}", + endpoint_a, body_a); } if (error) @@ -319,17 +313,15 @@ void nano::distributed_work::stop_once (bool const local_stop_a) connection_l->socket.close (ec); if (ec) { - this_l->node.logger.error (nano::log::type::distributed_work, "Error closing socket with work peer: {}:{} ({})", - nano::util::to_str (connection_l->endpoint.address ()), - connection_l->endpoint.port (), + this_l->node.logger.error (nano::log::type::distributed_work, "Error closing socket with work peer: {} ({})", + connection_l->endpoint, ec.message ()); } } else { - this_l->node.logger.error (nano::log::type::distributed_work, "Error cancelling operation with work peer: {}:{} ({})", - nano::util::to_str (connection_l->endpoint.address ()), - connection_l->endpoint.port (), + this_l->node.logger.error (nano::log::type::distributed_work, "Error cancelling operation with work peer: {} ({})", + connection_l->endpoint, ec.message ()); } } @@ -347,7 +339,7 @@ void nano::distributed_work::set_once (uint64_t const work_a, std::string const elapsed.stop (); node.logger.info (nano::log::type::distributed_work, "Work generation for {}, with a threshold difficulty of {} (multiplier {}x) complete: {} ms", - request.root.to_string (), + request.root, nano::to_string_hex (request.difficulty), nano::to_string (nano::difficulty::to_multiplier (request.difficulty, node.default_difficulty (request.version)), 2), elapsed.value ().count ()); @@ -369,7 +361,7 @@ void nano::distributed_work::cancel () elapsed.stop (); node.logger.info (nano::log::type::distributed_work, "Work generation for {} was cancelled after {} ms", - request.root.to_string (), + request.root, elapsed.value ().count ()); status = work_generation_status::cancelled; @@ -397,7 +389,7 @@ void nano::distributed_work::handle_failure () if (!local_generation_started && !finished.exchange (true)) { node.logger.info (nano::log::type::distributed_work, "Work peer(s) failed to generate work for root {}, retrying... (backoff: {}s)", - request.root.to_string (), + request.root, backoff.count ()); status = work_generation_status::failure_peers; diff --git a/nano/node/election.cpp b/nano/node/election.cpp index 1f064b62e..3ee56c1f0 100644 --- a/nano/node/election.cpp +++ b/nano/node/election.cpp @@ -65,7 +65,7 @@ void nano::election::confirm_once (nano::unique_lock & lock) nano::log::arg{ "status", extended_status }); node.logger.debug (nano::log::type::election, "Election confirmed with winner: {} (behavior: {}, state: {}, voters: {}, blocks: {}, duration: {}ms, confirmation requests: {})", - status_l.winner->hash ().to_string (), + status_l.winner->hash (), to_string (behavior_m), to_string (state_m), extended_status.status.voter_count, @@ -179,7 +179,7 @@ void nano::election::send_confirm_req (nano::confirmation_solicitor & solicitor_ 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 (), + qualified_root, to_string (behavior_m), to_string (state_m), status.voter_count, @@ -210,7 +210,7 @@ bool nano::election::transition_priority () 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, duration ().count ()); return true; @@ -270,8 +270,8 @@ void nano::election::broadcast_block (nano::confirmation_solicitor & solicitor_a 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 (), + status.winner->hash (), + qualified_root, to_string (behavior_m), to_string (state_m), status.voter_count, @@ -558,11 +558,11 @@ nano::vote_code nano::election::vote (nano::account const & rep, uint64_t timest nano::log::arg{ "weight", weight }); node.logger.debug (nano::log::type::election, "Vote received for: {} from: {} root: {} (final: {}, weight: {}, source: {})", - block_hash_a.to_string (), - rep.to_account (), - qualified_root.to_string (), + block_hash_a, + rep, + qualified_root, nano::vote::is_final_timestamp (timestamp_a), - weight.convert_to (), + weight, to_string (vote_source_a)); if (!confirmed_locked ()) @@ -839,11 +839,10 @@ bool nano::election::contains (nano::block_hash const & hash) const return last_blocks.contains (hash); } -// TODO: Remove the need for .to_string () calls void nano::election::operator() (nano::object_stream & obs) const { obs.write ("id", id); - obs.write ("qualified_root", qualified_root.to_string ()); + obs.write ("qualified_root", qualified_root); obs.write ("behavior", behavior_m); obs.write ("height", height); obs.write ("status", current_status ()); @@ -851,7 +850,7 @@ void nano::election::operator() (nano::object_stream & obs) const void nano::election_extended_status::operator() (nano::object_stream & obs) const { - obs.write ("winner", status.winner->hash ().to_string ()); + obs.write ("winner", status.winner->hash ()); obs.write ("tally_amount", status.tally.to_string_dec ()); obs.write ("final_tally_amount", status.final_tally.to_string_dec ()); obs.write ("confirmation_request_count", status.confirmation_request_count); @@ -862,8 +861,8 @@ void nano::election_extended_status::operator() (nano::object_stream & obs) cons obs.write_range ("votes", votes, [] (auto const & entry, nano::object_stream & obs) { auto & [account, info] = entry; - obs.write ("account", account.to_account ()); - obs.write ("hash", info.hash.to_string ()); + obs.write ("account", account); + obs.write ("hash", info.hash); obs.write ("final", nano::vote::is_final_timestamp (info.timestamp)); obs.write ("timestamp", info.timestamp); obs.write ("time", info.time.time_since_epoch ().count ()); @@ -876,7 +875,7 @@ void nano::election_extended_status::operator() (nano::object_stream & obs) cons obs.write_range ("tally", tally, [] (auto const & entry, nano::object_stream & obs) { auto & [amount, block] = entry; - obs.write ("hash", block->hash ().to_string ()); + obs.write ("hash", block->hash ()); obs.write ("amount", amount); }); } diff --git a/nano/node/epoch_upgrader.cpp b/nano/node/epoch_upgrader.cpp index 1a44e9f24..751df5d69 100644 --- a/nano/node/epoch_upgrader.cpp +++ b/nano/node/epoch_upgrader.cpp @@ -65,7 +65,7 @@ void nano::epoch_upgrader::upgrade_impl (nano::raw_key const & prv_a, nano::epoc bool fork (result == nano::block_status::fork); logger.error (nano::log::type::epoch_upgrader, "Failed to upgrade account {} (valid signature: {}, valid work: {}, fork: {})", - account_a.to_account (), + account_a, valid_signature, valid_work, fork); diff --git a/nano/node/local_block_broadcaster.cpp b/nano/node/local_block_broadcaster.cpp index 10acde626..6b17d6303 100644 --- a/nano/node/local_block_broadcaster.cpp +++ b/nano/node/local_block_broadcaster.cpp @@ -192,7 +192,7 @@ void nano::local_block_broadcaster::run_broadcasts (nano::unique_lockhash ().to_string (), + entry.block->hash (), entry.rebroadcasts); stats.inc (nano::stat::type::local_block_broadcaster, nano::stat::detail::broadcast, nano::stat::dir::out); diff --git a/nano/node/node.cpp b/nano/node/node.cpp index 1bb2c22de..83a8a137d 100644 --- a/nano/node/node.cpp +++ b/nano/node/node.cpp @@ -483,7 +483,7 @@ void nano::node::process_active (std::shared_ptr const & incoming) [[nodiscard]] nano::block_status nano::node::process (secure::write_transaction const & transaction, std::shared_ptr block) { auto status = ledger.process (transaction, block); - logger.debug (nano::log::type::node, "Directly processed block: {} (status: {})", block->hash ().to_string (), to_string (status)); + logger.debug (nano::log::type::node, "Directly processed block: {} (status: {})", block->hash (), to_string (status)); return status; } diff --git a/nano/node/repcrawler.cpp b/nano/node/repcrawler.cpp index 18523cc95..88589a110 100644 --- a/nano/node/repcrawler.cpp +++ b/nano/node/repcrawler.cpp @@ -91,8 +91,8 @@ void nano::rep_crawler::validate_and_process (nano::unique_lock & l if (rep_weight < minimum) { logger.debug (nano::log::type::rep_crawler, "Ignoring vote from account: {} with too little voting weight: {}", - vote->account.to_account (), - fmt::streamed (rep_weight)); + vote->account, + rep_weight); continue; // Skip this vote } @@ -220,8 +220,8 @@ void nano::rep_crawler::cleanup () erase_if (reps, [this] (rep_entry const & rep) { if (!rep.channel->alive ()) { - logger.info (nano::log::type::rep_crawler, "Evicting representative: {} with dead channel at: {}", rep.account.to_account (), rep.channel->to_string ()); stats.inc (nano::stat::type::rep_crawler, nano::stat::detail::channel_dead); + logger.info (nano::log::type::rep_crawler, "Evicting representative: {} with dead channel at: {}", rep.account, rep.channel->to_string ()); return true; // Erase } return false; @@ -233,13 +233,13 @@ void nano::rep_crawler::cleanup () { if (query.replies == 0) { - logger.debug (nano::log::type::rep_crawler, "Aborting unresponsive query for block: {} from: {}", query.hash.to_string (), query.channel->to_string ()); stats.inc (nano::stat::type::rep_crawler, nano::stat::detail::query_timeout); + logger.debug (nano::log::type::rep_crawler, "Aborting unresponsive query for block: {} from: {}", query.hash, query.channel->to_string ()); } else { - logger.debug (nano::log::type::rep_crawler, "Completion of query with: {} replies for block: {} from: {}", query.replies, query.hash.to_string (), query.channel->to_string ()); stats.inc (nano::stat::type::rep_crawler, nano::stat::detail::query_completion); + logger.debug (nano::log::type::rep_crawler, "Completion of query with: {} replies for block: {} from: {}", query.replies, query.hash, query.channel->to_string ()); } return true; // Erase } @@ -345,8 +345,8 @@ void nano::rep_crawler::query (std::dequeto_string ()); stats.inc (nano::stat::type::rep_crawler, nano::stat::detail::query_sent); + logger.debug (nano::log::type::rep_crawler, "Sending query for block: {} to: {}", hash_root.first, channel->to_string ()); auto const & [hash, root] = hash_root; nano::confirm_req req{ network_constants, hash, root }; @@ -357,8 +357,8 @@ void nano::rep_crawler::query (std::dequeto_string ()); stats.inc (nano::stat::type::rep_crawler, nano::stat::detail::query_duplicate); + logger.debug (nano::log::type::rep_crawler, "Ignoring duplicate query for block: {} to: {}", hash_root.first, channel->to_string ()); } } } @@ -393,8 +393,8 @@ bool nano::rep_crawler::process (std::shared_ptr const & vote, std:: }); if (found) { - logger.debug (nano::log::type::rep_crawler, "Processing response for block: {} from: {}", target_hash.to_string (), channel->to_string ()); stats.inc (nano::stat::type::rep_crawler, nano::stat::detail::response); + logger.debug (nano::log::type::rep_crawler, "Processing response for block: {} from: {}", target_hash, channel->to_string ()); // Track response time stats.sample (nano::stat::sample::rep_response_time, nano::log::milliseconds_delta (it->time), { 0, config.query_timeout.count () }); diff --git a/nano/node/request_aggregator.cpp b/nano/node/request_aggregator.cpp index ab84cc60c..c59894bc5 100644 --- a/nano/node/request_aggregator.cpp +++ b/nano/node/request_aggregator.cpp @@ -253,19 +253,18 @@ auto nano::request_aggregator::aggregate (nano::secure::transaction const & tran if (should_generate_final_vote (block)) { to_generate_final.push_back (block); + stats.inc (nano::stat::type::requests, nano::stat::detail::requests_final); logger.debug (nano::log::type::request_aggregator, "Replying with final vote for: {} to: {}", - block->hash ().to_string (), // TODO: Lazy eval - channel_a->to_string ()); // TODO: Lazy eval + block->hash (), channel_a->to_string ()); // TODO: Lazy eval } else { stats.inc (nano::stat::type::requests, nano::stat::detail::requests_non_final); logger.debug (nano::log::type::request_aggregator, "Skipping reply with normal vote for: {} (requested by: {})", - block->hash ().to_string (), // TODO: Lazy eval - channel_a->to_string ()); // TODO: Lazy eval + block->hash (), channel_a->to_string ()); // TODO: Lazy eval } } else @@ -273,9 +272,7 @@ auto nano::request_aggregator::aggregate (nano::secure::transaction const & tran stats.inc (nano::stat::type::requests, nano::stat::detail::requests_unknown); logger.debug (nano::log::type::request_aggregator, "Cannot reply, block not found: {} with root: {} (requested by: {})", - hash.to_string (), // TODO: Lazy eval - root.to_string (), // TODO: Lazy eval - channel_a->to_string ()); // TODO: Lazy eval + hash, root, channel_a->to_string ()); // TODO: Lazy eval } } diff --git a/nano/node/scheduler/priority.cpp b/nano/node/scheduler/priority.cpp index 14d83af51..61762a277 100644 --- a/nano/node/scheduler/priority.cpp +++ b/nano/node/scheduler/priority.cpp @@ -135,7 +135,7 @@ bool nano::scheduler::priority::activate (secure::transaction const & transactio { stats.inc (nano::stat::type::election_scheduler, nano::stat::detail::activated); logger.trace (nano::log::type::election_scheduler, nano::log::detail::block_activated, - nano::log::arg{ "account", account.to_account () }, // TODO: Convert to lazy eval + nano::log::arg{ "account", account }, nano::log::arg{ "block", block }, nano::log::arg{ "time", account_info.modified }, nano::log::arg{ "priority_balance", priority_balance }, diff --git a/nano/node/transport/tcp_listener.cpp b/nano/node/transport/tcp_listener.cpp index e666b2dd6..34bc625a9 100644 --- a/nano/node/transport/tcp_listener.cpp +++ b/nano/node/transport/tcp_listener.cpp @@ -186,7 +186,7 @@ void nano::transport::tcp_listener::cleanup () if (connection.socket.expired () && connection.server.expired ()) { stats.inc (nano::stat::type::tcp_listener, nano::stat::detail::erase_dead); - logger.debug (nano::log::type::tcp_listener, "Evicting dead connection: {}", fmt::streamed (connection.endpoint)); + logger.debug (nano::log::type::tcp_listener, "Evicting dead connection: {}", connection.endpoint); return true; } else @@ -216,7 +216,7 @@ void nano::transport::tcp_listener::timeout () stats.inc (nano::stat::type::tcp_listener, nano::stat::detail::attempt_timeout); logger.debug (nano::log::type::tcp_listener, "Connection attempt timed out: {} (started {}s ago)", - fmt::streamed (attempt.endpoint), nano::log::seconds_delta (attempt.start)); + attempt.endpoint, nano::log::seconds_delta (attempt.start)); } } } @@ -239,7 +239,7 @@ bool nano::transport::tcp_listener::connect (asio::ip::address ip, uint16_t port { stats.inc (nano::stat::type::tcp_listener_rejected, nano::stat::detail::max_attempts, nano::stat::dir::out); logger.debug (nano::log::type::tcp_listener, "Max connection attempts reached ({}), rejected connection attempt: {}", - count, ip.to_string ()); + count, ip); return false; // Rejected } @@ -248,7 +248,7 @@ bool nano::transport::tcp_listener::connect (asio::ip::address ip, uint16_t port { stats.inc (nano::stat::type::tcp_listener_rejected, nano::stat::detail::max_attempts_per_ip, nano::stat::dir::out); logger.debug (nano::log::type::tcp_listener, "Connection attempt already in progress ({}), rejected connection attempt: {}", - count, ip.to_string ()); + count, ip); return false; // Rejected } @@ -264,7 +264,7 @@ bool nano::transport::tcp_listener::connect (asio::ip::address ip, uint16_t port nano::tcp_endpoint const endpoint{ ip, port }; stats.inc (nano::stat::type::tcp_listener, nano::stat::detail::connect_initiate, nano::stat::dir::out); - logger.debug (nano::log::type::tcp_listener, "Initiating outgoing connection to: {}", fmt::streamed (endpoint)); + logger.debug (nano::log::type::tcp_listener, "Initiating outgoing connection to: {}", endpoint); auto task = nano::async::task (strand, connect_impl (endpoint)); @@ -438,9 +438,7 @@ auto nano::transport::tcp_listener::check_limits (asio::ip::address const & ip, if (node.network.excluded_peers.check (ip)) // true => error { stats.inc (nano::stat::type::tcp_listener_rejected, nano::stat::detail::excluded, to_stat_dir (type)); - logger.debug (nano::log::type::tcp_listener, "Rejected connection from excluded peer: {} ({})", - ip.to_string (), - to_string (type)); + logger.debug (nano::log::type::tcp_listener, "Rejected connection from excluded peer: {} ({})", ip, to_string (type)); return accept_result::rejected; } @@ -451,9 +449,7 @@ auto nano::transport::tcp_listener::check_limits (asio::ip::address const & ip, { stats.inc (nano::stat::type::tcp_listener_rejected, nano::stat::detail::max_per_ip, to_stat_dir (type)); logger.debug (nano::log::type::tcp_listener, "Max connections: {} per IP: {} reached, unable to open a new connection ({})", - count, - ip.to_string (), - to_string (type)); + count, ip, to_string (type)); return accept_result::rejected; } @@ -466,9 +462,7 @@ auto nano::transport::tcp_listener::check_limits (asio::ip::address const & ip, { stats.inc (nano::stat::type::tcp_listener_rejected, nano::stat::detail::max_per_subnetwork, to_stat_dir (type)); logger.debug (nano::log::type::tcp_listener, "Max connections: {} per subnetwork of IP: {} reached, unable to open a new connection ({})", - count, - ip.to_string (), - to_string (type)); + count, ip, to_string (type)); return accept_result::rejected; } @@ -482,7 +476,7 @@ auto nano::transport::tcp_listener::check_limits (asio::ip::address const & ip, { stats.inc (nano::stat::type::tcp_listener_rejected, nano::stat::detail::max_attempts, to_stat_dir (type)); logger.debug (nano::log::type::tcp_listener, "Max inbound connections reached: {}, unable to accept new connection: {}", - count, ip.to_string ()); + count, ip); return accept_result::rejected; } @@ -493,7 +487,7 @@ auto nano::transport::tcp_listener::check_limits (asio::ip::address const & ip, { stats.inc (nano::stat::type::tcp_listener_rejected, nano::stat::detail::max_attempts, to_stat_dir (type)); logger.debug (nano::log::type::tcp_listener, "Max outbound connections reached: {}, unable to initiate new connection: {}", - count, ip.to_string ()); + count, ip); return accept_result::rejected; }