diff --git a/plugins/net_plugin/net_plugin.cpp b/plugins/net_plugin/net_plugin.cpp index 7c78a4485a..bcad57e3e8 100644 --- a/plugins/net_plugin/net_plugin.cpp +++ b/plugins/net_plugin/net_plugin.cpp @@ -2713,7 +2713,7 @@ namespace eosio { // thread safe void dispatch_manager::bcast_block(const signed_block_ptr& b, const block_id_type& id) { - fc_dlog( p2p_blk_log, "bcast block ${b}", ("b", b->block_num()) ); + fc_dlog( p2p_blk_log, "bcast block ${b}:${id}", ("b", b->block_num())("id", id.str().substr(8,16)) ); if(my_impl->sync_master->syncing_from_peer() ) return; diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 70279b86b7..60f58f0eb5 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -43,6 +43,8 @@ configure_file(${CMAKE_CURRENT_SOURCE_DIR}/nodeos_chainbase_allocation_test.py $ configure_file(${CMAKE_CURRENT_SOURCE_DIR}/nodeos_protocol_feature_test.py ${CMAKE_CURRENT_BINARY_DIR}/nodeos_protocol_feature_test.py COPYONLY) configure_file(${CMAKE_CURRENT_SOURCE_DIR}/nodeos_multiple_version_protocol_feature_test.py ${CMAKE_CURRENT_BINARY_DIR}/nodeos_multiple_version_protocol_feature_test.py COPYONLY) configure_file(${CMAKE_CURRENT_SOURCE_DIR}/nodeos_extra_packed_data_test.py ${CMAKE_CURRENT_BINARY_DIR}/nodeos_extra_packed_data_test.py COPYONLY) +configure_file(${CMAKE_CURRENT_SOURCE_DIR}/nodeos_late_block_test.py ${CMAKE_CURRENT_BINARY_DIR}/nodeos_late_block_test.py COPYONLY) +configure_file(${CMAKE_CURRENT_SOURCE_DIR}/nodeos_late_block_test_shape.json ${CMAKE_CURRENT_BINARY_DIR}/nodeos_late_block_test_shape.json COPYONLY) configure_file(${CMAKE_CURRENT_SOURCE_DIR}/validate-dirty-db.py ${CMAKE_CURRENT_BINARY_DIR}/validate-dirty-db.py COPYONLY) configure_file(${CMAKE_CURRENT_SOURCE_DIR}/keosd_auto_launch_test.py ${CMAKE_CURRENT_BINARY_DIR}/keosd_auto_launch_test.py COPYONLY) configure_file(${CMAKE_CURRENT_SOURCE_DIR}/db_modes_test.sh ${CMAKE_CURRENT_BINARY_DIR}/db_modes_test.sh COPYONLY) @@ -206,6 +208,7 @@ add_np_test(NAME nodeos_snapshot_diff_test COMMAND tests/nodeos_snapshot_diff_te add_np_test(NAME nodeos_snapshot_diff_if_test COMMAND tests/nodeos_snapshot_diff_test.py -v --activate-if ${UNSHARE}) add_np_test(NAME nodeos_snapshot_forked_test COMMAND tests/nodeos_snapshot_forked_test.py -v ${UNSHARE}) add_np_test(NAME nodeos_snapshot_forked_if_test COMMAND tests/nodeos_snapshot_forked_test.py -v --activate-if ${UNSHARE}) +add_np_test(NAME nodeos_late_block_test COMMAND tests/nodeos_late_block_test.py -v ${UNSHARE}) add_np_test(NAME trx_finality_status_test COMMAND tests/trx_finality_status_test.py -v ${UNSHARE}) add_np_test(NAME trx_finality_status_if_test COMMAND tests/trx_finality_status_test.py -v --activate-if ${UNSHARE}) diff --git a/tests/TestHarness/Node.py b/tests/TestHarness/Node.py index 89a61bfb8b..9a9f5bab6e 100644 --- a/tests/TestHarness/Node.py +++ b/tests/TestHarness/Node.py @@ -676,21 +676,23 @@ def findStderrFiles(path): def findInLog(self, searchStr): dataDir=Utils.getNodeDataDir(self.nodeId) files=Node.findStderrFiles(dataDir) + pattern = re.compile(searchStr) for file in files: with open(file, 'r') as f: for line in f: - if searchStr in line: + if pattern.search(line): return True return False def linesInLog(self, searchStr): dataDir=Utils.getNodeDataDir(self.nodeId) files=Node.findStderrFiles(dataDir) + pattern = re.compile(searchStr) lines=[] for file in files: with open(file, 'r') as f: for line in f: - if searchStr in line: + if pattern.search(line): lines.append(line) return lines diff --git a/tests/nodeos_late_block_test.py b/tests/nodeos_late_block_test.py new file mode 100755 index 0000000000..0f334a6061 --- /dev/null +++ b/tests/nodeos_late_block_test.py @@ -0,0 +1,109 @@ +#!/usr/bin/env python3 +import os +import shutil +import signal +import time +from TestHarness import Cluster, TestHelper, Utils, WalletMgr +from TestHarness.Node import BlockType + +############################################################### +# nodeos_late_block_test +# +# Set up a cluster of 4 producer nodes so that 3 can reach consensus. +# Node_00 - defproducera,b,c +# Node_01 - defproducerd,e,f +# Node_02 - defproducerg,h,i +# Node_04 - bridge between 2 & 3 +# Node_03 - defproducerj,k,l +# +# When Node_02 is producing shutdown Node_04 and bring it back up when Node_03 is producing. +# Verify that Node_03 realizes it should switch over to fork other nodes have chosen. +############################################################### + +Print=Utils.Print +errorExit=Utils.errorExit + +args=TestHelper.parse_args({"-d","--keep-logs","--dump-error-details","-v","--leave-running","--unshared"}) +pnodes=4 +total_nodes=pnodes + 1 +delay=args.d +debug=args.v +dumpErrorDetails=args.dump_error_details + +Utils.Debug=debug +testSuccessful=False + +cluster=Cluster(unshared=args.unshared, keepRunning=args.leave_running, keepLogs=args.keep_logs) +walletMgr=WalletMgr(True, keepRunning=args.leave_running, keepLogs=args.keep_logs) + +try: + TestHelper.printSystemInfo("BEGIN") + cluster.setWalletMgr(walletMgr) + + Print(f'producing nodes: {pnodes}, delay between nodes launch: {delay} second{"s" if delay != 1 else ""}') + + Print("Stand up cluster") + # do not allow pause production to interfere with late block test + extraNodeosArgs=" --production-pause-vote-timeout-ms 0 " + + if cluster.launch(pnodes=pnodes, totalNodes=total_nodes, extraNodeosArgs=extraNodeosArgs, + topo="./tests/nodeos_late_block_test_shape.json", delay=delay, loadSystemContract=False, + activateIF=True, signatureProviderForNonProducer=True) is False: + errorExit("Failed to stand up eos cluster.") + + assert cluster.biosNode.getInfo(exitOnError=True)["head_block_producer"] != "eosio", "launch should have waited for production to change" + cluster.biosNode.kill(signal.SIGTERM) + cluster.waitOnClusterSync(blockAdvancing=5) + + node3 = cluster.getNode(3) + node4 = cluster.getNode(4) # bridge between 2 & 3 + + Print("Wait for producer before j") + node3.waitForAnyProducer("defproducerh", exitOnError=True) + node3.waitForAnyProducer("defproduceri", exitOnError=True) + iProdBlockNum = node3.getHeadBlockNum() + + node4.kill(signal.SIGTERM) + assert not node4.verifyAlive(), "Node4 did not shutdown" + + Print("Wait until Node_03 starts to produce its second round ") + node3.waitForProducer("defproducerk", exitOnError=True) + + Print("Relaunch bridge to connection Node_02 and Node_03") + node4.relaunch() + + Print("Verify Node_03 fork switches even though it is producing") + node3.waitForProducer("defproduceri", exitOnError=True) + Print("Verify fork switch") + assert node3.findInLog("switching forks .* defproducerk"), "Expected to find 'switching forks' in node_03 log" + + Print("Wait until Node_00 to produce") + node3.waitForProducer("defproducera") + + # verify the LIB blocks of defproduceri made it into the canonical chain + # defproducerk has produced at least one block, but possibly more by time of relaunch, so verify only some of the round + for i in range(9): + defprod=node3.getBlockProducerByNum(iProdBlockNum + i) + assert defprod == "defproduceri", f"expected defproduceri for block {iProdBlockNum + i}, instead: {defprod}" + + # verify that defproducerk blocks made it into the canonical chain as well + # It can take a while to resolve the fork, but should have at least one defproducerk block unless defproducerl + # wins the fork in which case there will be another fork switch + expectedProd = "defproducerk" + if node3.findInLog("switching forks .* defproducerl"): + expectedProd = "defproducera" + iProdBlockNum += 12 # into the next set of blocks + found_defproducer = False + for i in range(12): + defprod=node3.getBlockProducerByNum(iProdBlockNum + i) + if defprod == expectedProd: + found_defproducer = True + + assert found_defproducer, f"expected {expectedProd} in blocks {iProdBlockNum}-{iProdBlockNum+12}" + + testSuccessful=True +finally: + TestHelper.shutdown(cluster, walletMgr, testSuccessful=testSuccessful, dumpErrorDetails=dumpErrorDetails) + +exitCode = 0 if testSuccessful else 1 +exit(exitCode) diff --git a/tests/nodeos_late_block_test_shape.json b/tests/nodeos_late_block_test_shape.json new file mode 100644 index 0000000000..4d1ce08cd0 --- /dev/null +++ b/tests/nodeos_late_block_test_shape.json @@ -0,0 +1,122 @@ +{ + "name": "testnet_", + "nodes": { + "bios":{ + "name": "bios", + "keys": [ + { + "privkey":"5KQwrPbwdL6PhXujxW37FSSQZ1JiwsST4cqQzDeyXtP79zkvFD3", + "pubkey":"EOS6MRyAjQq8ud7hVNYcfnVPJqcVpscN5So8BhtHuGYqET5GDW5CV" + } + ], + "peers": [ + "testnet_01", + "testnet_02" + ], + "producers": [ + "eosio" + ], + "dont_start": false + }, + "testnet_00":{ + "name": "testnet_00", + "keys": [ + { + "privkey":"5K3h9XiAmrx9EuqD8CRxHgQwEVDaWpqrhrnpdvwHtVzwJFMhNmE", + "pubkey":"EOS7K5pQCk22ojetRdyumrqp6nJX6eiQiTWWcGkZAMGhoBxgcsxhK", + "blspubkey":"PUB_BLS_kGOCEX1MM5Xl928OOvGLyNo3_GpV8av1HnoaCEGOD8bAu3MDvazu0gCZGA1G7msTh1ZTPMEMVdXMuRVS0tv_9bW9Ohz9XvgtjgbPpxxc_NaeENkGg4uDBOro0Rk8DCEW4ToLKA", + "blsprivkey":"PVT_BLS_EnQXObGKvYqfubrKjxpCqNkHeLlkQg7LERjDGm1RKjgyFZnk", + "blspop":"SIG_BLS_bXrzPVc-ahxOCWrcl-iWIMuS8ego54iz7vi38A8h_ViqtxklH9O3A2z0eiw5j40M08ejiTm7JbCY_GOwulv1oXb9SaLYQkCTZjzCVssDkghLBRTVCZW2oJmU9WbZXikNw6nkygTs5sUTtCda2a_M5jqY_Rw92_NWmbolgBNkFvMcAgSHexdETA-b7QgJX_oYBWkyP0Pt8LzO6bJueZSjH8wZ8VuPc9o8taY85mt_qgdOTbXVBG2m5ud0eAUps2UHAHt-Ig" + } + ], + "peers": [ + "testnet_01", + "testnet_02" + ], + "producers": [ + "defproducera", + "defproducerb", + "defproducerc" + ], + "dont_start": false + }, + "testnet_01":{ + "name": "testnet_01", + "keys": [ + { + "privkey":"5HviUPkTEtvF2B1nm8aZUnjma2TzgpKRjuXjwHyy3FME4xDbkZF", + "pubkey":"EOS5CbcTDgbks2ptTxvyCbT9HFbzX7PDHUY2wN4DDnVBhhQr2ZNDE", + "blspubkey":"PUB_BLS_Y8ndNvnrEpnzJcNUg49ncWDiDGRgR7WUmRRDR9yMURoS6zF14sPnbb-DsTGp0cEM628a4CmG6KXMhPJMqGZvb7RM_MGIwgbEhVaENL8rXeYLOuFDS375KHFgXxs2P5sZuaN7aA", + "blsprivkey":"PVT_BLS_A1Mifu5xyaxiveyjnZ-qN2zOt-5_KLMpjTrDI9udcQNV1NBR", + "blspop":"SIG_BLS_7D0OUU1h7E0AKkAmqV4v3Ot9oSPWJBOss4yDejr2x1g5G31cSSAYIAtqZOYC-ioNzddY7zkvTcbhKgBzv5a-G1HmV1pOCXXPJ5TL0iqU8Ks5abeEWCdhArGATmRQiSMYNcj9rMQcm3H6Z0pOlOdbDdt8Cg-SY_H4jEGmAY2ZqudAH_U8gS19aydJU-2uQq0SPIr2Okl-WNbc-q3NVQw6Y0sAHAwN4BOIHup2MJyDDDIbpSEkBchRp3zna1XJf6oBuUzpqQ" + } + ], + "peers": [ + "testnet_00", + "testnet_01" + ], + "producers": [ + "defproducerd", + "defproducere", + "defproducerf" + ], + "dont_start": false + }, + "testnet_02":{ + "name": "testnet_02", + "keys": [ + { + "privkey":"5KkQbdxFHr8Pg1N3DEMDdU7emFgUTwQvh99FDJrodFhUbbsAtQT", + "pubkey":"EOS6Tkpf8kcDfa32WA9B4nTcEJ64ZdDMSNioDcaL6rzdMwnpzaWJB", + "blspubkey":"PUB_BLS_Wf_O_QeyVhekDXS5q3qBxTyj_qxSrX_uiCY4z8ClpW0X2jrAVgAVHOQ9IR2H40QTWveD8QIGhhSbmSFPa0zFbs5k3yfnjfuuwpA7T1O13_LSdtxT19ehYiE4chZX6SUMJ09JFA", + "blsprivkey":"PVT_BLS_1ZLWim0k80ssXswSZp1T3ydHO9U3gLnKKlEBIDy8927XDLLj", + "blspop":"SIG_BLS_EL09aI3w-qCgarLM2Z5-T6sisSHBN0J4vMZxtGQklkOcAxgnCaPPXe0roxY4W0gVe2y6T01YrklmT_qZu2tAwqiNrVJcScY8QKvRSeczGBBab1MgnHvaAOuf6bA4JPAELIu2iPWfsS6-oLyLbNP5xtZpMXPHu3yaSJssXNOb5rcVs1KXaIUEagJeAlBBQEcKmFWfeAsJ_R8JDw4i9gSNmROzUjm6LVBpvB7vrnPDPFRA0BQ19H4FED6PtuFPShwJGVz4dg" + } + ], + "peers": [ + "testnet_00", + "testnet_01", + "testnet_04" + ], + "producers": [ + "defproducerg", + "defproducerh", + "defproduceri" + ], + "dont_start": false + }, + "testnet_03":{ + "name": "testnet_03", + "keys": [ + { + "privkey":"5JxTJJegQBpEL1p77TzkN1ompMB9gDwAfjM9chPzFCB4chxmwrE", + "pubkey":"EOS52ntDHqA2qj4xVo7KmxdezMRhvvBqpZBuKYJCsgihisxmywpAx", + "blspubkey":"PUB_BLS_C-FprIiry6X-8dlLYH7xUAhIuKXBQv56zJPgtcdmKeHf8AAy750eRrOYBtKG0-QEIN5l_yl9dTLvAYmOios6Q5t3ybWBUVVQ2WWcbZLVxzwBftLwYvo1zPXH7LHEE_sAgP1i7g", + "blsprivkey":"PVT_BLS_ubElmjajfsYP_9HRSpmV-Fi_IPWKTyJS4XFSWrU8ezMZ_mL_", + "blspop":"SIG_BLS_k3wrhVl2GUG_lGsPr9io-zoamPw7eiaxMDExk-yOqcpXtu0zALHoUWJRh0WOerAS1-_RQNhbi4q-BWO9IbiNWRKP9CYIhNIL6ochGHHy4aBmZ-IzEjfBrDt7inDtFTYY0Gl372e5OqPXAwi6J3GeHipXuzAiw7SV8XdWFefthxId4meKX6vw5_RWx4XQ4ScRYoCG7UQtIZkQPEsu1SfJGL6z-cfTTSq-naKbzp0QQYfqtQkFfmL7qQUH1iohnb0HbTbRbQ" + } + ], + "peers": [ + "testnet_04" + ], + "producers": [ + "defproducerj", + "defproducerk", + "defproducerl" + ], + "dont_start": false + }, + "testnet_04":{ + "name": "testnet_04", + "keys": [ + ], + "peers": [ + "testnet_02", + "testnet_03" + ], + "producers": [ + ], + "dont_start": false + } + } +}