Merge pull request #10054 from EOSIO/qy-multiversion-test-failure-2.1.x

Fix multiversion test failure - merge 2.1.x

Author: bogniq

.cicd/generate-pipeline.sh

@@ -418,16 +418,10 @@ EOF
             IFS=$nIFS
         done
         IFS=$oIFS
-        if [[ "$ROUND" != "$ROUNDS" ]]; then
-            echo '  - wait'
-            echo ''
-        fi
-    done
-    # Execute multiversion test
-    if [[ ! "$PINNED" == 'false' || "$SKIP_MULTIVERSION_TEST" == 'false' ]]; then
-        cat <<EOF
+        if [[ ! "$PINNED" == 'false' || "$SKIP_MULTIVERSION_TEST" == 'false' ]]; then
+            cat <<EOF
   - label: ":pipeline: Multiversion Test"
-    command: 
+    command:
       - "buildkite-agent artifact download build.tar.gz . --step ':ubuntu: Ubuntu 18.04 - Build' && tar -xzf build.tar.gz"
       - ./.cicd/test.sh .cicd/multiversion.sh
     env:
@@ -440,6 +434,12 @@ EOF
 
 EOF
     fi
+        if [[ "$ROUND" != "$ROUNDS" ]]; then
+            echo '  - wait'
+            echo ''
+        fi
+    done
+    
     # trigger eosio-lrt post pr
     if [[ -z $BUILDKITE_TRIGGERED_FROM_BUILD_ID && $TRIGGER_JOB == "true" ]]; then
         if ( [[ ! $PINNED == false ]] ); then

tests/Node.py

@@ -221,12 +221,13 @@ def validateAccounts(self, accounts):
                 raise
 
     # pylint: disable=too-many-branches
-    def getBlock(self, blockNum, silentErrors=False, exitOnError=False):
+    def getBlock(self, blockNumOrId, silentErrors=False, exitOnError=False):
         """Given a blockId will return block details."""
-        assert(isinstance(blockNum, int))
+        assert(isinstance(blockNumOrId, int) or isinstance(blockNumOrId, str))
         cmdDesc="get block"
-        cmd="%s %d" % (cmdDesc, blockNum)
-        msg="(block number=%s)" % (blockNum);
+        numOrId="number" if isinstance(blockNumOrId, int) else "id"
+        cmd="%s %s" % (cmdDesc, blockNumOrId)
+        msg="(block %s=%s)" % (numOrId, blockNumOrId)
         return self.processCleosCmd(cmd, cmdDesc, silentErrors=silentErrors, exitOnError=exitOnError, exitMsg=msg)
 
     def isBlockPresent(self, blockNum, blockType=BlockType.head):

tests/nodeos_multiple_version_protocol_feature_test.py

@@ -45,18 +45,21 @@ def restartNode(node: Node, chainArg=None, addSwapFlags=None, nodeosPath=None):
 
 def shouldNodeContainPreactivateFeature(node):
     preactivateFeatureDigest = node.getSupportedProtocolFeatureDict()["PREACTIVATE_FEATURE"]["feature_digest"]
-    assert preactivateFeatureDigest
+    assert preactivateFeatureDigest, "preactivateFeatureDigest should not be empty"
     blockHeaderState = node.getLatestBlockHeaderState()
+    assert blockHeaderState, "blockHeaderState should not be empty"
     activatedProtocolFeatures = blockHeaderState["activated_protocol_features"]["protocol_features"]
     return preactivateFeatureDigest in activatedProtocolFeatures
 
+beginningOfProdTurnHead = 0
 def waitUntilBeginningOfProdTurn(node, producerName, timeout=30, sleepTime=0.4):
     def isDesiredProdTurn():
-        headBlockNum = node.getHeadBlockNum()
-        res =  node.getBlock(headBlockNum)["producer"] == producerName and \
-               node.getBlock(headBlockNum-1)["producer"] != producerName
+        beginningOfProdTurnHead = node.getHeadBlockNum()
+        res =  node.getBlock(beginningOfProdTurnHead)["producer"] == producerName and \
+               node.getBlock(beginningOfProdTurnHead-1)["producer"] != producerName
         return res
-    Utils.waitForTruth(isDesiredProdTurn, timeout, sleepTime)
+    ret = Utils.waitForTruth(isDesiredProdTurn, timeout, sleepTime)
+    assert ret != None, "Expected producer to arrive within 19 seconds (with 3 other producers)"
 
 def waitForOneRound():
     time.sleep(24) # We have 4 producers for this test
@@ -120,17 +123,41 @@ def resumeBlockProductions():
         for node in allNodes:
             if not node.killed: node.processCurlCmd("producer", "resume", "")
 
-    def areNodesInSync(nodes:[Node]):
+    def areNodesInSync(nodes:[Node], pauseAll=True, resumeAll=True):
         # Pause all block production to ensure the head is not moving
-        pauseBlockProductions()
-        time.sleep(2) # Wait for some time to ensure all blocks are propagated
+        if pauseAll:
+            pauseBlockProductions()
+            time.sleep(2) # Wait for some time to ensure all blocks are propagated
+
+        # Get current head block number and IDs for each producer
+        headBlockNums = []
         headBlockIds = []
         for node in nodes:
-            headBlockId = node.getInfo()["head_block_id"]
-            headBlockIds.append(headBlockId)
-        resumeBlockProductions()
-        return len(set(headBlockIds)) == 1
-
+            hb = node.getInfo()
+            headBlockNums.append(hb["head_block_num"])
+            headBlockIds.append(hb["head_block_id"])
+            Utils.Print("node {}, head block id: {}, num: {}".format(node.nodeId, hb["head_block_id"], hb["head_block_num"]))
+        assert len(set(headBlockNums)) == len(set(headBlockIds)), "Different block IDs have the same block numbers, thus nodes are not in sync"
+        # Check if each node has head blocks from other producers
+        inSync = True
+        if len(set(headBlockNums)) != 1:
+            def nodeHasBlocks(node, blockIds, blockNums):
+                for blkId, blkNum in zip(blockIds, blockNums):
+                    assert node.waitForBlock(blkNum, timeout=3) != None, "Expected to find block {}, but only reached {}".format(blkNum, node.getInfo()["head_block_num"])
+                    if node.getBlock(blkId) is None:
+                        Utils.Print("node {} does not have block Id: {} (num: {})".format(node.nodeId, blkId, blkNum))
+                        return False
+                return True
+            for node in nodes:
+                if not nodeHasBlocks(node, headBlockIds, headBlockNums): 
+                    inSync = False
+                    break
+
+        if resumeAll:
+            resumeBlockProductions()
+        return inSync
+
+    Utils.Print("+++ Nodes are in sync before preactivation +++")
     # Before everything starts, all nodes (new version and old version) should be in sync
     assert areNodesInSync(allNodes), "Nodes are not in sync before preactivation"
 
@@ -142,16 +169,26 @@ def areNodesInSync(nodes:[Node]):
     # Therefore, 1st node will be out of sync with 2nd, 3rd, and 4th node
     # After a round has passed though, 1st node will realize he's in minority fork and then join the other nodes
     # Hence, the PREACTIVATE_FEATURE that was previously activated will be dropped and all of the nodes should be in sync
+    Utils.Print("+++ 1st Node should contain PREACTIVATE FEATURE +++")
     setValidityOfActTimeSubjRestriction(newNodes[1], "PREACTIVATE_FEATURE", False)
     setValidityOfActTimeSubjRestriction(newNodes[2], "PREACTIVATE_FEATURE", False)
 
-    waitUntilBeginningOfProdTurn(newNodes[0], "defproducera")
-    newNodes[0].activatePreactivateFeature()
+    for i in range(3):
+        Utils.Print("1st node tries activatePreactivateFeature time(s): {}".format(i+1))
+        # 1st node waits for the start of the production turn each time it tries activatePreactivateFeature()
+        waitUntilBeginningOfProdTurn(newNodes[0], "defproducera")
+        newNodes[0].activatePreactivateFeature()
+        if shouldNodeContainPreactivateFeature(newNodes[0]):
+            break
+        diff = newNodes[0].getInfo()["head_block_num"] - beginningOfProdTurnHead
+        assert diff >= 12, "1st node should contain PREACTIVATE FEATURE since we set it during its production window"
+
     assert shouldNodeContainPreactivateFeature(newNodes[0]), "1st node should contain PREACTIVATE FEATURE"
     assert not (shouldNodeContainPreactivateFeature(newNodes[1]) or shouldNodeContainPreactivateFeature(newNodes[2])), \
-           "2nd and 3rd node should not contain PREACTIVATE FEATURE"
-    assert areNodesInSync([newNodes[1], newNodes[2], oldNode]), "2nd, 3rd and 4th node should be in sync"
-    assert not areNodesInSync(allNodes), "1st node should be out of sync with the rest nodes"
+        "2nd and 3rd node should not contain PREACTIVATE FEATURE"
+    Utils.Print("+++ 2nd, 3rd and 4th node should be in sync, and 1st node should be out of sync +++")
+    assert areNodesInSync([newNodes[1], newNodes[2], oldNode], pauseAll=True, resumeAll=False), "2nd, 3rd and 4th node should be in sync"
+    assert not areNodesInSync(allNodes, pauseAll=False, resumeAll=True), "+++ 1st node should be out of sync with the rest nodes +++"
 
     waitForOneRound()
 
@@ -170,8 +207,8 @@ def areNodesInSync(nodes:[Node]):
     libBeforePreactivation = newNodes[0].getIrreversibleBlockNum()
     newNodes[0].activatePreactivateFeature()
 
-    assert areNodesInSync(newNodes), "New nodes should be in sync"
-    assert not areNodesInSync(allNodes), "Nodes should not be in sync after preactivation"
+    assert areNodesInSync(newNodes, pauseAll=True, resumeAll=False), "New nodes should be in sync"
+    assert not areNodesInSync(allNodes, pauseAll=False, resumeAll=True), "Nodes should not be in sync after preactivation"
     for node in newNodes: assert shouldNodeContainPreactivateFeature(node), "New node should contain PREACTIVATE_FEATURE"
 
     activatedBlockNum = newNodes[0].getHeadBlockNum() # The PREACTIVATE_FEATURE should have been activated before or at this block num
@@ -181,7 +218,7 @@ def areNodesInSync(nodes:[Node]):
            newNodes[2].getIrreversibleBlockNum() >= activatedBlockNum, \
            "2nd and 3rd node LIB should also be able to advance past the block that contains PREACTIVATE_FEATURE"
     assert oldNode.getIrreversibleBlockNum() <= libBeforePreactivation, \
-           "4th node LIB should stuck on LIB before PREACTIVATE_FEATURE is activated"
+           "4th node LIB should be stuck on LIB before PREACTIVATE_FEATURE is activated"
 
     # Restart old node with newest version
     # Before we are migrating to new version, use --export-reversible-blocks as the old version