Merge pull request #1745 from AntelopeIO/GH-1507-bad-block-log-main

[5.0 -> main] P2P: Modify log level for message to avoid confusion
AntelopeIO · Oct 11, 2023 · f43996f · f43996f
2 parents a1a3029 + 97f65e0
commit f43996f
Showing 1 changed file with 39 additions and 35 deletions.
diff --git a/plugins/net_plugin/net_plugin.cpp b/plugins/net_plugin/net_plugin.cpp
@@ -1366,7 +1366,7 @@ namespace eosio {
       boost::system::error_code ec;
       socket->set_option( nodelay, ec );
       if( ec ) {
-         peer_elog( this, "connection failed (set_option): ${e1}", ( "e1", ec.message() ) );
+         peer_wlog( this, "connection failed (set_option): ${e1}", ( "e1", ec.message() ) );
          close();
          return false;
       } else {
@@ -1544,6 +1544,7 @@ namespace eosio {
             peer_ilog( this, "fetch block by id returned null, id ${id}", ("id", blkid) );
          }
       } catch( const assert_exception& ex ) {
+         // possible corrupted block log
          peer_elog( this, "caught assert on fetch_block_by_id, ${ex}, id ${id}", ("ex", ex.to_string())("id", blkid) );
       } catch( ... ) {
          peer_elog( this, "caught other exception fetching block id ${id}", ("id", blkid) );
@@ -1671,7 +1672,7 @@ namespace eosio {
 
                if( ec ) {
                   if( ec.value() != boost::asio::error::eof ) {
-                     peer_elog( c, "Error sending to peer: ${i}", ( "i", ec.message() ) );
+                     peer_wlog( c, "Error sending to peer: ${i}", ( "i", ec.message() ) );
                   } else {
                      peer_wlog( c, "connection closure detected on write" );
                   }
@@ -2126,7 +2127,7 @@ namespace eosio {
 
       // verify there is an available source
       if( !new_sync_source ) {
-         fc_elog( logger, "Unable to continue syncing at this time");
+         fc_wlog( logger, "Unable to continue syncing at this time");
          sync_source.reset();
          sync_known_lib_num = chain_info.lib_num;
          sync_last_requested_num = 0;
@@ -2373,7 +2374,7 @@ namespace eosio {
                   "sync_recv_notice only called on catch_up" );
       if (msg.known_blocks.mode == catch_up) {
          if (msg.known_blocks.ids.empty()) {
-            peer_elog( c, "got a catch up with ids size = 0" );
+            peer_wlog( c, "got a catch up with ids size = 0" );
          } else {
             const block_id_type& id = msg.known_blocks.ids.back();
             peer_ilog( c, "notice_message, pending ${p}, blk_num ${n}, id ${id}...",
@@ -2661,7 +2662,7 @@ namespace eosio {
    void dispatch_manager::recv_notice(const connection_ptr& c, const notice_message& msg, bool generated) {
       if (msg.known_trx.mode == normal) {
       } else if (msg.known_trx.mode != none) {
-         peer_elog( c, "passed a notice_message with something other than a normal on none known_trx" );
+         peer_wlog( c, "passed a notice_message with something other than a normal on none known_trx" );
          return;
       }
       if (msg.known_blocks.mode == normal) {
@@ -2672,7 +2673,7 @@ namespace eosio {
             }
          }
       } else if (msg.known_blocks.mode != none) {
-         peer_elog( c, "passed a notice_message with something other than a normal on none known_blocks" );
+         peer_wlog( c, "passed a notice_message with something other than a normal on none known_blocks" );
          return;
       }
    }
@@ -2774,7 +2775,7 @@ namespace eosio {
                   c->send_time();
                }
             } else {
-               fc_elog( logger, "connection failed to ${a}, ${error}", ("a", c->peer_address())( "error", err.message()));
+               fc_ilog( logger, "connection failed to ${a}, ${error}", ("a", c->peer_address())( "error", err.message()));
                c->close( false );
                if (my_impl->increment_failed_p2p_connections) {
                   my_impl->increment_failed_p2p_connections();
@@ -2795,7 +2796,7 @@ namespace eosio {
       const auto&               paddr_add = socket.remote_endpoint(rec).address();
       string                    paddr_str;
       if (rec) {
-         fc_elog(logger, "Error getting remote endpoint: ${m}", ("m", rec.message()));
+         fc_ilog(logger, "Unable to get remote endpoint: ${m}", ("m", rec.message()));
       } else {
          paddr_str        = paddr_add.to_string();
          connections.for_each_connection([&visitors, &from_addr, &paddr_str](const connection_ptr& conn) {
@@ -3013,7 +3014,7 @@ namespace eosio {
          }
 
       } catch( const fc::exception& e ) {
-         peer_elog( this, "Exception in handling message: ${s}", ("s", e.to_detail_string()) );
+         peer_wlog( this, "Exception in handling message: ${s}", ("s", e.to_detail_string()) );
          close();
          return false;
       }
@@ -3230,7 +3231,7 @@ namespace eosio {
    // called from connection strand
    void connection::handle_message( const handshake_message& msg ) {
       if( !is_valid( msg ) ) {
-         peer_elog( this, "bad handshake message");
+         peer_wlog( this, "bad handshake message");
          no_retry = go_away_reason::fatal_other;
          enqueue( go_away_message( fatal_other ) );
          return;
@@ -3248,7 +3249,7 @@ namespace eosio {
       set_state(connection_state::connected);
       if (msg.generation == 1) {
          if( msg.node_id == my_impl->node_id) {
-            peer_elog( this, "Self connection detected node_id ${id}. Closing connection", ("id", msg.node_id) );
+            peer_ilog( this, "Self connection detected node_id ${id}. Closing connection", ("id", msg.node_id) );
             no_retry = go_away_reason::self;
             enqueue( go_away_message( go_away_reason::self ) );
             return;
@@ -3323,7 +3324,7 @@ namespace eosio {
          }
 
          if( msg.chain_id != my_impl->chain_id ) {
-            peer_elog( this, "Peer on a different chain. Closing connection" );
+            peer_ilog( this, "Peer on a different chain. Closing connection" );
             no_retry = go_away_reason::wrong_chain;
             enqueue( go_away_message(go_away_reason::wrong_chain) );
             return;
@@ -3340,7 +3341,7 @@ namespace eosio {
          short_conn_node_id = conn_node_id.str().substr( 0, 7 );
 
          if( !my_impl->authenticate_peer( msg ) ) {
-            peer_elog( this, "Peer not authenticated.  Closing connection." );
+            peer_wlog( this, "Peer not authenticated.  Closing connection." );
             no_retry = go_away_reason::authentication;
             enqueue( go_away_message( go_away_reason::authentication ) );
             return;
@@ -3365,9 +3366,9 @@ namespace eosio {
                on_fork = true;
             }
             if( on_fork ) {
-                  peer_elog( this, "Peer chain is forked, sending: forked go away" );
-                  no_retry = go_away_reason::forked;
-                  enqueue( go_away_message( go_away_reason::forked ) );
+               peer_wlog( this, "Peer chain is forked, sending: forked go away" );
+               no_retry = go_away_reason::forked;
+               enqueue( go_away_message( go_away_reason::forked ) );
             }
          }
 
@@ -3502,7 +3503,7 @@ namespace eosio {
       //
       set_state(connection_state::connected);
       if( msg.known_blocks.ids.size() > 2 ) {
-         peer_elog( this, "Invalid notice_message, known_blocks.ids.size ${s}, closing connection",
+         peer_wlog( this, "Invalid notice_message, known_blocks.ids.size ${s}, closing connection",
                     ("s", msg.known_blocks.ids.size()) );
          close( false );
          return;
@@ -3554,15 +3555,15 @@ namespace eosio {
          break;
       }
       default: {
-         peer_elog( this, "bad notice_message : invalid known_blocks.mode ${m}",
+         peer_wlog( this, "bad notice_message : invalid known_blocks.mode ${m}",
                     ("m", static_cast<uint32_t>(msg.known_blocks.mode)) );
       }
       }
    }
 
    void connection::handle_message( const request_message& msg ) {
       if( msg.req_blocks.ids.size() > 1 ) {
-         peer_elog( this, "Invalid request_message, req_blocks.ids.size ${s}, closing",
+         peer_wlog( this, "Invalid request_message, req_blocks.ids.size ${s}, closing",
                     ("s", msg.req_blocks.ids.size()) );
          close();
          return;
@@ -3593,7 +3594,7 @@ namespace eosio {
          // no break
       case normal :
          if( !msg.req_trx.ids.empty() ) {
-            peer_elog( this, "Invalid request_message, req_trx.ids.size ${s}", ("s", msg.req_trx.ids.size()) );
+            peer_wlog( this, "Invalid request_message, req_trx.ids.size ${s}", ("s", msg.req_trx.ids.size()) );
             close();
             return;
          }
@@ -3643,7 +3644,7 @@ namespace eosio {
             if( !trace->except ) {
                fc_dlog( logger, "chain accepted transaction, bcast ${id}", ("id", trace->id) );
             } else {
-               fc_elog( logger, "bad packed_transaction : ${m}", ("m", trace->except->what()));
+               fc_ilog( logger, "bad packed_transaction : ${m}", ("m", trace->except->what()));
             }
          }
          connection_ptr conn = weak.lock();
@@ -3675,11 +3676,11 @@ namespace eosio {
             bsp = cc.create_block_state( id, ptr );
          } catch( const fc::exception& ex ) {
             exception = true;
-            fc_elog( logger, "bad block exception connection ${cid}: #${n} ${id}...: ${m}",
+            fc_ilog( logger, "bad block exception connection ${cid}: #${n} ${id}...: ${m}",
                      ("cid", cid)("n", ptr->block_num())("id", id.str().substr(8,16))("m",ex.to_string()));
          } catch( ... ) {
             exception = true;
-            fc_elog( logger, "bad block connection ${cid}: #${n} ${id}...: unknown exception",
+            fc_wlog( logger, "bad block connection ${cid}: #${n} ${id}...: unknown exception",
                      ("cid", cid)("n", ptr->block_num())("id", id.str().substr(8,16)));
          }
          if( exception ) {
@@ -3727,8 +3728,11 @@ namespace eosio {
             });
             return;
          }
-      } catch(...) {
-         fc_elog( logger, "Caught an unknown exception trying to fetch block ${id}", ("id", blk_id) );
+      } catch( const assert_exception& ex ) {
+         // possible corrupted block log
+         fc_elog( logger, "caught assert on fetch_block_by_id, ${ex}, id ${id}, conn ${c}", ("ex", ex.to_string())("id", blk_id)("c", connection_id) );
+      } catch( ... ) {
+         fc_elog( logger, "caught an unknown exception trying to fetch block ${id}, conn ${c}", ("id", blk_id)("c", connection_id) );
       }
 
       fc::microseconds age( fc::time_point::now() - block->timestamp);
@@ -3741,23 +3745,23 @@ namespace eosio {
          accepted = my_impl->chain_plug->accept_block(block, blk_id, bsp);
          my_impl->update_chain_info();
       } catch( const unlinkable_block_exception &ex) {
-         fc_elog(logger, "unlinkable_block_exception connection ${cid}: #${n} ${id}...: ${m}",
+         fc_ilog(logger, "unlinkable_block_exception connection ${cid}: #${n} ${id}...: ${m}",
                  ("cid", c->connection_id)("n", blk_num)("id", blk_id.str().substr(8,16))("m",ex.to_string()));
          reason = unlinkable;
       } catch( const block_validate_exception &ex ) {
-         fc_elog(logger, "block_validate_exception connection ${cid}: #${n} ${id}...: ${m}",
+         fc_ilog(logger, "block_validate_exception connection ${cid}: #${n} ${id}...: ${m}",
                  ("cid", c->connection_id)("n", blk_num)("id", blk_id.str().substr(8,16))("m",ex.to_string()));
          reason = validation;
       } catch( const assert_exception &ex ) {
-         fc_elog(logger, "block assert_exception connection ${cid}: #${n} ${id}...: ${m}",
+         fc_wlog(logger, "block assert_exception connection ${cid}: #${n} ${id}...: ${m}",
                  ("cid", c->connection_id)("n", blk_num)("id", blk_id.str().substr(8,16))("m",ex.to_string()));
          reason = fatal_other;
       } catch( const fc::exception &ex ) {
-         fc_elog(logger, "bad block exception connection ${cid}: #${n} ${id}...: ${m}",
+         fc_ilog(logger, "bad block exception connection ${cid}: #${n} ${id}...: ${m}",
                  ("cid", c->connection_id)("n", blk_num)("id", blk_id.str().substr(8,16))("m",ex.to_string()));
          reason = fatal_other;
       } catch( ... ) {
-         fc_elog(logger, "bad block connection ${cid}: #${n} ${id}...: unknown exception",
+         fc_wlog(logger, "bad block connection ${cid}: #${n} ${id}...: unknown exception",
                  ("cid", c->connection_id)("n", blk_num)("id", blk_id.str().substr(8,16)));
          reason = fatal_other;
       }
@@ -3906,7 +3910,7 @@ namespace eosio {
          if(producer_plug != nullptr)
             found_producer_key = producer_plug->is_producer_key(msg.key);
          if( allowed_it == allowed_peers.end() && private_it == private_keys.end() && !found_producer_key) {
-            fc_elog( logger, "Peer ${peer} sent a handshake with an unauthorized key: ${key}.",
+            fc_wlog( logger, "Peer ${peer} sent a handshake with an unauthorized key: ${key}.",
                      ("peer", msg.p2p_address)("key", msg.key) );
             return false;
          }
@@ -3915,19 +3919,19 @@ namespace eosio {
       if(msg.sig != chain::signature_type() && msg.token != sha256()) {
          sha256 hash = fc::sha256::hash(msg.time);
          if(hash != msg.token) {
-            fc_elog( logger, "Peer ${peer} sent a handshake with an invalid token.", ("peer", msg.p2p_address) );
+            fc_wlog( logger, "Peer ${peer} sent a handshake with an invalid token.", ("peer", msg.p2p_address) );
             return false;
          }
          chain::public_key_type peer_key;
          try {
             peer_key = crypto::public_key(msg.sig, msg.token, true);
          }
          catch (const std::exception& /*e*/) {
-            fc_elog( logger, "Peer ${peer} sent a handshake with an unrecoverable key.", ("peer", msg.p2p_address) );
+            fc_wlog( logger, "Peer ${peer} sent a handshake with an unrecoverable key.", ("peer", msg.p2p_address) );
             return false;
          }
          if((allowed_connections & (Producers | Specified)) && peer_key != msg.key) {
-            fc_elog( logger, "Peer ${peer} sent a handshake with an unauthenticated key.", ("peer", msg.p2p_address) );
+            fc_wlog( logger, "Peer ${peer} sent a handshake with an unauthenticated key.", ("peer", msg.p2p_address) );
             return false;
          }
       }
@@ -4523,7 +4527,7 @@ namespace eosio {
             if( !err ) {
                it->c->connect( results );
             } else {
-               fc_elog( logger, "Unable to resolve ${host}:${port} ${error}",
+               fc_wlog( logger, "Unable to resolve ${host}:${port} ${error}",
                         ("host", host)("port", port)( "error", err.message() ) );
                it->c->set_state(connection::connection_state::closed);
                ++(it->c->consecutive_immediate_connection_close);