From 184a4665292be0e7f90c5cb9cadbcc1e3f5c0753 Mon Sep 17 00:00:00 2001 From: Kevin Heifner Date: Mon, 29 Jul 2024 17:34:36 -0500 Subject: [PATCH 1/3] Log when block has no QCs --- libraries/chain/fork_database.cpp | 4 ++-- plugins/producer_plugin/producer_plugin.cpp | 4 ++++ 2 files changed, 6 insertions(+), 2 deletions(-) diff --git a/libraries/chain/fork_database.cpp b/libraries/chain/fork_database.cpp index 525429d651..1ec4487547 100644 --- a/libraries/chain/fork_database.cpp +++ b/libraries/chain/fork_database.cpp @@ -26,7 +26,7 @@ namespace eosio::chain { std::string r; r += "[ last_final_block_timestamp: " + bs.last_final_block_timestamp().to_time_point().to_iso_string() + ", "; r += "latest_qc_block_timestamp: " + bs.latest_qc_block_timestamp().to_time_point().to_iso_string() + ", "; - r += "timestamp: " + bs.timestamp().to_time_point().to_iso_string(); + r += "timestamp: " + bs.timestamp().to_time_point().to_iso_string() + ", "; r += "id: " + bs.id().str(); r += " ]"; return r; @@ -36,7 +36,7 @@ namespace eosio::chain { std::string r; r += "[ irreversible_blocknum: " + std::to_string(bs.irreversible_blocknum()) + ", "; r += "block_num: " + std::to_string(bs.block_num()) + ", "; - r += "timestamp: " + bs.timestamp().to_time_point().to_iso_string(); + r += "timestamp: " + bs.timestamp().to_time_point().to_iso_string() + ", "; r += "id: " + bs.id().str(); r += " ]"; return r; diff --git a/plugins/producer_plugin/producer_plugin.cpp b/plugins/producer_plugin/producer_plugin.cpp index c5a6e4a593..aad30b3886 100644 --- a/plugins/producer_plugin/producer_plugin.cpp +++ b/plugins/producer_plugin/producer_plugin.cpp @@ -684,6 +684,10 @@ class producer_plugin_impl : public std::enable_shared_from_thisis_proper_svnn_block()) { + fc_ilog(vote_logger, "Block ${id}... #${n} @ ${t} produced by ${p}, latency: ${l}ms has no votes", + ("id", id.str().substr(8, 16))("n", block->block_num())("t", block->timestamp)("p", block->producer) + ("l", (fc::time_point::now() - block->timestamp).count() / 1000)); } } } From 17d8dd4059c99c42938d88495f656b29d72cf7f0 Mon Sep 17 00:00:00 2001 From: Kevin Heifner Date: Tue, 30 Jul 2024 12:29:49 -0500 Subject: [PATCH 2/3] Add log of received block with qc, previous, and timestamp --- libraries/chain/controller.cpp | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/libraries/chain/controller.cpp b/libraries/chain/controller.cpp index 96626627a3..b5c524fe43 100644 --- a/libraries/chain/controller.cpp +++ b/libraries/chain/controller.cpp @@ -3968,6 +3968,10 @@ struct controller_impl { auto qc_ext = bsp_in->block->extract_extension(); const qc_t& received_qc = qc_ext.qc; + dlog("received block: #${bn} ${t} ${prod} ${id}, qc claim: ${qc}, previous: ${p}", + ("bn", bsp_in->block_num())("t", bsp_in->timestamp())("prod", bsp_in->producer())("id", bsp_in->id()) + ("qc", qc_ext.qc.to_qc_claim())("p", bsp_in->previous())); + block_state_ptr claimed_bsp = fork_db_fetch_bsp_on_branch_by_num( bsp_in->previous(), qc_ext.qc.block_num ); if( !claimed_bsp ) { dlog("qc not found in forkdb, qc: ${qc} for block ${bn} ${id}, previous ${p}", From 6c3c7090e9fbc43ee089645e93d5032e1451e372 Mon Sep 17 00:00:00 2001 From: Kevin Heifner Date: Tue, 30 Jul 2024 13:17:55 -0500 Subject: [PATCH 3/3] Move received log to verify_qc_claim --- libraries/chain/controller.cpp | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-) diff --git a/libraries/chain/controller.cpp b/libraries/chain/controller.cpp index b5c524fe43..dad55120d2 100644 --- a/libraries/chain/controller.cpp +++ b/libraries/chain/controller.cpp @@ -3777,6 +3777,9 @@ struct controller_impl { invalid_qc_claim, "Block #${b} doesn't have a finality header extension even though its predecessor does.", ("b", block_num) ); + + dlog("received block: #${bn} ${t} ${prod} ${id}, no qc claim, previous: ${p}", + ("bn", block_num)("t", b->timestamp)("prod", b->producer)("id", id)("p", b->previous)); return; } @@ -3784,6 +3787,10 @@ struct controller_impl { const auto& f_ext = std::get(*header_ext); const auto new_qc_claim = f_ext.qc_claim; + dlog("received block: #${bn} ${t} ${prod} ${id}, qc claim: ${qc}, previous: ${p}", + ("bn", block_num)("t", b->timestamp)("prod", b->producer)("id", id) + ("qc", new_qc_claim)("p", b->previous)); + // If there is a header extension, but the previous block does not have a header extension, // ensure the block does not have a QC and the QC claim of the current block has a block_num // of the current block’s number and that it is a claim of a weak QC. Then return early. @@ -3968,10 +3975,6 @@ struct controller_impl { auto qc_ext = bsp_in->block->extract_extension(); const qc_t& received_qc = qc_ext.qc; - dlog("received block: #${bn} ${t} ${prod} ${id}, qc claim: ${qc}, previous: ${p}", - ("bn", bsp_in->block_num())("t", bsp_in->timestamp())("prod", bsp_in->producer())("id", bsp_in->id()) - ("qc", qc_ext.qc.to_qc_claim())("p", bsp_in->previous())); - block_state_ptr claimed_bsp = fork_db_fetch_bsp_on_branch_by_num( bsp_in->previous(), qc_ext.qc.block_num ); if( !claimed_bsp ) { dlog("qc not found in forkdb, qc: ${qc} for block ${bn} ${id}, previous ${p}",