Merge pull request #550 from AntelopeIO/better_logging

[1.0] Better logging for aggregate_vote failure and add logging for proposer policy becoming active

libraries/chain/block_header_state.cpp

@@ -346,6 +346,14 @@ void finish_next(const block_header_state& prev,
          ilog("New finalizer policy becoming active in block ${n}:${id}: ${pol}",
               ("n",block_header::num_from_id(id))("id", id)("pol", *act));
       }
+
+      if (next_header_state.active_proposer_policy->proposer_schedule.version != prev.active_proposer_policy->proposer_schedule.version) {
+         const auto& act = next_header_state.active_proposer_policy;
+         dlog("Proposer policy version change: ${old_ver} -> ${new_ver}",
+              ("old_ver", prev.active_proposer_policy->proposer_schedule.version)("new_ver",act->proposer_schedule.version));
+         dlog("New proposer policy becoming active in block ${n}:${id}: ${pol}",
+              ("n",block_header::num_from_id(id))("id", id)("pol", *act));
+      }
    }
 }
 

libraries/chain/block_state.cpp

@@ -177,7 +177,7 @@ void block_state::set_trxs_metas( deque<transaction_metadata_ptr>&& trxs_metas,
 // Called from vote threads
 aggregate_vote_result_t block_state::aggregate_vote(uint32_t connection_id, const vote_message& vote) {
    auto finalizer_digest = vote.strong ? strong_digest.to_uint8_span() : std::span<const uint8_t>(weak_digest);
-   return aggregating_qc.aggregate_vote(connection_id, vote, block_num(), finalizer_digest);
+   return aggregating_qc.aggregate_vote(connection_id, vote, block_id, finalizer_digest);
 }
 
 // Only used for testing

libraries/chain/finality/qc.cpp

@@ -1,5 +1,6 @@
 #include <eosio/chain/finality/qc.hpp>
 #include <eosio/chain/finality/vote_message.hpp>
+#include <eosio/chain/block_header_state.hpp>
 #include <fc/crypto/bls_utils.hpp>
 
 namespace eosio::chain {
@@ -429,15 +430,16 @@ bool aggregating_qc_t::received_qc_is_strong() const {
 }
 
 aggregate_vote_result_t aggregating_qc_t::aggregate_vote(uint32_t connection_id, const vote_message& vote,
-                                                         block_num_type block_num, std::span<const uint8_t> finalizer_digest)
+                                                         const block_id_type& block_id, std::span<const uint8_t> finalizer_digest)
 {
    aggregate_vote_result_t r;
+   block_num_type block_num = block_header::num_from_id(block_id);
 
    bool verified_sig = false;
    auto verify_sig = [&]() -> vote_result_t {
       if (!verified_sig && !fc::crypto::blslib::verify(vote.finalizer_key, finalizer_digest, vote.sig)) {
-         fc_wlog(vote_logger, "connection - ${c} signature from finalizer ${k}.. cannot be verified",
-                 ("c", connection_id)("k", vote.finalizer_key.to_string().substr(8,16)));
+         fc_wlog(vote_logger, "connection - ${c} block_num: ${bn} block_id: ${id}, signature from finalizer ${k}.. cannot be verified, vote strong: ${sv}",
+                 ("c", connection_id)("bn", block_num)("id", block_id)("k", vote.finalizer_key.to_string().substr(8,16))("sv", vote.strong));
          return vote_result_t::invalid_signature;
       }
       verified_sig = true;
@@ -452,8 +454,8 @@ aggregate_vote_result_t aggregating_qc_t::aggregate_vote(uint32_t connection_id,
          auth = finalizer_authority_ptr{finalizer_policy, &(*itr)}; // use aliasing shared_ptr constructor
          auto index = std::distance(finalizers.begin(), itr);
          if (agg_qc_sig.has_voted(index)) {
-            fc_tlog(vote_logger, "connection - ${c} block_num: ${bn}, duplicate finalizer ${k}..",
-                    ("c", connection_id)("bn", block_num)("k", vote.finalizer_key.to_string().substr(8,16)));
+            fc_tlog(vote_logger, "connection - ${c} block_num: ${bn} block_id: ${id}, duplicate finalizer ${k}..",
+                    ("c", connection_id)("bn", block_num)("id", block_id)("k", vote.finalizer_key.to_string().substr(8,16)));
             return vote_result_t::duplicate;
          }
          if (vote_result_t vs = verify_sig(); vs != vote_result_t::success)

libraries/chain/include/eosio/chain/finality/qc.hpp

@@ -258,7 +258,7 @@ namespace eosio::chain {
       bool set_received_qc(const qc_t& qc);
       bool received_qc_is_strong() const;
       aggregate_vote_result_t aggregate_vote(uint32_t connection_id, const vote_message& vote,
-                                             block_num_type block_num, std::span<const uint8_t> finalizer_digest);
+                                             const block_id_type& block_id, std::span<const uint8_t> finalizer_digest);
       vote_status_t has_voted(const bls_public_key& key) const;
       bool is_quorum_met() const;