From ec4f5e956c1ee4b8701c61440f1a72579b253c68 Mon Sep 17 00:00:00 2001 From: oldcold Date: Thu, 13 Jun 2019 16:42:11 +0800 Subject: [PATCH 1/4] add debug log for testing --- plugins/net_plugin/net_plugin.cpp | 2 ++ 1 file changed, 2 insertions(+) diff --git a/plugins/net_plugin/net_plugin.cpp b/plugins/net_plugin/net_plugin.cpp index cdc243a8fef..84c646e5b34 100644 --- a/plugins/net_plugin/net_plugin.cpp +++ b/plugins/net_plugin/net_plugin.cpp @@ -2797,6 +2797,7 @@ namespace eosio { case normal : peer_ilog(c, "received request_message:normal"); if( !msg.req_blocks.ids.empty() ) { + wlog("received request_message, sending ${num} blocks from my node", ("num", msg.req_blocks.ids.size())); for (auto const &bid: msg.req_blocks.ids) { c->blk_send(bid); } @@ -3144,6 +3145,7 @@ namespace eosio { } if (!missing_blocks.empty()) { + wlog( "requesting ${num} missing blocks from view change", ("num", missing_blocks.size())); request_message req; for (auto const &b: missing_blocks) { req.req_blocks.ids.push_back(b); From 5b1c1883db3839f35a3f9ba76c4a3341e4ed3100 Mon Sep 17 00:00:00 2001 From: oldcold Date: Fri, 14 Jun 2019 02:02:34 +0800 Subject: [PATCH 2/4] bug fix: add watermark check during marking prepared state. --- libraries/chain/pbft.cpp | 6 ++---- libraries/chain/pbft_database.cpp | 9 ++++++--- 2 files changed, 8 insertions(+), 7 deletions(-) diff --git a/libraries/chain/pbft.cpp b/libraries/chain/pbft.cpp index dc8e87f8198..b96142f4d1a 100644 --- a/libraries/chain/pbft.cpp +++ b/libraries/chain/pbft.cpp @@ -496,10 +496,8 @@ namespace eosio { } } pbft_db.mark_as_prepared(new_view.prepared_cert.block_info.block_id); - if (pbft_db.should_prepared()) { - transit_to_prepared_state(s); - return; - } + transit_to_prepared_state(s); + return; } transit_to_committed_state(s, true); diff --git a/libraries/chain/pbft_database.cpp b/libraries/chain/pbft_database.cpp index 338c7fbd441..16ea20953d2 100644 --- a/libraries/chain/pbft_database.cpp +++ b/libraries/chain/pbft_database.cpp @@ -99,6 +99,8 @@ namespace eosio { auto current = ctrl.fetch_block_state_by_id(p.block_info.block_id); + auto current_watermark = get_current_pbft_watermark(); + while ((current) && (current->block_num > ctrl.last_irreversible_block_num())) { auto curr_itr = by_block_id_index.find(current->id); @@ -131,13 +133,12 @@ namespace eosio { auto prepares = cpsp->prepares; auto as = current->active_schedule.producers; auto threshold = as.size()* 2 / 3 + 1; - if (prepares.size() >= threshold && !cpsp->is_prepared) { + if (prepares.size() >= threshold && !cpsp->is_prepared && !(cpsp->block_num > current_watermark && current_watermark > 0)) { flat_map prepare_count; for (auto const &pre: prepares) { if (prepare_count.find(pre.view) == prepare_count.end()) prepare_count[pre.view] = 0; } - for (auto const &sp: as) { for (auto const &pp: prepares) { if (sp.block_signing_key == pp.common.sender) prepare_count[pp.view] += 1; @@ -156,8 +157,10 @@ namespace eosio { void pbft_database::mark_as_prepared(const block_id_type &bid) { auto &by_block_id_index = pbft_state_index.get(); auto itr = by_block_id_index.find(bid); + auto bnum = block_info_type{bid}.block_num(); + if (itr == by_block_id_index.end()) { - auto ps = pbft_state{bid, block_info_type{bid}.block_num(), .is_prepared = true}; + auto ps = pbft_state{bid, bnum, .is_prepared = true}; auto psp = make_shared(ps); pbft_state_index.insert(psp); return; From b6b59a1ac1ac6aed4700aede0b54491fac87e235 Mon Sep 17 00:00:00 2001 From: oldcold Date: Fri, 14 Jun 2019 03:26:37 +0800 Subject: [PATCH 3/4] retry sending my lscb --- libraries/chain/pbft_database.cpp | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) diff --git a/libraries/chain/pbft_database.cpp b/libraries/chain/pbft_database.cpp index 16ea20953d2..09e7450aa50 100644 --- a/libraries/chain/pbft_database.cpp +++ b/libraries/chain/pbft_database.cpp @@ -1182,7 +1182,8 @@ namespace eosio { pbft_state_ptr psp = (*itr); flat_map pending_checkpoint_block_num; // block_height and retry_flag - for (auto i = psp->block_num; i > ctrl.last_stable_checkpoint_block_num() && i > 1; --i) { + auto lscb_num = ctrl.last_stable_checkpoint_block_num(); + for (auto i = psp->block_num; i > lscb_num && i > 1; --i) { if (checkpoint(i)) { auto &by_block = checkpoint_index.get(); @@ -1222,6 +1223,14 @@ namespace eosio { } } } + } else if (lscb_num > 0) { //retry sending my lscb + for (auto const &my_sp : ctrl.my_signature_providers()) { + auto uuid = boost::uuids::to_string(uuid_generator()); + pbft_checkpoint cp; + cp.common.uuid=uuid; cp.block_info={ctrl.last_stable_checkpoint_block_id()}; cp.common.sender=my_sp.first; cp.common.chain_id=chain_id; + cp.sender_signature = my_sp.second(cp.digest()); + new_pc.emplace_back(cp); + } } return new_pc; } From e18d3979d6afa5fbc91f5165283dcb7b90fb00c9 Mon Sep 17 00:00:00 2001 From: oldcold Date: Fri, 14 Jun 2019 15:21:54 +0800 Subject: [PATCH 4/4] reformat net layer debug log. --- .../include/eosio/chain/pbft_database.hpp | 2 ++ libraries/chain/pbft_database.cpp | 21 ++++++++----------- plugins/net_plugin/net_plugin.cpp | 10 ++++++--- 3 files changed, 18 insertions(+), 15 deletions(-) diff --git a/libraries/chain/include/eosio/chain/pbft_database.hpp b/libraries/chain/include/eosio/chain/pbft_database.hpp index 1bff8528ae1..7dcf2f5b51d 100644 --- a/libraries/chain/include/eosio/chain/pbft_database.hpp +++ b/libraries/chain/include/eosio/chain/pbft_database.hpp @@ -589,6 +589,8 @@ namespace eosio { bool is_valid_pbft_message(const pbft_message_common &common); + bool is_less_than_high_watermark(const block_num_type &bnum); + bool is_valid_prepared_certificate(const pbft_prepared_certificate &certificate); bool is_valid_committed_certificate(const pbft_committed_certificate &certificate); diff --git a/libraries/chain/pbft_database.cpp b/libraries/chain/pbft_database.cpp index 09e7450aa50..5ece4d1309e 100644 --- a/libraries/chain/pbft_database.cpp +++ b/libraries/chain/pbft_database.cpp @@ -58,6 +58,8 @@ namespace eosio { } else { checkpoint_index = pbft_checkpoint_state_multi_index_type{}; } + + fc::remove(checkpoints_db); } void pbft_database::close() { @@ -99,8 +101,6 @@ namespace eosio { auto current = ctrl.fetch_block_state_by_id(p.block_info.block_id); - auto current_watermark = get_current_pbft_watermark(); - while ((current) && (current->block_num > ctrl.last_irreversible_block_num())) { auto curr_itr = by_block_id_index.find(current->id); @@ -133,7 +133,7 @@ namespace eosio { auto prepares = cpsp->prepares; auto as = current->active_schedule.producers; auto threshold = as.size()* 2 / 3 + 1; - if (prepares.size() >= threshold && !cpsp->is_prepared && !(cpsp->block_num > current_watermark && current_watermark > 0)) { + if (prepares.size() >= threshold && !cpsp->is_prepared && is_less_than_high_watermark(cpsp->block_num)) { flat_map prepare_count; for (auto const &pre: prepares) { if (prepare_count.find(pre.view) == prepare_count.end()) prepare_count[pre.view] = 0; @@ -241,9 +241,6 @@ namespace eosio { if (itr == by_prepare_and_num_index.end()) return false; pbft_state_ptr psp = *itr; - auto current_watermark = get_current_pbft_watermark(); - - if (psp->block_num > current_watermark && current_watermark > 0) return false; if (psp->is_prepared && (psp->block_num > ctrl.last_irreversible_block_num())) { ctrl.set_pbft_prepared((*itr)->block_id); @@ -297,13 +294,12 @@ namespace eosio { curr_itr = by_block_id_index.find(current->id); if (curr_itr == by_block_id_index.end()) return; - auto cpsp = *curr_itr; auto as = current->active_schedule.producers; auto threshold = as.size()* 2 / 3 + 1; auto commits = cpsp->commits; - if (commits.size() >= threshold && !cpsp->is_committed) { + if (commits.size() >= threshold && !cpsp->is_committed && is_less_than_high_watermark(cpsp->block_num)) { flat_map commit_count; for (auto const &com: commits) { if (commit_count.find(com.view) == commit_count.end()) commit_count[com.view] = 0; @@ -377,10 +373,6 @@ namespace eosio { if (itr == by_commit_and_num_index.end()) return false; pbft_state_ptr psp = *itr; - auto current_watermark = get_current_pbft_watermark(); - - if (psp->block_num > current_watermark && current_watermark > 0) return false; - return (psp->is_committed && (psp->block_num > ctrl.last_irreversible_block_num())); } @@ -1500,6 +1492,11 @@ namespace eosio { return fork_schedules; } + bool pbft_database::is_less_than_high_watermark(const block_num_type &bnum) { + auto current_watermark = get_current_pbft_watermark(); + return current_watermark == 0 || bnum <= current_watermark; + } + pbft_state_ptr pbft_database::get_pbft_state_by_id(const block_id_type& id) const { auto &by_block_id_index = pbft_state_index.get(); diff --git a/plugins/net_plugin/net_plugin.cpp b/plugins/net_plugin/net_plugin.cpp index 84c646e5b34..568d1f371c3 100644 --- a/plugins/net_plugin/net_plugin.cpp +++ b/plugins/net_plugin/net_plugin.cpp @@ -2797,7 +2797,7 @@ namespace eosio { case normal : peer_ilog(c, "received request_message:normal"); if( !msg.req_blocks.ids.empty() ) { - wlog("received request_message, sending ${num} blocks from my node", ("num", msg.req_blocks.ids.size())); + fc_dlog( logger, "received request_message, sending ${num} blocks from my node", ("num", msg.req_blocks.ids.size())); for (auto const &bid: msg.req_blocks.ids) { c->blk_send(bid); } @@ -2987,7 +2987,11 @@ namespace eosio { template bool net_plugin_impl::is_pbft_msg_outdated(M const & msg) { - return (time_point_sec(time_point::now()) > time_point_sec(msg.common.timestamp) + pbft_message_TTL); + if (time_point_sec(time_point::now()) > time_point_sec(msg.common.timestamp) + pbft_message_TTL) { + fc_dlog( logger, "received an outdated pbft message ${m}", ("m", msg)); + return true; + } + return false; } template @@ -3145,7 +3149,7 @@ namespace eosio { } if (!missing_blocks.empty()) { - wlog( "requesting ${num} missing blocks from view change", ("num", missing_blocks.size())); + fc_dlog( logger, "requesting ${num} missing blocks from view change", ("num", missing_blocks.size())); request_message req; for (auto const &b: missing_blocks) { req.req_blocks.ids.push_back(b);