[4.0 -> main] Fix for loading a snapshot with an empty block log but an existing fork database

libraries/chain/controller.cpp

@@ -563,7 +563,10 @@ struct controller_impl {
          ilog( "no irreversible blocks need to be replayed" );
       }
 
-      if( !except_ptr && !check_shutdown() && fork_db.head() ) {
+      if (snapshot_head_block != 0 && !blog_head) {
+         // loading from snapshot without a block log so fork_db can't be considered valid
+         fork_db.reset( *head );
+      } else if( !except_ptr && !check_shutdown() && fork_db.head() ) {
          auto head_block_num = head->block_num;
          auto branch = fork_db.fetch_branch( fork_db.head()->id );
          int rev = 0;
@@ -594,19 +597,21 @@ struct controller_impl {
    void startup(std::function<void()> shutdown, std::function<bool()> check_shutdown, const snapshot_reader_ptr& snapshot) {
       EOS_ASSERT( snapshot, snapshot_exception, "No snapshot reader provided" );
       this->shutdown = shutdown;
-      ilog( "Starting initialization from snapshot, this may take a significant amount of time" );
       try {
          snapshot->validate();
          if( auto blog_head = blog.head() ) {
+            ilog( "Starting initialization from snapshot and block log ${b}-${e}, this may take a significant amount of time",
+                  ("b", blog.first_block_num())("e", blog_head->block_num()) );
             read_from_snapshot( snapshot, blog.first_block_num(), blog_head->block_num() );
          } else {
+            ilog( "Starting initialization from snapshot and no block log, this may take a significant amount of time" );
             read_from_snapshot( snapshot, 0, std::numeric_limits<uint32_t>::max() );
-            const uint32_t lib_num = head->block_num;
-            EOS_ASSERT( lib_num > 0, snapshot_exception,
+            EOS_ASSERT( head->block_num > 0, snapshot_exception,
                         "Snapshot indicates controller head at block number 0, but that is not allowed. "
                         "Snapshot is invalid." );
-            blog.reset( chain_id, lib_num + 1 );
+            blog.reset( chain_id, head->block_num + 1 );
          }
+         ilog( "Snapshot loaded, lib: ${lib}", ("lib", head->block_num) );
 
          init(check_shutdown);
          ilog( "Finished initialization from snapshot" );

tests/nodeos_forked_chain_test.py

@@ -289,7 +289,7 @@ def getBlock(self, blockNum):
     timestamp=datetime.strptime(timestampStr, Utils.TimeFmt)
 
     shipNode = cluster.getNode(0)
-    block_range = 800
+    block_range = 1000
     start_block_num = blockNum
     end_block_num = start_block_num + block_range
 

tests/nodeos_irreversible_mode_test.py

@@ -21,13 +21,14 @@
 cmdError = Utils.cmdError
 relaunchTimeout = 30
 numOfProducers = 4
-totalNodes = 15
+totalNodes = 20
 
 # Parse command line arguments
 args = TestHelper.parse_args({"-v","--dump-error-details","--leave-running","--keep-logs","--unshared"})
 Utils.Debug = args.v
 dumpErrorDetails=args.dump_error_details
 speculativeReadMode="head"
+blockLogRetainBlocks="10000"
 
 # Setup cluster and it's wallet manager
 walletMgr=WalletMgr(True)
@@ -173,7 +174,13 @@ def relaunchNode(node: Node, chainArg="", addSwapFlags=None, relaunchAssertMessa
         11:"--read-mode irreversible",
         12:"--read-mode speculative",
         13:"--read-mode irreversible",
-        14:"--read-mode speculative --plugin eosio::producer_api_plugin"})
+        14:"--read-mode speculative --plugin eosio::producer_api_plugin",
+        15:"--read-mode speculative",
+        16:"--read-mode irreversible",
+        17:"--read-mode speculative",
+        18:"--read-mode irreversible",
+        19:"--read-mode speculative --plugin eosio::producer_api_plugin"
+        })
 
    producingNodeId = 0
    producingNode = cluster.getNode(producingNodeId)
@@ -253,7 +260,7 @@ def switchSpecToIrrMode(nodeIdOfNodeToTest, nodeToTest):
 
       # Kill and relaunch in irreversible mode
       nodeToTest.kill(signal.SIGTERM)
-      relaunchNode(nodeToTest, addSwapFlags={"--read-mode": "irreversible"})
+      relaunchNode(nodeToTest, addSwapFlags={"--read-mode": "irreversible", "--block-log-retain-blocks":blockLogRetainBlocks})
 
       # Ensure the node condition is as expected after relaunch
       confirmHeadLibAndForkDbHeadOfIrrMode(nodeToTest, headLibAndForkDbHeadBeforeSwitchMode)
@@ -266,7 +273,7 @@ def switchIrrToSpecMode(nodeIdOfNodeToTest, nodeToTest):
 
       # Kill and relaunch in speculative mode
       nodeToTest.kill(signal.SIGTERM)
-      relaunchNode(nodeToTest, addSwapFlags={"--read-mode": speculativeReadMode})
+      relaunchNode(nodeToTest, addSwapFlags={"--read-mode": speculativeReadMode, "--block-log-retain-blocks":blockLogRetainBlocks})
 
       # Ensure the node condition is as expected after relaunch
       confirmHeadLibAndForkDbHeadOfSpecMode(nodeToTest, headLibAndForkDbHeadBeforeSwitchMode)
@@ -282,7 +289,7 @@ def switchSpecToIrrModeWithConnectedToProdNode(nodeIdOfNodeToTest, nodeToTest):
          # Kill and relaunch in irreversible mode
          nodeToTest.kill(signal.SIGTERM)
          waitForBlksProducedAndLibAdvanced() # Wait for some blks to be produced and lib advance
-         relaunchNode(nodeToTest, addSwapFlags={"--read-mode": "irreversible"})
+         relaunchNode(nodeToTest, addSwapFlags={"--read-mode": "irreversible", "--block-log-retain-blocks":blockLogRetainBlocks})
 
          # Ensure the node condition is as expected after relaunch
          ensureHeadLibAndForkDbHeadIsAdvancing(nodeToTest)
@@ -301,7 +308,7 @@ def switchIrrToSpecModeWithConnectedToProdNode(nodeIdOfNodeToTest, nodeToTest):
          # Kill and relaunch in irreversible mode
          nodeToTest.kill(signal.SIGTERM)
          waitForBlksProducedAndLibAdvanced() # Wait for some blks to be produced and lib advance)
-         relaunchNode(nodeToTest, addSwapFlags={"--read-mode": speculativeReadMode})
+         relaunchNode(nodeToTest, addSwapFlags={"--read-mode": speculativeReadMode, "--block-log-retain-blocks":blockLogRetainBlocks})
 
          # Ensure the node condition is as expected after relaunch
          ensureHeadLibAndForkDbHeadIsAdvancing(nodeToTest)
@@ -393,6 +400,50 @@ def switchToSpecModeWithIrrModeSnapshot(nodeIdOfNodeToTest, nodeToTest):
       finally:
          stopProdNode()
 
+   # 10th test case: Load an irreversible snapshot into a node running without a block log
+   # Expectation: Node launches successfully
+   #              and the head and lib should be advancing after some blocks produced
+   def switchToNoBlockLogWithIrrModeSnapshot(nodeIdOfNodeToTest, nodeToTest):
+      try:
+         # Kill node and backup blocks directory of speculative mode
+         headLibAndForkDbHeadBeforeShutdown = getHeadLibAndForkDbHead(nodeToTest)
+         nodeToTest.kill(signal.SIGTERM)
+
+         # Relaunch in irreversible mode and create the snapshot
+         relaunchNode(nodeToTest, addSwapFlags={"--read-mode": "irreversible", "--block-log-retain-blocks":"0"})
+         confirmHeadLibAndForkDbHeadOfIrrMode(nodeToTest)
+         nodeToTest.createSnapshot()
+         nodeToTest.kill(signal.SIGTERM)
+
+         # Start from clean data dir and then relaunch with irreversible snapshot, no block log means that fork_db will be reset
+         removeState(nodeIdOfNodeToTest)
+         relaunchNode(nodeToTest, chainArg=" --snapshot {}".format(getLatestSnapshot(nodeIdOfNodeToTest)), addSwapFlags={"--read-mode": speculativeReadMode, "--block-log-retain-blocks":"0"})
+         confirmHeadLibAndForkDbHeadOfSpecMode(nodeToTest)
+         # Ensure it does not replay "reversible blocks", i.e. head and lib should be different
+         headLibAndForkDbHeadAfterRelaunch = getHeadLibAndForkDbHead(nodeToTest)
+         assert headLibAndForkDbHeadBeforeShutdown != headLibAndForkDbHeadAfterRelaunch, \
+            "1: Head, Lib, and Fork Db same after relaunch {} vs {}".format(headLibAndForkDbHeadBeforeShutdown, headLibAndForkDbHeadAfterRelaunch)
+
+         # Start production and wait until lib advance, ensure everything is alright
+         startProdNode()
+         ensureHeadLibAndForkDbHeadIsAdvancing(nodeToTest)
+
+         # Note the head, lib and fork db head
+         stopProdNode()
+         headLibAndForkDbHeadBeforeShutdown = getHeadLibAndForkDbHead(nodeToTest)
+         nodeToTest.kill(signal.SIGTERM)
+
+         # Relaunch the node again (using the same snapshot)
+         # The end result should be the same as before shutdown
+         removeState(nodeIdOfNodeToTest)
+         relaunchNode(nodeToTest)
+         headLibAndForkDbHeadAfterRelaunch2 = getHeadLibAndForkDbHead(nodeToTest)
+         assert headLibAndForkDbHeadAfterRelaunch == headLibAndForkDbHeadAfterRelaunch2, \
+            "2: Head, Lib, and Fork Db after relaunch is different {} vs {}".format(headLibAndForkDbHeadAfterRelaunch, headLibAndForkDbHeadAfterRelaunch2)
+      finally:
+         stopProdNode()
+
+
    # Start executing test cases here
    testSuccessful = executeTest(1, replayInIrrModeWithRevBlks)
    testSuccessful = testSuccessful and executeTest(2, replayInIrrModeWithoutRevBlks)
@@ -412,6 +463,15 @@ def switchToSpecModeWithIrrModeSnapshot(nodeIdOfNodeToTest, nodeToTest):
    testSuccessful = testSuccessful and executeTest(13, switchIrrToSpecModeWithConnectedToProdNode)
    testSuccessful = testSuccessful and executeTest(14, switchToSpecModeWithIrrModeSnapshot)
 
+   # retest with read-mode head and no block log
+   speculativeReadMode="head"
+   blockLogRetainBlocks="0"
+   testSuccessful = testSuccessful and executeTest(15, switchSpecToIrrMode)
+   testSuccessful = testSuccessful and executeTest(16, switchIrrToSpecMode)
+   testSuccessful = testSuccessful and executeTest(17, switchSpecToIrrModeWithConnectedToProdNode)
+   testSuccessful = testSuccessful and executeTest(18, switchIrrToSpecModeWithConnectedToProdNode)
+   testSuccessful = testSuccessful and executeTest(19, switchToNoBlockLogWithIrrModeSnapshot)
+
 finally:
    TestHelper.shutdown(cluster, walletMgr, testSuccessful, dumpErrorDetails)
    # Print test result

tests/ship_streamer.cpp

@@ -10,6 +10,8 @@
 #include <boost/beast.hpp>
 #include <boost/program_options.hpp>
 
+#include <map>
+#include <set>
 #include <iostream>
 #include <string>
 
@@ -111,8 +113,9 @@ int main(int argc, char* argv[]) {
       stream.write(boost::asio::buffer(request_type.json_to_bin(request_sb.GetString(), [](){})));
       stream.read_message_max(0);
 
-      //      block_num, block_id
-      std::map<uint32_t, std::string> block_ids;
+      // Each block_num can have multiple block_ids since forks are possible
+      //       block_num,         block_id
+      std::map<uint32_t, std::set<std::string>> block_ids;
       bool is_first = true;
       for(;;) {
          boost::beast::flat_buffer buffer;
@@ -134,6 +137,21 @@ int main(int argc, char* argv[]) {
          eosio::check(result_document[1]["head"].HasMember("block_id"),                      "'head' does not contain 'block_id'");
          eosio::check(result_document[1]["head"]["block_id"].IsString(),                     "'head.block_id' isn't a string");
 
+         // stream what was received
+         if(is_first) {
+           std::cout << "[" << std::endl;
+           is_first = false;
+         } else {
+           std::cout << "," << std::endl;
+         }
+         std::cout << "{ \"get_blocks_result_v0\":" << std::endl;
+
+         rapidjson::StringBuffer result_sb;
+         rapidjson::PrettyWriter<rapidjson::StringBuffer> result_writer(result_sb);
+         result_document[1].Accept(result_writer);
+         std::cout << result_sb.GetString() << std::endl << "}" << std::endl;
+
+         // validate after streaming, so that invalid entry is included in the output
          uint32_t this_block_num = 0;
          if( result_document[1].HasMember("this_block") && result_document[1]["this_block"].IsObject() ) {
             if( result_document[1]["this_block"].HasMember("block_num") && result_document[1]["this_block"]["block_num"].IsUint() ) {
@@ -150,12 +168,14 @@ int main(int argc, char* argv[]) {
             if( !irreversible_only && !this_block_id.empty() && !prev_block_id.empty() ) {
                // verify forks were sent
                if (block_ids.count(this_block_num-1)) {
-                  if (block_ids[this_block_num-1] != prev_block_id) {
-                     std::cerr << "Received block: << " << this_block_num << " that does not link to previous: " << block_ids[this_block_num-1] << std::endl;
+                  if (block_ids[this_block_num-1].count(prev_block_id) == 0) {
+                     std::cerr << "Received block: << " << this_block_num << " that does not link to previous: ";
+                     std::copy(block_ids[this_block_num-1].begin(), block_ids[this_block_num-1].end(), std::ostream_iterator<std::string>(std::cerr, " "));
+                     std::cerr << std::endl;
                      return 1;
                   }
                }
-               block_ids[this_block_num] = this_block_id;
+               block_ids[this_block_num].insert(this_block_id);
 
                if( result_document[1]["last_irreversible"].HasMember("block_num") && result_document[1]["last_irreversible"]["block_num"].IsUint() ) {
                   uint32_t lib_num = result_document[1]["last_irreversible"]["block_num"].GetUint();
@@ -168,19 +188,6 @@ int main(int argc, char* argv[]) {
 
          }
 
-         if(is_first) {
-            std::cout << "[" << std::endl;
-            is_first = false;
-         } else {
-            std::cout << "," << std::endl;
-         }
-         std::cout << "{ \"get_blocks_result_v0\":" << std::endl;
-
-         rapidjson::StringBuffer result_sb;
-         rapidjson::PrettyWriter<rapidjson::StringBuffer> result_writer(result_sb);
-         result_document[1].Accept(result_writer);
-         std::cout << result_sb.GetString() << std::endl << "}" << std::endl;
-
          if( this_block_num == end_block_num ) break;
       }