diff options
53 files changed, 398 insertions, 394 deletions
diff --git a/qa/rpc-tests/abandonconflict.py b/qa/rpc-tests/abandonconflict.py index 5a860e439..887dbebd4 100755 --- a/qa/rpc-tests/abandonconflict.py +++ b/qa/rpc-tests/abandonconflict.py @@ -23,8 +23,8 @@ class AbandonConflictTest(BitcoinTestFramework): def setup_network(self): self.nodes = [] - self.nodes.append(start_node(0, self.options.tmpdir, ["-debug","-logtimemicros","-minrelaytxfee=0.00001"])) - self.nodes.append(start_node(1, self.options.tmpdir, ["-debug","-logtimemicros"])) + self.nodes.append(start_node(0, self.options.tmpdir, ["-minrelaytxfee=0.00001"])) + self.nodes.append(start_node(1, self.options.tmpdir)) connect_nodes(self.nodes[0], 1) def run_test(self): @@ -81,7 +81,7 @@ class AbandonConflictTest(BitcoinTestFramework): # Restart the node with a higher min relay fee so the parent tx is no longer in mempool # TODO: redo with eviction stop_node(self.nodes[0],0) - self.nodes[0]=start_node(0, self.options.tmpdir, ["-debug","-logtimemicros","-minrelaytxfee=0.0001"]) + self.nodes[0]=start_node(0, self.options.tmpdir, ["-minrelaytxfee=0.0001"]) # Verify txs no longer in mempool assert_equal(len(self.nodes[0].getrawmempool()), 0) @@ -107,7 +107,7 @@ class AbandonConflictTest(BitcoinTestFramework): # Verify that even with a low min relay fee, the tx is not reaccepted from wallet on startup once abandoned stop_node(self.nodes[0],0) - self.nodes[0]=start_node(0, self.options.tmpdir, ["-debug","-logtimemicros","-minrelaytxfee=0.00001"]) + self.nodes[0]=start_node(0, self.options.tmpdir, ["-minrelaytxfee=0.00001"]) assert_equal(len(self.nodes[0].getrawmempool()), 0) assert_equal(self.nodes[0].getbalance(), balance) @@ -127,7 +127,7 @@ class AbandonConflictTest(BitcoinTestFramework): # Remove using high relay fee again stop_node(self.nodes[0],0) - self.nodes[0]=start_node(0, self.options.tmpdir, ["-debug","-logtimemicros","-minrelaytxfee=0.0001"]) + self.nodes[0]=start_node(0, self.options.tmpdir, ["-minrelaytxfee=0.0001"]) assert_equal(len(self.nodes[0].getrawmempool()), 0) newbalance = self.nodes[0].getbalance() assert_equal(newbalance, balance - Decimal("24.9996")) @@ -158,9 +158,9 @@ class AbandonConflictTest(BitcoinTestFramework): self.nodes[0].invalidateblock(self.nodes[0].getbestblockhash()) newbalance = self.nodes[0].getbalance() #assert_equal(newbalance, balance - Decimal("10")) - print("If balance has not declined after invalidateblock then out of mempool wallet tx which is no longer") - print("conflicted has not resumed causing its inputs to be seen as spent. See Issue #7315") - print(str(balance) + " -> " + str(newbalance) + " ?") + self.log.info("If balance has not declined after invalidateblock then out of mempool wallet tx which is no longer") + self.log.info("conflicted has not resumed causing its inputs to be seen as spent. See Issue #7315") + self.log.info(str(balance) + " -> " + str(newbalance) + " ?") if __name__ == '__main__': AbandonConflictTest().main() diff --git a/qa/rpc-tests/assumevalid.py b/qa/rpc-tests/assumevalid.py index b8dafff16..c60c8e6d1 100755 --- a/qa/rpc-tests/assumevalid.py +++ b/qa/rpc-tests/assumevalid.py @@ -73,7 +73,7 @@ class SendHeadersTest(BitcoinTestFramework): # we need to pre-mine a block with an invalid transaction # signature so we can pass in the block hash as assumevalid. self.nodes = [] - self.nodes.append(start_node(0, self.options.tmpdir, ["-debug"])) + self.nodes.append(start_node(0, self.options.tmpdir)) def run_test(self): @@ -146,14 +146,14 @@ class SendHeadersTest(BitcoinTestFramework): # Start node1 and node2 with assumevalid so they accept a block with a bad signature. self.nodes.append(start_node(1, self.options.tmpdir, - ["-debug", "-assumevalid=" + hex(block102.sha256)])) + ["-assumevalid=" + hex(block102.sha256)])) node1 = BaseNode() # connects to node1 connections.append(NodeConn('127.0.0.1', p2p_port(1), self.nodes[1], node1)) node1.add_connection(connections[1]) node1.wait_for_verack() self.nodes.append(start_node(2, self.options.tmpdir, - ["-debug", "-assumevalid=" + hex(block102.sha256)])) + ["-assumevalid=" + hex(block102.sha256)])) node2 = BaseNode() # connects to node2 connections.append(NodeConn('127.0.0.1', p2p_port(2), self.nodes[2], node2)) node2.add_connection(connections[2]) diff --git a/qa/rpc-tests/bip65-cltv-p2p.py b/qa/rpc-tests/bip65-cltv-p2p.py index ea9c3d73a..63d05e8fc 100755 --- a/qa/rpc-tests/bip65-cltv-p2p.py +++ b/qa/rpc-tests/bip65-cltv-p2p.py @@ -43,7 +43,7 @@ class BIP65Test(ComparisonTestFramework): def setup_network(self): # Must set the blockversion for this test self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, - extra_args=[['-debug', '-whitelist=127.0.0.1', '-blockversion=3']], + extra_args=[['-whitelist=127.0.0.1', '-blockversion=3']], binary=[self.options.testbinary]) def run_test(self): diff --git a/qa/rpc-tests/bip68-112-113-p2p.py b/qa/rpc-tests/bip68-112-113-p2p.py index 836267ea7..0867f4258 100755 --- a/qa/rpc-tests/bip68-112-113-p2p.py +++ b/qa/rpc-tests/bip68-112-113-p2p.py @@ -99,7 +99,7 @@ class BIP68_112_113Test(ComparisonTestFramework): def setup_network(self): # Must set the blockversion for this test self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, - extra_args=[['-debug', '-whitelist=127.0.0.1', '-blockversion=4']], + extra_args=[['-whitelist=127.0.0.1', '-blockversion=4']], binary=[self.options.testbinary]) def run_test(self): diff --git a/qa/rpc-tests/bip68-sequence.py b/qa/rpc-tests/bip68-sequence.py index 3fe3b471f..ffd461ccb 100755 --- a/qa/rpc-tests/bip68-sequence.py +++ b/qa/rpc-tests/bip68-sequence.py @@ -24,8 +24,8 @@ class BIP68Test(BitcoinTestFramework): def setup_network(self): self.nodes = [] - self.nodes.append(start_node(0, self.options.tmpdir, ["-debug"])) - self.nodes.append(start_node(1, self.options.tmpdir, ["-debug", "-acceptnonstdtxn=0"])) + self.nodes.append(start_node(0, self.options.tmpdir)) + self.nodes.append(start_node(1, self.options.tmpdir, ["-acceptnonstdtxn=0"])) self.is_network_split = False self.relayfee = self.nodes[0].getnetworkinfo()["relayfee"] connect_nodes(self.nodes[0], 1) @@ -34,26 +34,26 @@ class BIP68Test(BitcoinTestFramework): # Generate some coins self.nodes[0].generate(110) - print("Running test disable flag") + self.log.info("Running test disable flag") self.test_disable_flag() - print("Running test sequence-lock-confirmed-inputs") + self.log.info("Running test sequence-lock-confirmed-inputs") self.test_sequence_lock_confirmed_inputs() - print("Running test sequence-lock-unconfirmed-inputs") + self.log.info("Running test sequence-lock-unconfirmed-inputs") self.test_sequence_lock_unconfirmed_inputs() - print("Running test BIP68 not consensus before versionbits activation") + self.log.info("Running test BIP68 not consensus before versionbits activation") self.test_bip68_not_consensus() - print("Activating BIP68 (and 112/113)") + self.log.info("Activating BIP68 (and 112/113)") self.activateCSV() - print("Verifying nVersion=2 transactions are standard.") - print("Note that with current versions of bitcoin software, nVersion=2 transactions are always standard (independent of BIP68 activation status).") + self.log.info("Verifying nVersion=2 transactions are standard.") + self.log.info("Note that nVersion=2 transactions are always standard (independent of BIP68 activation status).") self.test_version2_relay() - print("Passed\n") + self.log.info("Passed") # Test that BIP68 is not in effect if tx version is 1, or if # the first sequence bit is set. diff --git a/qa/rpc-tests/bip9-softforks.py b/qa/rpc-tests/bip9-softforks.py index 70d4be3f6..0dffd06e1 100755 --- a/qa/rpc-tests/bip9-softforks.py +++ b/qa/rpc-tests/bip9-softforks.py @@ -35,7 +35,7 @@ class BIP9SoftForksTest(ComparisonTestFramework): def setup_network(self): self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, - extra_args=[['-debug', '-whitelist=127.0.0.1']], + extra_args=[['-whitelist=127.0.0.1']], binary=[self.options.testbinary]) def run_test(self): diff --git a/qa/rpc-tests/bipdersig-p2p.py b/qa/rpc-tests/bipdersig-p2p.py index b82ef8939..22bd39fbe 100755 --- a/qa/rpc-tests/bipdersig-p2p.py +++ b/qa/rpc-tests/bipdersig-p2p.py @@ -50,7 +50,7 @@ class BIP66Test(ComparisonTestFramework): def setup_network(self): # Must set the blockversion for this test self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, - extra_args=[['-debug', '-whitelist=127.0.0.1', '-blockversion=2']], + extra_args=[['-whitelist=127.0.0.1', '-blockversion=2']], binary=[self.options.testbinary]) def run_test(self): diff --git a/qa/rpc-tests/bumpfee.py b/qa/rpc-tests/bumpfee.py index 68e9808ea..69db197e7 100755 --- a/qa/rpc-tests/bumpfee.py +++ b/qa/rpc-tests/bumpfee.py @@ -26,7 +26,7 @@ class BumpFeeTest(BitcoinTestFramework): self.setup_clean_chain = True def setup_network(self, split=False): - extra_args = [["-debug", "-prematurewitness", "-walletprematurewitness", "-walletrbf={}".format(i)] + extra_args = [["-prematurewitness", "-walletprematurewitness", "-walletrbf={}".format(i)] for i in range(self.num_nodes)] self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, extra_args) @@ -45,7 +45,7 @@ class BumpFeeTest(BitcoinTestFramework): rbf_node_address = rbf_node.getnewaddress() # fund rbf node with 10 coins of 0.001 btc (100,000 satoshis) - print("Mining blocks...") + self.log.info("Mining blocks...") peer_node.generate(110) self.sync_all() for i in range(25): @@ -55,7 +55,7 @@ class BumpFeeTest(BitcoinTestFramework): self.sync_all() assert_equal(rbf_node.getbalance(), Decimal("0.025")) - print("Running tests") + self.log.info("Running tests") dest_address = peer_node.getnewaddress() test_small_output_fails(rbf_node, dest_address) test_dust_to_fee(rbf_node, dest_address) @@ -70,7 +70,7 @@ class BumpFeeTest(BitcoinTestFramework): test_unconfirmed_not_spendable(rbf_node, rbf_node_address) test_bumpfee_metadata(rbf_node, dest_address) test_locked_wallet_fails(rbf_node, dest_address) - print("Success") + self.log.info("Success") def test_simple_bumpfee_succeeds(rbf_node, peer_node, dest_address): diff --git a/qa/rpc-tests/fundrawtransaction.py b/qa/rpc-tests/fundrawtransaction.py index 1f8658129..fd330ef27 100755 --- a/qa/rpc-tests/fundrawtransaction.py +++ b/qa/rpc-tests/fundrawtransaction.py @@ -34,8 +34,6 @@ class RawTransactionsTest(BitcoinTestFramework): self.sync_all() def run_test(self): - print("Mining blocks...") - min_relay_tx_fee = self.nodes[0].getnetworkinfo()['relayfee'] # This test is not meant to test fee estimation and we'd like # to be sure all txs are sent at a consistent desired feerate diff --git a/qa/rpc-tests/getblocktemplate_longpoll.py b/qa/rpc-tests/getblocktemplate_longpoll.py index b73fea069..dc17bbd7b 100755 --- a/qa/rpc-tests/getblocktemplate_longpoll.py +++ b/qa/rpc-tests/getblocktemplate_longpoll.py @@ -29,7 +29,7 @@ class GetBlockTemplateLPTest(BitcoinTestFramework): self.setup_clean_chain = False def run_test(self): - print("Warning: this test will take about 70 seconds in the best case. Be patient.") + self.log.info("Warning: this test will take about 70 seconds in the best case. Be patient.") self.nodes[0].generate(10) templat = self.nodes[0].getblocktemplate() longpollid = templat['longpollid'] diff --git a/qa/rpc-tests/import-rescan.py b/qa/rpc-tests/import-rescan.py index 64e0eec61..0218a4616 100755 --- a/qa/rpc-tests/import-rescan.py +++ b/qa/rpc-tests/import-rescan.py @@ -7,11 +7,11 @@ Test rescan behavior of importaddress, importpubkey, importprivkey, and importmulti RPCs with different types of keys and rescan options. -In the first part of the test, node 1 creates an address for each type of -import RPC call and node 0 sends BTC to it. Then other nodes import the -addresses, and the test makes listtransactions and getbalance calls to confirm -that the importing node either did or did not execute rescans picking up the -send transactions. +In the first part of the test, node 0 creates an address for each type of +import RPC call and sends BTC to it. Then other nodes import the addresses, +and the test makes listtransactions and getbalance calls to confirm that the +importing node either did or did not execute rescans picking up the send +transactions. In the second part of the test, node 0 sends more BTC to each address, and the test makes more listtransactions and getbalance calls to confirm that the @@ -117,7 +117,7 @@ class ImportRescanTest(BitcoinTestFramework): self.num_nodes = 2 + len(IMPORT_NODES) def setup_network(self): - extra_args = [["-debug=1"] for _ in range(self.num_nodes)] + extra_args = [[] for _ in range(self.num_nodes)] for i, import_node in enumerate(IMPORT_NODES, 2): if import_node.prune: extra_args[i] += ["-prune=1"] diff --git a/qa/rpc-tests/importmulti.py b/qa/rpc-tests/importmulti.py index 015336eff..298b6e9b8 100755 --- a/qa/rpc-tests/importmulti.py +++ b/qa/rpc-tests/importmulti.py @@ -17,7 +17,7 @@ class ImportMultiTest (BitcoinTestFramework): self.is_network_split=False def run_test (self): - print ("Mining blocks...") + self.log.info("Mining blocks...") self.nodes[0].generate(1) self.nodes[1].generate(1) timestamp = self.nodes[1].getblock(self.nodes[1].getbestblockhash())['mediantime'] @@ -48,7 +48,7 @@ class ImportMultiTest (BitcoinTestFramework): # RPC importmulti ----------------------------------------------- # Bitcoin Address - print("Should import an address") + self.log.info("Should import an address") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) result = self.nodes[1].importmulti([{ "scriptPubKey": { @@ -64,7 +64,7 @@ class ImportMultiTest (BitcoinTestFramework): watchonly_address = address['address'] watchonly_timestamp = timestamp - print("Should not import an invalid address") + self.log.info("Should not import an invalid address") result = self.nodes[1].importmulti([{ "scriptPubKey": { "address": "not valid address", @@ -76,7 +76,7 @@ class ImportMultiTest (BitcoinTestFramework): assert_equal(result[0]['error']['message'], 'Invalid address') # ScriptPubKey + internal - print("Should import a scriptPubKey with internal flag") + self.log.info("Should import a scriptPubKey with internal flag") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) result = self.nodes[1].importmulti([{ "scriptPubKey": address['scriptPubKey'], @@ -90,7 +90,7 @@ class ImportMultiTest (BitcoinTestFramework): assert_equal(address_assert['timestamp'], timestamp) # ScriptPubKey + !internal - print("Should not import a scriptPubKey without internal flag") + self.log.info("Should not import a scriptPubKey without internal flag") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) result = self.nodes[1].importmulti([{ "scriptPubKey": address['scriptPubKey'], @@ -106,7 +106,7 @@ class ImportMultiTest (BitcoinTestFramework): # Address + Public key + !Internal - print("Should import an address with public key") + self.log.info("Should import an address with public key") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) result = self.nodes[1].importmulti([{ "scriptPubKey": { @@ -123,7 +123,7 @@ class ImportMultiTest (BitcoinTestFramework): # ScriptPubKey + Public key + internal - print("Should import a scriptPubKey with internal and with public key") + self.log.info("Should import a scriptPubKey with internal and with public key") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) request = [{ "scriptPubKey": address['scriptPubKey'], @@ -139,7 +139,7 @@ class ImportMultiTest (BitcoinTestFramework): assert_equal(address_assert['timestamp'], timestamp) # ScriptPubKey + Public key + !internal - print("Should not import a scriptPubKey without internal and with public key") + self.log.info("Should not import a scriptPubKey without internal and with public key") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) request = [{ "scriptPubKey": address['scriptPubKey'], @@ -156,7 +156,7 @@ class ImportMultiTest (BitcoinTestFramework): assert_equal('timestamp' in address_assert, False) # Address + Private key + !watchonly - print("Should import an address with private key") + self.log.info("Should import an address with private key") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) result = self.nodes[1].importmulti([{ "scriptPubKey": { @@ -172,7 +172,7 @@ class ImportMultiTest (BitcoinTestFramework): assert_equal(address_assert['timestamp'], timestamp) # Address + Private key + watchonly - print("Should not import an address with private key and with watchonly") + self.log.info("Should not import an address with private key and with watchonly") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) result = self.nodes[1].importmulti([{ "scriptPubKey": { @@ -191,7 +191,7 @@ class ImportMultiTest (BitcoinTestFramework): assert_equal('timestamp' in address_assert, False) # ScriptPubKey + Private key + internal - print("Should import a scriptPubKey with internal and with private key") + self.log.info("Should import a scriptPubKey with internal and with private key") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) result = self.nodes[1].importmulti([{ "scriptPubKey": address['scriptPubKey'], @@ -206,7 +206,7 @@ class ImportMultiTest (BitcoinTestFramework): assert_equal(address_assert['timestamp'], timestamp) # ScriptPubKey + Private key + !internal - print("Should not import a scriptPubKey without internal and with private key") + self.log.info("Should not import a scriptPubKey without internal and with private key") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) result = self.nodes[1].importmulti([{ "scriptPubKey": address['scriptPubKey'], @@ -233,7 +233,7 @@ class ImportMultiTest (BitcoinTestFramework): timestamp = self.nodes[1].getblock(self.nodes[1].getbestblockhash())['mediantime'] transaction = self.nodes[1].gettransaction(transactionid) - print("Should import a p2sh") + self.log.info("Should import a p2sh") result = self.nodes[1].importmulti([{ "scriptPubKey": { "address": multi_sig_script['address'] @@ -261,7 +261,7 @@ class ImportMultiTest (BitcoinTestFramework): timestamp = self.nodes[1].getblock(self.nodes[1].getbestblockhash())['mediantime'] transaction = self.nodes[1].gettransaction(transactionid) - print("Should import a p2sh with respective redeem script") + self.log.info("Should import a p2sh with respective redeem script") result = self.nodes[1].importmulti([{ "scriptPubKey": { "address": multi_sig_script['address'] @@ -289,7 +289,7 @@ class ImportMultiTest (BitcoinTestFramework): timestamp = self.nodes[1].getblock(self.nodes[1].getbestblockhash())['mediantime'] transaction = self.nodes[1].gettransaction(transactionid) - print("Should import a p2sh with respective redeem script and private keys") + self.log.info("Should import a p2sh with respective redeem script and private keys") result = self.nodes[1].importmulti([{ "scriptPubKey": { "address": multi_sig_script['address'] @@ -316,7 +316,7 @@ class ImportMultiTest (BitcoinTestFramework): self.nodes[1].generate(1) transaction = self.nodes[1].gettransaction(transactionid) - print("Should import a p2sh with respective redeem script and private keys") + self.log.info("Should import a p2sh with respective redeem script and private keys") result = self.nodes[1].importmulti([{ "scriptPubKey": { "address": multi_sig_script['address'] @@ -332,7 +332,7 @@ class ImportMultiTest (BitcoinTestFramework): # Address + Public key + !Internal + Wrong pubkey - print("Should not import an address with a wrong public key") + self.log.info("Should not import an address with a wrong public key") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) address2 = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) result = self.nodes[1].importmulti([{ @@ -352,7 +352,7 @@ class ImportMultiTest (BitcoinTestFramework): # ScriptPubKey + Public key + internal + Wrong pubkey - print("Should not import a scriptPubKey with internal and with a wrong public key") + self.log.info("Should not import a scriptPubKey with internal and with a wrong public key") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) address2 = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) request = [{ @@ -372,7 +372,7 @@ class ImportMultiTest (BitcoinTestFramework): # Address + Private key + !watchonly + Wrong private key - print("Should not import an address with a wrong private key") + self.log.info("Should not import an address with a wrong private key") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) address2 = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) result = self.nodes[1].importmulti([{ @@ -392,7 +392,7 @@ class ImportMultiTest (BitcoinTestFramework): # ScriptPubKey + Private key + internal + Wrong private key - print("Should not import a scriptPubKey with internal and with a wrong private key") + self.log.info("Should not import a scriptPubKey with internal and with a wrong private key") address = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) address2 = self.nodes[0].validateaddress(self.nodes[0].getnewaddress()) result = self.nodes[1].importmulti([{ @@ -418,7 +418,7 @@ class ImportMultiTest (BitcoinTestFramework): assert_equal(address_assert['timestamp'], watchonly_timestamp); # Bad or missing timestamps - print("Should throw on invalid or missing timestamp values") + self.log.info("Should throw on invalid or missing timestamp values") assert_raises_message(JSONRPCException, 'Missing required timestamp field for key', self.nodes[1].importmulti, [{ "scriptPubKey": address['scriptPubKey'], diff --git a/qa/rpc-tests/importprunedfunds.py b/qa/rpc-tests/importprunedfunds.py index 4e529951e..b4c8ee6c7 100755 --- a/qa/rpc-tests/importprunedfunds.py +++ b/qa/rpc-tests/importprunedfunds.py @@ -21,7 +21,7 @@ class ImportPrunedFundsTest(BitcoinTestFramework): self.sync_all() def run_test(self): - print("Mining blocks...") + self.log.info("Mining blocks...") self.nodes[0].generate(101) self.sync_all() diff --git a/qa/rpc-tests/invalidateblock.py b/qa/rpc-tests/invalidateblock.py index 92e65927d..8c80b6400 100755 --- a/qa/rpc-tests/invalidateblock.py +++ b/qa/rpc-tests/invalidateblock.py @@ -18,53 +18,51 @@ class InvalidateTest(BitcoinTestFramework): def setup_network(self): self.nodes = [] self.is_network_split = False - self.nodes.append(start_node(0, self.options.tmpdir, ["-debug"])) - self.nodes.append(start_node(1, self.options.tmpdir, ["-debug"])) - self.nodes.append(start_node(2, self.options.tmpdir, ["-debug"])) + self.nodes.append(start_node(0, self.options.tmpdir)) + self.nodes.append(start_node(1, self.options.tmpdir)) + self.nodes.append(start_node(2, self.options.tmpdir)) def run_test(self): - print("Make sure we repopulate setBlockIndexCandidates after InvalidateBlock:") - print("Mine 4 blocks on Node 0") + self.log.info("Make sure we repopulate setBlockIndexCandidates after InvalidateBlock:") + self.log.info("Mine 4 blocks on Node 0") self.nodes[0].generate(4) assert(self.nodes[0].getblockcount() == 4) besthash = self.nodes[0].getbestblockhash() - print("Mine competing 6 blocks on Node 1") + self.log.info("Mine competing 6 blocks on Node 1") self.nodes[1].generate(6) assert(self.nodes[1].getblockcount() == 6) - print("Connect nodes to force a reorg") + self.log.info("Connect nodes to force a reorg") connect_nodes_bi(self.nodes,0,1) sync_blocks(self.nodes[0:2]) assert(self.nodes[0].getblockcount() == 6) badhash = self.nodes[1].getblockhash(2) - print("Invalidate block 2 on node 0 and verify we reorg to node 0's original chain") + self.log.info("Invalidate block 2 on node 0 and verify we reorg to node 0's original chain") self.nodes[0].invalidateblock(badhash) newheight = self.nodes[0].getblockcount() newhash = self.nodes[0].getbestblockhash() if (newheight != 4 or newhash != besthash): raise AssertionError("Wrong tip for node0, hash %s, height %d"%(newhash,newheight)) - print("\nMake sure we won't reorg to a lower work chain:") + self.log.info("Make sure we won't reorg to a lower work chain:") connect_nodes_bi(self.nodes,1,2) - print("Sync node 2 to node 1 so both have 6 blocks") + self.log.info("Sync node 2 to node 1 so both have 6 blocks") sync_blocks(self.nodes[1:3]) assert(self.nodes[2].getblockcount() == 6) - print("Invalidate block 5 on node 1 so its tip is now at 4") + self.log.info("Invalidate block 5 on node 1 so its tip is now at 4") self.nodes[1].invalidateblock(self.nodes[1].getblockhash(5)) assert(self.nodes[1].getblockcount() == 4) - print("Invalidate block 3 on node 2, so its tip is now 2") + self.log.info("Invalidate block 3 on node 2, so its tip is now 2") self.nodes[2].invalidateblock(self.nodes[2].getblockhash(3)) assert(self.nodes[2].getblockcount() == 2) - print("..and then mine a block") + self.log.info("..and then mine a block") self.nodes[2].generate(1) - print("Verify all nodes are at the right height") + self.log.info("Verify all nodes are at the right height") time.sleep(5) - for i in range(3): - print(i,self.nodes[i].getblockcount()) - assert(self.nodes[2].getblockcount() == 3) - assert(self.nodes[0].getblockcount() == 4) + assert_equal(self.nodes[2].getblockcount(), 3) + assert_equal(self.nodes[0].getblockcount(), 4) node1height = self.nodes[1].getblockcount() if node1height < 4: raise AssertionError("Node 1 reorged to a lower height: %d"%node1height) diff --git a/qa/rpc-tests/listsinceblock.py b/qa/rpc-tests/listsinceblock.py index 88304af5b..a75e66c8c 100755 --- a/qa/rpc-tests/listsinceblock.py +++ b/qa/rpc-tests/listsinceblock.py @@ -62,7 +62,7 @@ class ListSinceBlockTest (BitcoinTestFramework): # generate on both sides lastblockhash = self.nodes[1].generate(6)[5] self.nodes[2].generate(7) - print('lastblockhash=%s' % (lastblockhash)) + self.log.info('lastblockhash=%s' % (lastblockhash)) self.sync_all() diff --git a/qa/rpc-tests/maxblocksinflight.py b/qa/rpc-tests/maxblocksinflight.py index 8ea405b4d..564337d06 100755 --- a/qa/rpc-tests/maxblocksinflight.py +++ b/qa/rpc-tests/maxblocksinflight.py @@ -13,7 +13,6 @@ reach. [0.10 clients shouldn't request more than 16 from a single peer.] from test_framework.mininode import * from test_framework.test_framework import BitcoinTestFramework from test_framework.util import * -import logging MAX_REQUESTS = 128 @@ -33,7 +32,6 @@ class TestManager(NodeConnCB): def __init__(self): NodeConnCB.__init__(self) - self.log = logging.getLogger("BlockRelayTest") def add_new_connection(self, connection): self.connection = connection @@ -65,7 +63,7 @@ class TestManager(NodeConnCB): raise AssertionError("Error, test failed: block %064x requested more than once" % key) if total_requests > MAX_REQUESTS: raise AssertionError("Error, too many blocks (%d) requested" % total_requests) - print("Round %d: success (total requests: %d)" % (count, total_requests)) + self.log.info("Round %d: success (total requests: %d)" % (count, total_requests)) self.disconnectOkay = True self.connection.disconnect_node() @@ -84,7 +82,7 @@ class MaxBlocksInFlightTest(BitcoinTestFramework): def setup_network(self): self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, - extra_args=[['-debug', '-whitelist=127.0.0.1']], + extra_args=[['-whitelist=127.0.0.1']], binary=[self.options.testbinary]) def run_test(self): diff --git a/qa/rpc-tests/maxuploadtarget.py b/qa/rpc-tests/maxuploadtarget.py index 757aa60af..40cd85c9e 100755 --- a/qa/rpc-tests/maxuploadtarget.py +++ b/qa/rpc-tests/maxuploadtarget.py @@ -90,7 +90,7 @@ class MaxUploadTest(BitcoinTestFramework): def setup_network(self): # Start a node with maxuploadtarget of 200 MB (/24h) self.nodes = [] - self.nodes.append(start_node(0, self.options.tmpdir, ["-debug", "-maxuploadtarget=800", "-blockmaxsize=999000"])) + self.nodes.append(start_node(0, self.options.tmpdir, ["-maxuploadtarget=800", "-blockmaxsize=999000"])) def run_test(self): # Before we connect anything, we first set the time on the node @@ -161,7 +161,7 @@ class MaxUploadTest(BitcoinTestFramework): test_nodes[0].send_message(getdata_request) test_nodes[0].wait_for_disconnect() assert_equal(len(self.nodes[0].getpeerinfo()), 2) - print("Peer 0 disconnected after downloading old block too many times") + self.log.info("Peer 0 disconnected after downloading old block too many times") # Requesting the current block on test_nodes[1] should succeed indefinitely, # even when over the max upload target. @@ -172,7 +172,7 @@ class MaxUploadTest(BitcoinTestFramework): test_nodes[1].sync_with_ping() assert_equal(test_nodes[1].block_receive_map[big_new_block], i+1) - print("Peer 1 able to repeatedly download new block") + self.log.info("Peer 1 able to repeatedly download new block") # But if test_nodes[1] tries for an old block, it gets disconnected too. getdata_request.inv = [CInv(2, big_old_block)] @@ -180,9 +180,9 @@ class MaxUploadTest(BitcoinTestFramework): test_nodes[1].wait_for_disconnect() assert_equal(len(self.nodes[0].getpeerinfo()), 1) - print("Peer 1 disconnected after trying to download old block") + self.log.info("Peer 1 disconnected after trying to download old block") - print("Advancing system time on node to clear counters...") + self.log.info("Advancing system time on node to clear counters...") # If we advance the time by 24 hours, then the counters should reset, # and test_nodes[2] should be able to retrieve the old block. @@ -192,14 +192,14 @@ class MaxUploadTest(BitcoinTestFramework): test_nodes[2].sync_with_ping() assert_equal(test_nodes[2].block_receive_map[big_old_block], 1) - print("Peer 2 able to download old block") + self.log.info("Peer 2 able to download old block") [c.disconnect_node() for c in connections] #stop and start node 0 with 1MB maxuploadtarget, whitelist 127.0.0.1 - print("Restarting nodes with -whitelist=127.0.0.1") + self.log.info("Restarting nodes with -whitelist=127.0.0.1") stop_node(self.nodes[0], 0) - self.nodes[0] = start_node(0, self.options.tmpdir, ["-debug", "-whitelist=127.0.0.1", "-maxuploadtarget=1", "-blockmaxsize=999000"]) + self.nodes[0] = start_node(0, self.options.tmpdir, ["-whitelist=127.0.0.1", "-maxuploadtarget=1", "-blockmaxsize=999000"]) #recreate/reconnect 3 test nodes test_nodes = [] @@ -225,7 +225,7 @@ class MaxUploadTest(BitcoinTestFramework): test_nodes[1].wait_for_disconnect() assert_equal(len(self.nodes[0].getpeerinfo()), 3) #node is still connected because of the whitelist - print("Peer 1 still connected after trying to download old block (whitelisted)") + self.log.info("Peer 1 still connected after trying to download old block (whitelisted)") [c.disconnect_node() for c in connections] diff --git a/qa/rpc-tests/mempool_limit.py b/qa/rpc-tests/mempool_limit.py index 8fae92ad2..a7ca576ae 100755 --- a/qa/rpc-tests/mempool_limit.py +++ b/qa/rpc-tests/mempool_limit.py @@ -11,7 +11,7 @@ class MempoolLimitTest(BitcoinTestFramework): def setup_network(self): self.nodes = [] - self.nodes.append(start_node(0, self.options.tmpdir, ["-maxmempool=5", "-spendzeroconfchange=0", "-debug"])) + self.nodes.append(start_node(0, self.options.tmpdir, ["-maxmempool=5", "-spendzeroconfchange=0"])) self.is_network_split = False self.sync_all() self.relayfee = self.nodes[0].getnetworkinfo()['relayfee'] diff --git a/qa/rpc-tests/mempool_packages.py b/qa/rpc-tests/mempool_packages.py index 3437c89ec..915d17405 100755 --- a/qa/rpc-tests/mempool_packages.py +++ b/qa/rpc-tests/mempool_packages.py @@ -19,8 +19,8 @@ class MempoolPackagesTest(BitcoinTestFramework): def setup_network(self): self.nodes = [] - self.nodes.append(start_node(0, self.options.tmpdir, ["-maxorphantx=1000", "-debug"])) - self.nodes.append(start_node(1, self.options.tmpdir, ["-maxorphantx=1000", "-limitancestorcount=5", "-debug"])) + self.nodes.append(start_node(0, self.options.tmpdir, ["-maxorphantx=1000"])) + self.nodes.append(start_node(1, self.options.tmpdir, ["-maxorphantx=1000", "-limitancestorcount=5"])) connect_nodes(self.nodes[0], 1) self.is_network_split = False self.sync_all() @@ -115,7 +115,7 @@ class MempoolPackagesTest(BitcoinTestFramework): try: self.chain_transaction(self.nodes[0], txid, vout, value, fee, 1) except JSONRPCException as e: - print("too-long-ancestor-chain successfully rejected") + self.log.info("too-long-ancestor-chain successfully rejected") # Check that prioritising a tx before it's added to the mempool works # First clear the mempool by mining a block. @@ -165,9 +165,9 @@ class MempoolPackagesTest(BitcoinTestFramework): mempool = self.nodes[0].getrawmempool(True) assert_equal(mempool[parent_transaction]['descendantcount'], MAX_DESCENDANTS) except JSONRPCException as e: - print(e.error['message']) + self.log.info(e.error['message']) assert_equal(i, MAX_DESCENDANTS - 1) - print("tx that would create too large descendant package successfully rejected") + self.log.info("tx that would create too large descendant package successfully rejected") # TODO: check that node1's mempool is as expected diff --git a/qa/rpc-tests/mempool_reorg.py b/qa/rpc-tests/mempool_reorg.py index 2cd557327..585e4147b 100755 --- a/qa/rpc-tests/mempool_reorg.py +++ b/qa/rpc-tests/mempool_reorg.py @@ -21,7 +21,7 @@ class MempoolCoinbaseTest(BitcoinTestFramework): alert_filename = None # Set by setup_network def setup_network(self): - args = ["-checkmempool", "-debug=mempool"] + args = ["-checkmempool"] self.nodes = [] self.nodes.append(start_node(0, self.options.tmpdir, args)) self.nodes.append(start_node(1, self.options.tmpdir, args)) diff --git a/qa/rpc-tests/mempool_resurrect_test.py b/qa/rpc-tests/mempool_resurrect_test.py index c7f37aaa4..727892d1f 100755 --- a/qa/rpc-tests/mempool_resurrect_test.py +++ b/qa/rpc-tests/mempool_resurrect_test.py @@ -17,7 +17,7 @@ class MempoolCoinbaseTest(BitcoinTestFramework): def setup_network(self): # Just need one node for this test - args = ["-checkmempool", "-debug=mempool"] + args = ["-checkmempool"] self.nodes = [] self.nodes.append(start_node(0, self.options.tmpdir, args)) self.is_network_split = False diff --git a/qa/rpc-tests/mempool_spendcoinbase.py b/qa/rpc-tests/mempool_spendcoinbase.py index da8485e2a..4818ad8bd 100755 --- a/qa/rpc-tests/mempool_spendcoinbase.py +++ b/qa/rpc-tests/mempool_spendcoinbase.py @@ -25,7 +25,7 @@ class MempoolSpendCoinbaseTest(BitcoinTestFramework): def setup_network(self): # Just need one node for this test - args = ["-checkmempool", "-debug=mempool"] + args = ["-checkmempool"] self.nodes = [] self.nodes.append(start_node(0, self.options.tmpdir, args)) self.is_network_split = False diff --git a/qa/rpc-tests/merkle_blocks.py b/qa/rpc-tests/merkle_blocks.py index c4b45425d..5963f2e7b 100755 --- a/qa/rpc-tests/merkle_blocks.py +++ b/qa/rpc-tests/merkle_blocks.py @@ -17,11 +17,11 @@ class MerkleBlockTest(BitcoinTestFramework): def setup_network(self): self.nodes = [] # Nodes 0/1 are "wallet" nodes - self.nodes.append(start_node(0, self.options.tmpdir, ["-debug"])) - self.nodes.append(start_node(1, self.options.tmpdir, ["-debug"])) + self.nodes.append(start_node(0, self.options.tmpdir)) + self.nodes.append(start_node(1, self.options.tmpdir)) # Nodes 2/3 are used for testing - self.nodes.append(start_node(2, self.options.tmpdir, ["-debug"])) - self.nodes.append(start_node(3, self.options.tmpdir, ["-debug", "-txindex"])) + self.nodes.append(start_node(2, self.options.tmpdir)) + self.nodes.append(start_node(3, self.options.tmpdir, ["-txindex"])) connect_nodes(self.nodes[0], 1) connect_nodes(self.nodes[0], 2) connect_nodes(self.nodes[0], 3) @@ -30,7 +30,7 @@ class MerkleBlockTest(BitcoinTestFramework): self.sync_all() def run_test(self): - print("Mining blocks...") + self.log.info("Mining blocks...") self.nodes[0].generate(105) self.sync_all() diff --git a/qa/rpc-tests/nulldummy.py b/qa/rpc-tests/nulldummy.py index b44a98bfd..4b215a70b 100755 --- a/qa/rpc-tests/nulldummy.py +++ b/qa/rpc-tests/nulldummy.py @@ -45,7 +45,7 @@ class NULLDUMMYTest(BitcoinTestFramework): def setup_network(self): # Must set the blockversion for this test self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, - extra_args=[['-debug', '-whitelist=127.0.0.1', '-walletprematurewitness']]) + extra_args=[['-whitelist=127.0.0.1', '-walletprematurewitness']]) def run_test(self): self.address = self.nodes[0].getnewaddress() @@ -64,7 +64,7 @@ class NULLDUMMYTest(BitcoinTestFramework): self.lastblockheight = 429 self.lastblocktime = int(time.time()) + 429 - print ("Test 1: NULLDUMMY compliant base transactions should be accepted to mempool and mined before activation [430]") + self.log.info("Test 1: NULLDUMMY compliant base transactions should be accepted to mempool and mined before activation [430]") test1txs = [self.create_transaction(self.nodes[0], coinbase_txid[0], self.ms_address, 49)] txid1 = self.tx_submit(self.nodes[0], test1txs[0]) test1txs.append(self.create_transaction(self.nodes[0], txid1, self.ms_address, 48)) @@ -73,29 +73,29 @@ class NULLDUMMYTest(BitcoinTestFramework): txid3 = self.tx_submit(self.nodes[0], test1txs[2]) self.block_submit(self.nodes[0], test1txs, False, True) - print ("Test 2: Non-NULLDUMMY base multisig transaction should not be accepted to mempool before activation") + self.log.info("Test 2: Non-NULLDUMMY base multisig transaction should not be accepted to mempool before activation") test2tx = self.create_transaction(self.nodes[0], txid2, self.ms_address, 47) trueDummy(test2tx) txid4 = self.tx_submit(self.nodes[0], test2tx, NULLDUMMY_ERROR) - print ("Test 3: Non-NULLDUMMY base transactions should be accepted in a block before activation [431]") + self.log.info("Test 3: Non-NULLDUMMY base transactions should be accepted in a block before activation [431]") self.block_submit(self.nodes[0], [test2tx], False, True) - print ("Test 4: Non-NULLDUMMY base multisig transaction is invalid after activation") + self.log.info("Test 4: Non-NULLDUMMY base multisig transaction is invalid after activation") test4tx = self.create_transaction(self.nodes[0], txid4, self.address, 46) test6txs=[CTransaction(test4tx)] trueDummy(test4tx) self.tx_submit(self.nodes[0], test4tx, NULLDUMMY_ERROR) self.block_submit(self.nodes[0], [test4tx]) - print ("Test 5: Non-NULLDUMMY P2WSH multisig transaction invalid after activation") + self.log.info("Test 5: Non-NULLDUMMY P2WSH multisig transaction invalid after activation") test5tx = self.create_transaction(self.nodes[0], txid3, self.wit_address, 48) test6txs.append(CTransaction(test5tx)) test5tx.wit.vtxinwit[0].scriptWitness.stack[0] = b'\x01' self.tx_submit(self.nodes[0], test5tx, NULLDUMMY_ERROR) self.block_submit(self.nodes[0], [test5tx], True) - print ("Test 6: NULLDUMMY compliant base/witness transactions should be accepted to mempool and in block after activation [432]") + self.log.info("Test 6: NULLDUMMY compliant base/witness transactions should be accepted to mempool and in block after activation [432]") for i in test6txs: self.tx_submit(self.nodes[0], i) self.block_submit(self.nodes[0], test6txs, True, True) diff --git a/qa/rpc-tests/p2p-acceptblock.py b/qa/rpc-tests/p2p-acceptblock.py index 4767dd8fe..e1111da4a 100755 --- a/qa/rpc-tests/p2p-acceptblock.py +++ b/qa/rpc-tests/p2p-acceptblock.py @@ -119,10 +119,10 @@ class AcceptBlockTest(BitcoinTestFramework): # from peers which are not whitelisted, while Node1 will be used for # the whitelisted case. self.nodes = [] - self.nodes.append(start_node(0, self.options.tmpdir, ["-debug"], + self.nodes.append(start_node(0, self.options.tmpdir, binary=self.options.testbinary)) self.nodes.append(start_node(1, self.options.tmpdir, - ["-debug", "-whitelist=127.0.0.1"], + ["-whitelist=127.0.0.1"], binary=self.options.testbinary)) def run_test(self): @@ -160,7 +160,7 @@ class AcceptBlockTest(BitcoinTestFramework): [ x.sync_with_ping() for x in [test_node, white_node] ] assert_equal(self.nodes[0].getblockcount(), 2) assert_equal(self.nodes[1].getblockcount(), 2) - print("First height 2 block accepted by both nodes") + self.log.info("First height 2 block accepted by both nodes") # 3. Send another block that builds on the original tip. blocks_h2f = [] # Blocks at height 2 that fork off the main chain @@ -179,7 +179,7 @@ class AcceptBlockTest(BitcoinTestFramework): if x['hash'] == blocks_h2f[1].hash: assert_equal(x['status'], "valid-headers") - print("Second height 2 block accepted only from whitelisted peer") + self.log.info("Second height 2 block accepted only from whitelisted peer") # 4. Now send another block that builds on the forking chain. blocks_h3 = [] @@ -198,11 +198,11 @@ class AcceptBlockTest(BitcoinTestFramework): # But this block should be accepted by node0 since it has more work. self.nodes[0].getblock(blocks_h3[0].hash) - print("Unrequested more-work block accepted from non-whitelisted peer") + self.log.info("Unrequested more-work block accepted from non-whitelisted peer") # Node1 should have accepted and reorged. assert_equal(self.nodes[1].getblockcount(), 3) - print("Successfully reorged to length 3 chain from whitelisted peer") + self.log.info("Successfully reorged to length 3 chain from whitelisted peer") # 4b. Now mine 288 more blocks and deliver; all should be processed but # the last (height-too-high) on node0. Node1 should process the tip if @@ -232,7 +232,7 @@ class AcceptBlockTest(BitcoinTestFramework): white_node.send_message(msg_block(tips[1])) # Now deliver the tip white_node.sync_with_ping() self.nodes[1].getblock(tips[1].hash) - print("Unrequested block far ahead of tip accepted from whitelisted peer") + self.log.info("Unrequested block far ahead of tip accepted from whitelisted peer") # 5. Test handling of unrequested block on the node that didn't process # Should still not be processed (even though it has a child that has more @@ -246,7 +246,7 @@ class AcceptBlockTest(BitcoinTestFramework): # a getdata request for this block. test_node.sync_with_ping() assert_equal(self.nodes[0].getblockcount(), 2) - print("Unrequested block that would complete more-work chain was ignored") + self.log.info("Unrequested block that would complete more-work chain was ignored") # 6. Try to get node to request the missing block. # Poke the node with an inv for block at height 3 and see if that @@ -262,14 +262,14 @@ class AcceptBlockTest(BitcoinTestFramework): # Check that the getdata includes the right block assert_equal(getdata.inv[0].hash, blocks_h2f[0].sha256) - print("Inv at tip triggered getdata for unprocessed block") + self.log.info("Inv at tip triggered getdata for unprocessed block") # 7. Send the missing block for the third time (now it is requested) test_node.send_message(msg_block(blocks_h2f[0])) test_node.sync_with_ping() assert_equal(self.nodes[0].getblockcount(), 290) - print("Successfully reorged to longer chain from non-whitelisted peer") + self.log.info("Successfully reorged to longer chain from non-whitelisted peer") [ c.disconnect_node() for c in connections ] diff --git a/qa/rpc-tests/p2p-compactblocks.py b/qa/rpc-tests/p2p-compactblocks.py index 79561f35f..1fc0312c3 100755 --- a/qa/rpc-tests/p2p-compactblocks.py +++ b/qa/rpc-tests/p2p-compactblocks.py @@ -120,8 +120,8 @@ class CompactBlocksTest(BitcoinTestFramework): # Start up node0 to be a version 1, pre-segwit node. self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, - [["-debug", "-logtimemicros=1", "-bip9params=segwit:0:0"], - ["-debug", "-logtimemicros", "-txindex"]]) + [["-bip9params=segwit:0:0"], + ["-txindex"]]) connect_nodes(self.nodes[0], 1) def build_block_on_tip(self, node, segwit=False): @@ -846,102 +846,102 @@ class CompactBlocksTest(BitcoinTestFramework): # We will need UTXOs to construct transactions in later tests. self.make_utxos() - print("Running tests, pre-segwit activation:") + self.log.info("Running tests, pre-segwit activation:") - print("\tTesting SENDCMPCT p2p message... ") + self.log.info("Testing SENDCMPCT p2p message... ") self.test_sendcmpct(self.nodes[0], self.test_node, 1) sync_blocks(self.nodes) self.test_sendcmpct(self.nodes[1], self.segwit_node, 2, old_node=self.old_node) sync_blocks(self.nodes) - print("\tTesting compactblock construction...") + self.log.info("Testing compactblock construction...") self.test_compactblock_construction(self.nodes[0], self.test_node, 1, False) sync_blocks(self.nodes) self.test_compactblock_construction(self.nodes[1], self.segwit_node, 2, False) sync_blocks(self.nodes) - print("\tTesting compactblock requests... ") + self.log.info("Testing compactblock requests... ") self.test_compactblock_requests(self.nodes[0], self.test_node, 1, False) sync_blocks(self.nodes) self.test_compactblock_requests(self.nodes[1], self.segwit_node, 2, False) sync_blocks(self.nodes) - print("\tTesting getblocktxn requests...") + self.log.info("Testing getblocktxn requests...") self.test_getblocktxn_requests(self.nodes[0], self.test_node, 1) sync_blocks(self.nodes) self.test_getblocktxn_requests(self.nodes[1], self.segwit_node, 2) sync_blocks(self.nodes) - print("\tTesting getblocktxn handler...") + self.log.info("Testing getblocktxn handler...") self.test_getblocktxn_handler(self.nodes[0], self.test_node, 1) sync_blocks(self.nodes) self.test_getblocktxn_handler(self.nodes[1], self.segwit_node, 2) self.test_getblocktxn_handler(self.nodes[1], self.old_node, 1) sync_blocks(self.nodes) - print("\tTesting compactblock requests/announcements not at chain tip...") + self.log.info("Testing compactblock requests/announcements not at chain tip...") self.test_compactblocks_not_at_tip(self.nodes[0], self.test_node) sync_blocks(self.nodes) self.test_compactblocks_not_at_tip(self.nodes[1], self.segwit_node) self.test_compactblocks_not_at_tip(self.nodes[1], self.old_node) sync_blocks(self.nodes) - print("\tTesting handling of incorrect blocktxn responses...") + self.log.info("Testing handling of incorrect blocktxn responses...") self.test_incorrect_blocktxn_response(self.nodes[0], self.test_node, 1) sync_blocks(self.nodes) self.test_incorrect_blocktxn_response(self.nodes[1], self.segwit_node, 2) sync_blocks(self.nodes) # End-to-end block relay tests - print("\tTesting end-to-end block relay...") + self.log.info("Testing end-to-end block relay...") self.request_cb_announcements(self.test_node, self.nodes[0], 1) self.request_cb_announcements(self.old_node, self.nodes[1], 1) self.request_cb_announcements(self.segwit_node, self.nodes[1], 2) self.test_end_to_end_block_relay(self.nodes[0], [self.segwit_node, self.test_node, self.old_node]) self.test_end_to_end_block_relay(self.nodes[1], [self.segwit_node, self.test_node, self.old_node]) - print("\tTesting handling of invalid compact blocks...") + self.log.info("Testing handling of invalid compact blocks...") self.test_invalid_tx_in_compactblock(self.nodes[0], self.test_node, False) self.test_invalid_tx_in_compactblock(self.nodes[1], self.segwit_node, False) self.test_invalid_tx_in_compactblock(self.nodes[1], self.old_node, False) - print("\tTesting reconstructing compact blocks from all peers...") + self.log.info("Testing reconstructing compact blocks from all peers...") self.test_compactblock_reconstruction_multiple_peers(self.nodes[1], self.segwit_node, self.old_node) sync_blocks(self.nodes) # Advance to segwit activation - print ("\nAdvancing to segwit activation\n") + self.log.info("Advancing to segwit activation") self.activate_segwit(self.nodes[1]) - print ("Running tests, post-segwit activation...") + self.log.info("Running tests, post-segwit activation...") - print("\tTesting compactblock construction...") + self.log.info("Testing compactblock construction...") self.test_compactblock_construction(self.nodes[1], self.old_node, 1, True) self.test_compactblock_construction(self.nodes[1], self.segwit_node, 2, True) sync_blocks(self.nodes) - print("\tTesting compactblock requests (unupgraded node)... ") + self.log.info("Testing compactblock requests (unupgraded node)... ") self.test_compactblock_requests(self.nodes[0], self.test_node, 1, True) - print("\tTesting getblocktxn requests (unupgraded node)...") + self.log.info("Testing getblocktxn requests (unupgraded node)...") self.test_getblocktxn_requests(self.nodes[0], self.test_node, 1) # Need to manually sync node0 and node1, because post-segwit activation, # node1 will not download blocks from node0. - print("\tSyncing nodes...") + self.log.info("Syncing nodes...") assert(self.nodes[0].getbestblockhash() != self.nodes[1].getbestblockhash()) while (self.nodes[0].getblockcount() > self.nodes[1].getblockcount()): block_hash = self.nodes[0].getblockhash(self.nodes[1].getblockcount()+1) self.nodes[1].submitblock(self.nodes[0].getblock(block_hash, False)) assert_equal(self.nodes[0].getbestblockhash(), self.nodes[1].getbestblockhash()) - print("\tTesting compactblock requests (segwit node)... ") + self.log.info("Testing compactblock requests (segwit node)... ") self.test_compactblock_requests(self.nodes[1], self.segwit_node, 2, True) - print("\tTesting getblocktxn requests (segwit node)...") + self.log.info("Testing getblocktxn requests (segwit node)...") self.test_getblocktxn_requests(self.nodes[1], self.segwit_node, 2) sync_blocks(self.nodes) - print("\tTesting getblocktxn handler (segwit node should return witnesses)...") + self.log.info("Testing getblocktxn handler (segwit node should return witnesses)...") self.test_getblocktxn_handler(self.nodes[1], self.segwit_node, 2) self.test_getblocktxn_handler(self.nodes[1], self.old_node, 1) @@ -949,18 +949,18 @@ class CompactBlocksTest(BitcoinTestFramework): # announcement to all peers. # (Post-segwit activation, blocks won't propagate from node0 to node1 # automatically, so don't bother testing a block announced to node0.) - print("\tTesting end-to-end block relay...") + self.log.info("Testing end-to-end block relay...") self.request_cb_announcements(self.test_node, self.nodes[0], 1) self.request_cb_announcements(self.old_node, self.nodes[1], 1) self.request_cb_announcements(self.segwit_node, self.nodes[1], 2) self.test_end_to_end_block_relay(self.nodes[1], [self.segwit_node, self.test_node, self.old_node]) - print("\tTesting handling of invalid compact blocks...") + self.log.info("Testing handling of invalid compact blocks...") self.test_invalid_tx_in_compactblock(self.nodes[0], self.test_node, False) self.test_invalid_tx_in_compactblock(self.nodes[1], self.segwit_node, True) self.test_invalid_tx_in_compactblock(self.nodes[1], self.old_node, True) - print("\tTesting invalid index in cmpctblock message...") + self.log.info("Testing invalid index in cmpctblock message...") self.test_invalid_cmpctblock_message() diff --git a/qa/rpc-tests/p2p-feefilter.py b/qa/rpc-tests/p2p-feefilter.py index 1c62961db..d8f07700d 100755 --- a/qa/rpc-tests/p2p-feefilter.py +++ b/qa/rpc-tests/p2p-feefilter.py @@ -53,8 +53,8 @@ class FeeFilterTest(BitcoinTestFramework): # Node1 will be used to generate txs which should be relayed from Node0 # to our test node self.nodes = [] - self.nodes.append(start_node(0, self.options.tmpdir, ["-debug", "-logtimemicros"])) - self.nodes.append(start_node(1, self.options.tmpdir, ["-debug", "-logtimemicros"])) + self.nodes.append(start_node(0, self.options.tmpdir)) + self.nodes.append(start_node(1, self.options.tmpdir)) connect_nodes(self.nodes[0], 1) def run_test(self): diff --git a/qa/rpc-tests/p2p-leaktests.py b/qa/rpc-tests/p2p-leaktests.py index bf08ea32f..3a843197f 100755 --- a/qa/rpc-tests/p2p-leaktests.py +++ b/qa/rpc-tests/p2p-leaktests.py @@ -32,7 +32,7 @@ class CLazyNode(NodeConnCB): def bad_message(self, message): self.unexpected_msg = True - print("should not have received message: %s" % message.command) + self.log.info("should not have received message: %s" % message.command) def on_open(self, conn): self.connected = True @@ -102,7 +102,7 @@ class P2PLeakTest(BitcoinTestFramework): super().__init__() self.num_nodes = 1 def setup_network(self): - extra_args = [['-debug', '-banscore='+str(banscore)] + extra_args = [['-banscore='+str(banscore)] for i in range(self.num_nodes)] self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, extra_args) diff --git a/qa/rpc-tests/p2p-mempool.py b/qa/rpc-tests/p2p-mempool.py index c6b149021..0aa9c90e8 100755 --- a/qa/rpc-tests/p2p-mempool.py +++ b/qa/rpc-tests/p2p-mempool.py @@ -85,7 +85,7 @@ class P2PMempoolTests(BitcoinTestFramework): def setup_network(self): # Start a node with maxuploadtarget of 200 MB (/24h) self.nodes = [] - self.nodes.append(start_node(0, self.options.tmpdir, ["-debug", "-peerbloomfilters=0"])) + self.nodes.append(start_node(0, self.options.tmpdir, ["-peerbloomfilters=0"])) def run_test(self): #connect a mininode diff --git a/qa/rpc-tests/p2p-segwit.py b/qa/rpc-tests/p2p-segwit.py index 470a5398b..0f844883b 100755 --- a/qa/rpc-tests/p2p-segwit.py +++ b/qa/rpc-tests/p2p-segwit.py @@ -70,7 +70,6 @@ class TestNode(NodeConnCB): def on_reject(self, conn, message): self.last_reject = message - #print (message) # Syncing helpers def sync(self, test_function, timeout=60): @@ -195,13 +194,13 @@ class SegWitTest(BitcoinTestFramework): def setup_network(self): self.nodes = [] - self.nodes.append(start_node(0, self.options.tmpdir, ["-debug", "-logtimemicros=1", "-whitelist=127.0.0.1"])) + self.nodes.append(start_node(0, self.options.tmpdir, ["-whitelist=127.0.0.1"])) # Start a node for testing IsStandard rules. - self.nodes.append(start_node(1, self.options.tmpdir, ["-debug", "-logtimemicros=1", "-whitelist=127.0.0.1", "-acceptnonstdtxn=0"])) + self.nodes.append(start_node(1, self.options.tmpdir, ["-whitelist=127.0.0.1", "-acceptnonstdtxn=0"])) connect_nodes(self.nodes[0], 1) # Disable segwit's bip9 parameter to simulate upgrading after activation. - self.nodes.append(start_node(2, self.options.tmpdir, ["-debug", "-whitelist=127.0.0.1", "-bip9params=segwit:0:0"])) + self.nodes.append(start_node(2, self.options.tmpdir, ["-whitelist=127.0.0.1", "-bip9params=segwit:0:0"])) connect_nodes(self.nodes[0], 2) ''' Helpers ''' @@ -224,7 +223,7 @@ class SegWitTest(BitcoinTestFramework): ''' Individual tests ''' def test_witness_services(self): - print("\tVerifying NODE_WITNESS service bit") + self.log.info("Verifying NODE_WITNESS service bit") assert((self.test_node.connection.nServices & NODE_WITNESS) != 0) @@ -233,7 +232,7 @@ class SegWitTest(BitcoinTestFramework): def test_non_witness_transaction(self): # Mine a block with an anyone-can-spend coinbase, # let it mature, then try to spend it. - print("\tTesting non-witness transaction") + self.log.info("Testing non-witness transaction") block = self.build_next_block(nVersion=1) block.solve() self.test_node.send_message(msg_block(block)) @@ -262,7 +261,7 @@ class SegWitTest(BitcoinTestFramework): # Verify that blocks with witnesses are rejected before activation. def test_unnecessary_witness_before_segwit_activation(self): - print("\tTesting behavior of unnecessary witnesses") + self.log.info("Testing behavior of unnecessary witnesses") # For now, rely on earlier tests to have created at least one utxo for # us to use assert(len(self.utxo) > 0) @@ -389,7 +388,7 @@ class SegWitTest(BitcoinTestFramework): # This test can only be run after segwit has activated def test_witness_commitments(self): - print("\tTesting witness commitments") + self.log.info("Testing witness commitments") # First try a correct witness commitment. block = self.build_next_block() @@ -478,7 +477,7 @@ class SegWitTest(BitcoinTestFramework): def test_block_malleability(self): - print("\tTesting witness block malleability") + self.log.info("Testing witness block malleability") # Make sure that a block that has too big a virtual size # because of a too-large coinbase witness is not permanently @@ -519,7 +518,7 @@ class SegWitTest(BitcoinTestFramework): def test_witness_block_size(self): - print("\tTesting witness block size limit") + self.log.info("Testing witness block size limit") # TODO: Test that non-witness carrying blocks can't exceed 1MB # Skipping this test for now; this is covered in p2p-fullblocktest.py @@ -636,7 +635,7 @@ class SegWitTest(BitcoinTestFramework): # Consensus tests of extra witness data in a transaction. def test_extra_witness_data(self): - print("\tTesting extra witness data in tx") + self.log.info("Testing extra witness data in tx") assert(len(self.utxo) > 0) @@ -712,7 +711,7 @@ class SegWitTest(BitcoinTestFramework): def test_max_witness_push_length(self): ''' Should only allow up to 520 byte pushes in witness stack ''' - print("\tTesting maximum witness push size") + self.log.info("Testing maximum witness push size") MAX_SCRIPT_ELEMENT_SIZE = 520 assert(len(self.utxo)) @@ -752,7 +751,7 @@ class SegWitTest(BitcoinTestFramework): def test_max_witness_program_length(self): # Can create witness outputs that are long, but can't be greater than # 10k bytes to successfully spend - print("\tTesting maximum witness program length") + self.log.info("Testing maximum witness program length") assert(len(self.utxo)) MAX_PROGRAM_LENGTH = 10000 @@ -801,7 +800,7 @@ class SegWitTest(BitcoinTestFramework): def test_witness_input_length(self): ''' Ensure that vin length must match vtxinwit length ''' - print("\tTesting witness input length") + self.log.info("Testing witness input length") assert(len(self.utxo)) witness_program = CScript([OP_DROP, OP_TRUE]) @@ -884,7 +883,7 @@ class SegWitTest(BitcoinTestFramework): def test_witness_tx_relay_before_segwit_activation(self): - print("\tTesting relay of witness transactions") + self.log.info("Testing relay of witness transactions") # Generate a transaction that doesn't require a witness, but send it # with a witness. Should be rejected for premature-witness, but should # not be added to recently rejected list. @@ -908,7 +907,7 @@ class SegWitTest(BitcoinTestFramework): # a witness transaction ought not result in a getdata. try: self.test_node.announce_tx_and_wait_for_getdata(tx, timeout=2) - print("Error: duplicate tx getdata!") + self.log.error("Error: duplicate tx getdata!") assert(False) except AssertionError as e: pass @@ -936,7 +935,7 @@ class SegWitTest(BitcoinTestFramework): # - accepts transactions with valid witnesses # and that witness transactions are relayed to non-upgraded peers. def test_tx_relay_after_segwit_activation(self): - print("\tTesting relay of witness transactions") + self.log.info("Testing relay of witness transactions") # Generate a transaction that doesn't require a witness, but send it # with a witness. Should be rejected because we can't use a witness # when spending a non-witness output. @@ -1025,7 +1024,7 @@ class SegWitTest(BitcoinTestFramework): # This is true regardless of segwit activation. # Also test that we don't ask for blocks from unupgraded peers def test_block_relay(self, segwit_activated): - print("\tTesting block relay") + self.log.info("Testing block relay") blocktype = 2|MSG_WITNESS_FLAG @@ -1113,7 +1112,7 @@ class SegWitTest(BitcoinTestFramework): # V0 segwit outputs should be standard after activation, but not before. def test_standardness_v0(self, segwit_activated): - print("\tTesting standardness of v0 outputs (%s activation)" % ("after" if segwit_activated else "before")) + self.log.info("Testing standardness of v0 outputs (%s activation)" % ("after" if segwit_activated else "before")) assert(len(self.utxo)) witness_program = CScript([OP_TRUE]) @@ -1190,7 +1189,7 @@ class SegWitTest(BitcoinTestFramework): # Verify that future segwit upgraded transactions are non-standard, # but valid in blocks. Can run this before and after segwit activation. def test_segwit_versions(self): - print("\tTesting standardness/consensus for segwit versions (0-16)") + self.log.info("Testing standardness/consensus for segwit versions (0-16)") assert(len(self.utxo)) NUM_TESTS = 17 # will test OP_0, OP1, ..., OP_16 if (len(self.utxo) < NUM_TESTS): @@ -1274,7 +1273,7 @@ class SegWitTest(BitcoinTestFramework): def test_premature_coinbase_witness_spend(self): - print("\tTesting premature coinbase witness spend") + self.log.info("Testing premature coinbase witness spend") block = self.build_next_block() # Change the output of the block to be a witness output. witness_program = CScript([OP_TRUE]) @@ -1309,7 +1308,7 @@ class SegWitTest(BitcoinTestFramework): def test_signature_version_1(self): - print("\tTesting segwit signature hash version 1") + self.log.info("Testing segwit signature hash version 1") key = CECKey() key.set_secretbytes(b"9") pubkey = CPubKey(key.get_pubkey()) @@ -1428,7 +1427,7 @@ class SegWitTest(BitcoinTestFramework): block = self.build_next_block() if (not used_sighash_single_out_of_bounds): - print("WARNING: this test run didn't attempt SIGHASH_SINGLE with out-of-bounds index value") + self.log.info("WARNING: this test run didn't attempt SIGHASH_SINGLE with out-of-bounds index value") # Test the transactions we've added to the block if (len(block.vtx) > 1): self.update_witness_block_with_transactions(block, []) @@ -1491,7 +1490,7 @@ class SegWitTest(BitcoinTestFramework): # Test P2SH wrapped witness programs. def test_p2sh_witness(self, segwit_activated): - print("\tTesting P2SH witness transactions") + self.log.info("Testing P2SH witness transactions") assert(len(self.utxo)) @@ -1564,7 +1563,7 @@ class SegWitTest(BitcoinTestFramework): # To enable this test, pass --oldbinary=<path-to-pre-segwit-bitcoind> to # the test. def test_upgrade_after_activation(self, node, node_id): - print("\tTesting software upgrade after softfork activation") + self.log.info("Testing software upgrade after softfork activation") assert(node_id != 0) # node0 is assumed to be a segwit-active bitcoind @@ -1573,7 +1572,7 @@ class SegWitTest(BitcoinTestFramework): # Restart with the new binary stop_node(node, node_id) - self.nodes[node_id] = start_node(node_id, self.options.tmpdir, ["-debug"]) + self.nodes[node_id] = start_node(node_id, self.options.tmpdir) connect_nodes(self.nodes[0], node_id) sync_blocks(self.nodes) @@ -1592,7 +1591,7 @@ class SegWitTest(BitcoinTestFramework): def test_witness_sigops(self): '''Ensure sigop counting is correct inside witnesses.''' - print("\tTesting sigops limit") + self.log.info("Testing sigops limit") assert(len(self.utxo)) @@ -1694,7 +1693,7 @@ class SegWitTest(BitcoinTestFramework): # TODO: test p2sh sigop counting def test_getblocktemplate_before_lockin(self): - print("\tTesting getblocktemplate setting of segwit versionbit (before lockin)") + self.log.info("Testing getblocktemplate setting of segwit versionbit (before lockin)") # Node0 is segwit aware, node2 is not. for node in [self.nodes[0], self.nodes[2]]: gbt_results = node.getblocktemplate() @@ -1746,7 +1745,7 @@ class SegWitTest(BitcoinTestFramework): # Uncompressed pubkeys are no longer supported in default relay policy, # but (for now) are still valid in blocks. def test_uncompressed_pubkey(self): - print("\tTesting uncompressed pubkeys") + self.log.info("Testing uncompressed pubkeys") # Segwit transactions using uncompressed pubkeys are not accepted # under default policy, but should still pass consensus. key = CECKey() @@ -1848,7 +1847,7 @@ class SegWitTest(BitcoinTestFramework): self.utxo.append(UTXO(tx5.sha256, 0, tx5.vout[0].nValue)) def test_non_standard_witness(self): - print("\tTesting detection of non-standard P2WSH witness") + self.log.info("Testing detection of non-standard P2WSH witness") pad = chr(1).encode('latin-1') # Create scripts for tests @@ -1972,7 +1971,7 @@ class SegWitTest(BitcoinTestFramework): # Test logic begins here self.test_node.wait_for_verack() - print("\nStarting tests before segwit lock in:") + self.log.info("Starting tests before segwit lock in:") self.test_witness_services() # Verifies NODE_WITNESS self.test_non_witness_transaction() # non-witness tx's are accepted @@ -1987,7 +1986,7 @@ class SegWitTest(BitcoinTestFramework): sync_blocks(self.nodes) # At lockin, nothing should change. - print("\nTesting behavior post lockin, pre-activation") + self.log.info("Testing behavior post lockin, pre-activation") self.advance_to_segwit_lockin() # Retest unnecessary witnesses @@ -2000,7 +1999,7 @@ class SegWitTest(BitcoinTestFramework): sync_blocks(self.nodes) # Now activate segwit - print("\nTesting behavior after segwit activation") + self.log.info("Testing behavior after segwit activation") self.advance_to_segwit_active() sync_blocks(self.nodes) diff --git a/qa/rpc-tests/p2p-timeouts.py b/qa/rpc-tests/p2p-timeouts.py index 7f596b6e4..498acb23f 100755 --- a/qa/rpc-tests/p2p-timeouts.py +++ b/qa/rpc-tests/p2p-timeouts.py @@ -53,8 +53,7 @@ class TimeoutsTest(BitcoinTestFramework): self.nodes = [] # Start up node0 to be a version 1, pre-segwit node. - self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, - [["-debug", "-logtimemicros=1"]]) + self.nodes = start_nodes(self.num_nodes, self.options.tmpdir) def run_test(self): # Setup the p2p connections and start up the network thread. diff --git a/qa/rpc-tests/p2p-versionbits-warning.py b/qa/rpc-tests/p2p-versionbits-warning.py index 8e3e361fc..dc714e9a4 100755 --- a/qa/rpc-tests/p2p-versionbits-warning.py +++ b/qa/rpc-tests/p2p-versionbits-warning.py @@ -72,7 +72,7 @@ class VersionBitsWarningTest(BitcoinTestFramework): # Open and close to create zero-length file with open(self.alert_filename, 'w', encoding='utf8') as _: pass - self.extra_args = [["-debug", "-logtimemicros=1", "-alertnotify=echo %s >> \"" + self.alert_filename + "\""]] + self.extra_args = [["-alertnotify=echo %s >> \"" + self.alert_filename + "\""]] self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, self.extra_args) # Send numblocks blocks via peer with nVersionToUse set. diff --git a/qa/rpc-tests/preciousblock.py b/qa/rpc-tests/preciousblock.py index dde164f32..30b0b5a30 100755 --- a/qa/rpc-tests/preciousblock.py +++ b/qa/rpc-tests/preciousblock.py @@ -39,13 +39,12 @@ class PreciousTest(BitcoinTestFramework): super().__init__() self.setup_clean_chain = True self.num_nodes = 3 - self.extra_args = [["-debug"]] * self.num_nodes def setup_network(self): self.nodes = self.setup_nodes() def run_test(self): - print("Ensure submitblock can in principle reorg to a competing chain") + self.log.info("Ensure submitblock can in principle reorg to a competing chain") self.nodes[0].generate(1) assert_equal(self.nodes[0].getblockcount(), 1) (hashY, hashZ) = self.nodes[1].generate(2) @@ -53,62 +52,62 @@ class PreciousTest(BitcoinTestFramework): node_sync_via_rpc(self.nodes[0:3]) assert_equal(self.nodes[0].getbestblockhash(), hashZ) - print("Mine blocks A-B-C on Node 0") + self.log.info("Mine blocks A-B-C on Node 0") (hashA, hashB, hashC) = self.nodes[0].generate(3) assert_equal(self.nodes[0].getblockcount(), 5) - print("Mine competing blocks E-F-G on Node 1") + self.log.info("Mine competing blocks E-F-G on Node 1") (hashE, hashF, hashG) = self.nodes[1].generate(3) assert_equal(self.nodes[1].getblockcount(), 5) assert(hashC != hashG) - print("Connect nodes and check no reorg occurs") + self.log.info("Connect nodes and check no reorg occurs") # Submit competing blocks via RPC so any reorg should occur before we proceed (no way to wait on inaction for p2p sync) node_sync_via_rpc(self.nodes[0:2]) connect_nodes_bi(self.nodes,0,1) assert_equal(self.nodes[0].getbestblockhash(), hashC) assert_equal(self.nodes[1].getbestblockhash(), hashG) - print("Make Node0 prefer block G") + self.log.info("Make Node0 prefer block G") self.nodes[0].preciousblock(hashG) assert_equal(self.nodes[0].getbestblockhash(), hashG) - print("Make Node0 prefer block C again") + self.log.info("Make Node0 prefer block C again") self.nodes[0].preciousblock(hashC) assert_equal(self.nodes[0].getbestblockhash(), hashC) - print("Make Node1 prefer block C") + self.log.info("Make Node1 prefer block C") self.nodes[1].preciousblock(hashC) sync_chain(self.nodes[0:2]) # wait because node 1 may not have downloaded hashC assert_equal(self.nodes[1].getbestblockhash(), hashC) - print("Make Node1 prefer block G again") + self.log.info("Make Node1 prefer block G again") self.nodes[1].preciousblock(hashG) assert_equal(self.nodes[1].getbestblockhash(), hashG) - print("Make Node0 prefer block G again") + self.log.info("Make Node0 prefer block G again") self.nodes[0].preciousblock(hashG) assert_equal(self.nodes[0].getbestblockhash(), hashG) - print("Make Node1 prefer block C again") + self.log.info("Make Node1 prefer block C again") self.nodes[1].preciousblock(hashC) assert_equal(self.nodes[1].getbestblockhash(), hashC) - print("Mine another block (E-F-G-)H on Node 0 and reorg Node 1") + self.log.info("Mine another block (E-F-G-)H on Node 0 and reorg Node 1") self.nodes[0].generate(1) assert_equal(self.nodes[0].getblockcount(), 6) sync_blocks(self.nodes[0:2]) hashH = self.nodes[0].getbestblockhash() assert_equal(self.nodes[1].getbestblockhash(), hashH) - print("Node1 should not be able to prefer block C anymore") + self.log.info("Node1 should not be able to prefer block C anymore") self.nodes[1].preciousblock(hashC) assert_equal(self.nodes[1].getbestblockhash(), hashH) - print("Mine competing blocks I-J-K-L on Node 2") + self.log.info("Mine competing blocks I-J-K-L on Node 2") self.nodes[2].generate(4) assert_equal(self.nodes[2].getblockcount(), 6) hashL = self.nodes[2].getbestblockhash() - print("Connect nodes and check no reorg occurs") + self.log.info("Connect nodes and check no reorg occurs") node_sync_via_rpc(self.nodes[1:3]) connect_nodes_bi(self.nodes,1,2) connect_nodes_bi(self.nodes,0,2) assert_equal(self.nodes[0].getbestblockhash(), hashH) assert_equal(self.nodes[1].getbestblockhash(), hashH) assert_equal(self.nodes[2].getbestblockhash(), hashL) - print("Make Node1 prefer block L") + self.log.info("Make Node1 prefer block L") self.nodes[1].preciousblock(hashL) assert_equal(self.nodes[1].getbestblockhash(), hashL) - print("Make Node2 prefer block H") + self.log.info("Make Node2 prefer block H") self.nodes[2].preciousblock(hashH) assert_equal(self.nodes[2].getbestblockhash(), hashH) diff --git a/qa/rpc-tests/prioritise_transaction.py b/qa/rpc-tests/prioritise_transaction.py index 13be6eeea..10f596b2c 100755 --- a/qa/rpc-tests/prioritise_transaction.py +++ b/qa/rpc-tests/prioritise_transaction.py @@ -21,7 +21,7 @@ class PrioritiseTransactionTest(BitcoinTestFramework): self.nodes = [] self.is_network_split = False - self.nodes.append(start_node(0, self.options.tmpdir, ["-debug", "-printpriority=1"])) + self.nodes.append(start_node(0, self.options.tmpdir, ["-printpriority=1"])) self.relayfee = self.nodes[0].getnetworkinfo()['relayfee'] def run_test(self): @@ -56,7 +56,7 @@ class PrioritiseTransactionTest(BitcoinTestFramework): self.nodes[0].generate(1) mempool = self.nodes[0].getrawmempool() - print("Assert that prioritised transaction was mined") + self.log.info("Assert that prioritised transaction was mined") assert(txids[0][0] not in mempool) assert(txids[0][1] in mempool) @@ -88,7 +88,7 @@ class PrioritiseTransactionTest(BitcoinTestFramework): # High fee transaction should not have been mined, but other high fee rate # transactions should have been. mempool = self.nodes[0].getrawmempool() - print("Assert that de-prioritised transaction is still in mempool") + self.log.info("Assert that de-prioritised transaction is still in mempool") assert(high_fee_tx in mempool) for x in txids[2]: if (x != high_fee_tx): @@ -120,7 +120,7 @@ class PrioritiseTransactionTest(BitcoinTestFramework): # accepted. self.nodes[0].prioritisetransaction(tx_id, int(self.relayfee*COIN)) - print("Assert that prioritised free transaction is accepted to mempool") + self.log.info("Assert that prioritised free transaction is accepted to mempool") assert_equal(self.nodes[0].sendrawtransaction(tx_hex), tx_id) assert(tx_id in self.nodes[0].getrawmempool()) diff --git a/qa/rpc-tests/proxy_test.py b/qa/rpc-tests/proxy_test.py index e4e231f31..6b2a8ed1c 100755 --- a/qa/rpc-tests/proxy_test.py +++ b/qa/rpc-tests/proxy_test.py @@ -83,13 +83,13 @@ class ProxyTest(BitcoinTestFramework): # Note: proxies are not used to connect to local nodes # this is because the proxy to use is based on CService.GetNetwork(), which return NET_UNROUTABLE for localhost args = [ - ['-listen', '-debug=net', '-debug=proxy', '-proxy=%s:%i' % (self.conf1.addr),'-proxyrandomize=1'], - ['-listen', '-debug=net', '-debug=proxy', '-proxy=%s:%i' % (self.conf1.addr),'-onion=%s:%i' % (self.conf2.addr),'-proxyrandomize=0'], - ['-listen', '-debug=net', '-debug=proxy', '-proxy=%s:%i' % (self.conf2.addr),'-proxyrandomize=1'], + ['-listen', '-proxy=%s:%i' % (self.conf1.addr),'-proxyrandomize=1'], + ['-listen', '-proxy=%s:%i' % (self.conf1.addr),'-onion=%s:%i' % (self.conf2.addr),'-proxyrandomize=0'], + ['-listen', '-proxy=%s:%i' % (self.conf2.addr),'-proxyrandomize=1'], [] ] if self.have_ipv6: - args[3] = ['-listen', '-debug=net', '-debug=proxy', '-proxy=[%s]:%i' % (self.conf3.addr),'-proxyrandomize=0', '-noonion'] + args[3] = ['-listen', '-proxy=[%s]:%i' % (self.conf3.addr),'-proxyrandomize=0', '-noonion'] return start_nodes(self.num_nodes, self.options.tmpdir, extra_args=args) def node_test(self, node, proxies, auth, test_onion=True): diff --git a/qa/rpc-tests/pruning.py b/qa/rpc-tests/pruning.py index 6d778cfc5..c6a82b5fe 100755 --- a/qa/rpc-tests/pruning.py +++ b/qa/rpc-tests/pruning.py @@ -41,19 +41,19 @@ class PruneTest(BitcoinTestFramework): self.is_network_split = False # Create nodes 0 and 1 to mine - self.nodes.append(start_node(0, self.options.tmpdir, ["-debug","-maxreceivebuffer=20000","-blockmaxsize=999000", "-checkblocks=5"], timewait=900)) - self.nodes.append(start_node(1, self.options.tmpdir, ["-debug","-maxreceivebuffer=20000","-blockmaxsize=999000", "-checkblocks=5"], timewait=900)) + self.nodes.append(start_node(0, self.options.tmpdir, ["-maxreceivebuffer=20000","-blockmaxsize=999000", "-checkblocks=5"], timewait=900)) + self.nodes.append(start_node(1, self.options.tmpdir, ["-maxreceivebuffer=20000","-blockmaxsize=999000", "-checkblocks=5"], timewait=900)) # Create node 2 to test pruning - self.nodes.append(start_node(2, self.options.tmpdir, ["-debug","-maxreceivebuffer=20000","-prune=550"], timewait=900)) + self.nodes.append(start_node(2, self.options.tmpdir, ["-maxreceivebuffer=20000","-prune=550"], timewait=900)) self.prunedir = self.options.tmpdir+"/node2/regtest/blocks/" # Create nodes 3 and 4 to test manual pruning (they will be re-started with manual pruning later) - self.nodes.append(start_node(3, self.options.tmpdir, ["-debug=0","-maxreceivebuffer=20000","-blockmaxsize=999000"], timewait=900)) - self.nodes.append(start_node(4, self.options.tmpdir, ["-debug=0","-maxreceivebuffer=20000","-blockmaxsize=999000"], timewait=900)) + self.nodes.append(start_node(3, self.options.tmpdir, ["-maxreceivebuffer=20000","-blockmaxsize=999000"], timewait=900)) + self.nodes.append(start_node(4, self.options.tmpdir, ["-maxreceivebuffer=20000","-blockmaxsize=999000"], timewait=900)) # Create nodes 5 to test wallet in prune mode, but do not connect - self.nodes.append(start_node(5, self.options.tmpdir, ["-debug=0", "-prune=550"])) + self.nodes.append(start_node(5, self.options.tmpdir, ["-prune=550"])) # Determine default relay fee self.relayfee = self.nodes[0].getnetworkinfo()["relayfee"] @@ -79,9 +79,9 @@ class PruneTest(BitcoinTestFramework): def test_height_min(self): if not os.path.isfile(self.prunedir+"blk00000.dat"): raise AssertionError("blk00000.dat is missing, pruning too early") - print("Success") - print("Though we're already using more than 550MiB, current usage:", calc_usage(self.prunedir)) - print("Mining 25 more blocks should cause the first block file to be pruned") + self.log.info("Success") + self.log.info("Though we're already using more than 550MiB, current usage:", calc_usage(self.prunedir)) + self.log.info("Mining 25 more blocks should cause the first block file to be pruned") # Pruning doesn't run until we're allocating another chunk, 20 full blocks past the height cutoff will ensure this for i in range(25): mine_large_block(self.nodes[0], self.utxo_cache_0) @@ -92,22 +92,22 @@ class PruneTest(BitcoinTestFramework): if time.time() - waitstart > 30: raise AssertionError("blk00000.dat not pruned when it should be") - print("Success") + self.log.info("Success") usage = calc_usage(self.prunedir) - print("Usage should be below target:", usage) + self.log.info("Usage should be below target:", usage) if (usage > 550): raise AssertionError("Pruning target not being met") def create_chain_with_staleblocks(self): # Create stale blocks in manageable sized chunks - print("Mine 24 (stale) blocks on Node 1, followed by 25 (main chain) block reorg from Node 0, for 12 rounds") + self.log.info("Mine 24 (stale) blocks on Node 1, followed by 25 (main chain) block reorg from Node 0, for 12 rounds") for j in range(12): # Disconnect node 0 so it can mine a longer reorg chain without knowing about node 1's soon-to-be-stale chain # Node 2 stays connected, so it hears about the stale blocks and then reorg's when node0 reconnects # Stopping node 0 also clears its mempool, so it doesn't have node1's transactions to accidentally mine self.stop_node(0) - self.nodes[0]=start_node(0, self.options.tmpdir, ["-debug","-maxreceivebuffer=20000","-blockmaxsize=999000", "-checkblocks=5"], timewait=900) + self.nodes[0]=start_node(0, self.options.tmpdir, ["-maxreceivebuffer=20000","-blockmaxsize=999000", "-checkblocks=5"], timewait=900) # Mine 24 blocks in node 1 for i in range(24): if j == 0: @@ -124,7 +124,7 @@ class PruneTest(BitcoinTestFramework): connect_nodes(self.nodes[2], 0) sync_blocks(self.nodes[0:3]) - print("Usage can be over target because of high stale rate:", calc_usage(self.prunedir)) + self.log.info("Usage can be over target because of high stale rate:", calc_usage(self.prunedir)) def reorg_test(self): # Node 1 will mine a 300 block chain starting 287 blocks back from Node 0 and Node 2's tip @@ -132,14 +132,14 @@ class PruneTest(BitcoinTestFramework): # Reboot node 1 to clear its mempool (hopefully make the invalidate faster) # Lower the block max size so we don't keep mining all our big mempool transactions (from disconnected blocks) self.stop_node(1) - self.nodes[1]=start_node(1, self.options.tmpdir, ["-debug","-maxreceivebuffer=20000","-blockmaxsize=5000", "-checkblocks=5", "-disablesafemode"], timewait=900) + self.nodes[1]=start_node(1, self.options.tmpdir, ["-maxreceivebuffer=20000","-blockmaxsize=5000", "-checkblocks=5", "-disablesafemode"], timewait=900) height = self.nodes[1].getblockcount() - print("Current block height:", height) + self.log.info("Current block height:", height) invalidheight = height-287 badhash = self.nodes[1].getblockhash(invalidheight) - print("Invalidating block at height:",invalidheight,badhash) + self.log.info("Invalidating block at height:",invalidheight,badhash) self.nodes[1].invalidateblock(badhash) # We've now switched to our previously mined-24 block fork on node 1, but thats not what we want @@ -151,24 +151,24 @@ class PruneTest(BitcoinTestFramework): curhash = self.nodes[1].getblockhash(invalidheight - 1) assert(self.nodes[1].getblockcount() == invalidheight - 1) - print("New best height", self.nodes[1].getblockcount()) + self.log.info("New best height", self.nodes[1].getblockcount()) # Reboot node1 to clear those giant tx's from mempool self.stop_node(1) - self.nodes[1]=start_node(1, self.options.tmpdir, ["-debug","-maxreceivebuffer=20000","-blockmaxsize=5000", "-checkblocks=5", "-disablesafemode"], timewait=900) + self.nodes[1]=start_node(1, self.options.tmpdir, ["-maxreceivebuffer=20000","-blockmaxsize=5000", "-checkblocks=5", "-disablesafemode"], timewait=900) - print("Generating new longer chain of 300 more blocks") + self.log.info("Generating new longer chain of 300 more blocks") self.nodes[1].generate(300) - print("Reconnect nodes") + self.log.info("Reconnect nodes") connect_nodes(self.nodes[0], 1) connect_nodes(self.nodes[2], 1) sync_blocks(self.nodes[0:3], timeout=120) - print("Verify height on node 2:",self.nodes[2].getblockcount()) - print("Usage possibly still high bc of stale blocks in block files:", calc_usage(self.prunedir)) + self.log.info("Verify height on node 2:",self.nodes[2].getblockcount()) + self.log.info("Usage possibly still high bc of stale blocks in block files:", calc_usage(self.prunedir)) - print("Mine 220 more blocks so we have requisite history (some blocks will be big and cause pruning of previous chain)") + self.log.info("Mine 220 more blocks so we have requisite history (some blocks will be big and cause pruning of previous chain)") for i in range(22): # This can be slow, so do this in multiple RPC calls to avoid # RPC timeouts. @@ -176,7 +176,7 @@ class PruneTest(BitcoinTestFramework): sync_blocks(self.nodes[0:3], timeout=300) usage = calc_usage(self.prunedir) - print("Usage should be below target:", usage) + self.log.info("Usage should be below target:", usage) if (usage > 550): raise AssertionError("Pruning target not being met") @@ -185,7 +185,7 @@ class PruneTest(BitcoinTestFramework): def reorg_back(self): # Verify that a block on the old main chain fork has been pruned away assert_raises_jsonrpc(-1, "Block not available (pruned data)", self.nodes[2].getblock, self.forkhash) - print("Will need to redownload block",self.forkheight) + self.log.info("Will need to redownload block",self.forkheight) # Verify that we have enough history to reorg back to the fork point # Although this is more than 288 blocks, because this chain was written more recently @@ -209,14 +209,14 @@ class PruneTest(BitcoinTestFramework): # At this point node 2 is within 288 blocks of the fork point so it will preserve its ability to reorg if self.nodes[2].getblockcount() < self.mainchainheight: blocks_to_mine = first_reorg_height + 1 - self.mainchainheight - print("Rewind node 0 to prev main chain to mine longer chain to trigger redownload. Blocks needed:", blocks_to_mine) + self.log.info("Rewind node 0 to prev main chain to mine longer chain to trigger redownload. Blocks needed:", blocks_to_mine) self.nodes[0].invalidateblock(curchainhash) assert(self.nodes[0].getblockcount() == self.mainchainheight) assert(self.nodes[0].getbestblockhash() == self.mainchainhash2) goalbesthash = self.nodes[0].generate(blocks_to_mine)[-1] goalbestheight = first_reorg_height + 1 - print("Verify node 2 reorged back to the main chain, some blocks of which it had to redownload") + self.log.info("Verify node 2 reorged back to the main chain, some blocks of which it had to redownload") waitstart = time.time() while self.nodes[2].getblockcount() < goalbestheight: time.sleep(0.1) @@ -228,13 +228,13 @@ class PruneTest(BitcoinTestFramework): def manual_test(self, node_number, use_timestamp): # at this point, node has 995 blocks and has not yet run in prune mode - node = self.nodes[node_number] = start_node(node_number, self.options.tmpdir, ["-debug=0"], timewait=900) + node = self.nodes[node_number] = start_node(node_number, self.options.tmpdir, timewait=900) assert_equal(node.getblockcount(), 995) assert_raises_jsonrpc(-1, "not in prune mode", node.pruneblockchain, 500) self.stop_node(node_number) # now re-start in manual pruning mode - node = self.nodes[node_number] = start_node(node_number, self.options.tmpdir, ["-debug=0","-prune=1"], timewait=900) + node = self.nodes[node_number] = start_node(node_number, self.options.tmpdir, ["-prune=1"], timewait=900) assert_equal(node.getblockcount(), 995) def height(index): @@ -308,30 +308,30 @@ class PruneTest(BitcoinTestFramework): # stop node, start back up with auto-prune at 550MB, make sure still runs self.stop_node(node_number) - self.nodes[node_number] = start_node(node_number, self.options.tmpdir, ["-debug=0","-prune=550"], timewait=900) + self.nodes[node_number] = start_node(node_number, self.options.tmpdir, ["-prune=550"], timewait=900) - print("Success") + self.log.info("Success") def wallet_test(self): # check that the pruning node's wallet is still in good shape - print("Stop and start pruning node to trigger wallet rescan") + self.log.info("Stop and start pruning node to trigger wallet rescan") self.stop_node(2) - start_node(2, self.options.tmpdir, ["-debug=1","-prune=550"]) - print("Success") + start_node(2, self.options.tmpdir, ["-prune=550"]) + self.log.info("Success") # check that wallet loads loads successfully when restarting a pruned node after IBD. # this was reported to fail in #7494. - print ("Syncing node 5 to test wallet") + self.log.info("Syncing node 5 to test wallet") connect_nodes(self.nodes[0], 5) nds = [self.nodes[0], self.nodes[5]] sync_blocks(nds, wait=5, timeout=300) self.stop_node(5) #stop and start to trigger rescan - start_node(5, self.options.tmpdir, ["-debug=1","-prune=550"]) - print ("Success") + start_node(5, self.options.tmpdir, ["-prune=550"]) + self.log.info("Success") def run_test(self): - print("Warning! This test requires 4GB of disk space and takes over 30 mins (up to 2 hours)") - print("Mining a big blockchain of 995 blocks") + self.log.info("Warning! This test requires 4GB of disk space and takes over 30 mins (up to 2 hours)") + self.log.info("Mining a big blockchain of 995 blocks") self.create_big_chain() # Chain diagram key: # * blocks on main chain @@ -346,12 +346,12 @@ class PruneTest(BitcoinTestFramework): self.stop_node(3) self.stop_node(4) - print("Check that we haven't started pruning yet because we're below PruneAfterHeight") + self.log.info("Check that we haven't started pruning yet because we're below PruneAfterHeight") self.test_height_min() # Extend this chain past the PruneAfterHeight # N0=N1=N2 **...*(1020) - print("Check that we'll exceed disk space target if we have a very high stale block rate") + self.log.info("Check that we'll exceed disk space target if we have a very high stale block rate") self.create_chain_with_staleblocks() # Disconnect N0 # And mine a 24 block chain on N1 and a separate 25 block chain on N0 @@ -375,7 +375,7 @@ class PruneTest(BitcoinTestFramework): self.mainchainheight = self.nodes[2].getblockcount() #1320 self.mainchainhash2 = self.nodes[2].getblockhash(self.mainchainheight) - print("Check that we can survive a 288 block reorg still") + self.log.info("Check that we can survive a 288 block reorg still") (self.forkheight,self.forkhash) = self.reorg_test() #(1033, ) # Now create a 288 block reorg by mining a longer chain on N1 # First disconnect N1 @@ -408,7 +408,7 @@ class PruneTest(BitcoinTestFramework): # \ # *...**(1320) - print("Test that we can rerequest a block we previously pruned if needed for a reorg") + self.log.info("Test that we can rerequest a block we previously pruned if needed for a reorg") self.reorg_back() # Verify that N2 still has block 1033 on current chain (@), but not on main chain (*) # Invalidate 1033 on current chain (@) on N2 and we should be able to reorg to @@ -428,16 +428,16 @@ class PruneTest(BitcoinTestFramework): # # N1 doesn't change because 1033 on main chain (*) is invalid - print("Test manual pruning with block indices") + self.log.info("Test manual pruning with block indices") self.manual_test(3, use_timestamp=False) - print("Test manual pruning with timestamps") + self.log.info("Test manual pruning with timestamps") self.manual_test(4, use_timestamp=True) - print("Test wallet re-scan") + self.log.info("Test wallet re-scan") self.wallet_test() - print("Done") + self.log.info("Done") if __name__ == '__main__': PruneTest().main() diff --git a/qa/rpc-tests/reindex.py b/qa/rpc-tests/reindex.py index 1b547a920..0cebb0466 100755 --- a/qa/rpc-tests/reindex.py +++ b/qa/rpc-tests/reindex.py @@ -31,12 +31,12 @@ class ReindexTest(BitcoinTestFramework): self.nodes[0].generate(3) blockcount = self.nodes[0].getblockcount() stop_nodes(self.nodes) - extra_args = [["-debug", "-reindex-chainstate" if justchainstate else "-reindex", "-checkblockindex=1"]] + extra_args = [["-reindex-chainstate" if justchainstate else "-reindex", "-checkblockindex=1"]] self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, extra_args) while self.nodes[0].getblockcount() < blockcount: time.sleep(0.1) assert_equal(self.nodes[0].getblockcount(), blockcount) - print("Success") + self.log.info("Success") def run_test(self): self.reindex(False) diff --git a/qa/rpc-tests/replace-by-fee.py b/qa/rpc-tests/replace-by-fee.py index 51cbb4dc4..8e2abea6a 100755 --- a/qa/rpc-tests/replace-by-fee.py +++ b/qa/rpc-tests/replace-by-fee.py @@ -25,19 +25,15 @@ def make_utxo(node, amount, confirmed=True, scriptPubKey=CScript([1])): fee = 1*COIN while node.getbalance() < satoshi_round((amount + fee)/COIN): node.generate(100) - #print (node.getbalance(), amount, fee) new_addr = node.getnewaddress() - #print new_addr txid = node.sendtoaddress(new_addr, satoshi_round((amount+fee)/COIN)) tx1 = node.getrawtransaction(txid, 1) txid = int(txid, 16) i = None for i, txout in enumerate(tx1['vout']): - #print i, txout['scriptPubKey']['addresses'] if txout['scriptPubKey']['addresses'] == [new_addr]: - #print i break assert i is not None @@ -72,7 +68,7 @@ class ReplaceByFeeTest(BitcoinTestFramework): def setup_network(self): self.nodes = [] - self.nodes.append(start_node(0, self.options.tmpdir, ["-maxorphantx=1000", "-debug", + self.nodes.append(start_node(0, self.options.tmpdir, ["-maxorphantx=1000", "-whitelist=127.0.0.1", "-limitancestorcount=50", "-limitancestorsize=101", @@ -84,34 +80,34 @@ class ReplaceByFeeTest(BitcoinTestFramework): def run_test(self): make_utxo(self.nodes[0], 1*COIN) - print("Running test simple doublespend...") + self.log.info("Running test simple doublespend...") self.test_simple_doublespend() - print("Running test doublespend chain...") + self.log.info("Running test doublespend chain...") self.test_doublespend_chain() - print("Running test doublespend tree...") + self.log.info("Running test doublespend tree...") self.test_doublespend_tree() - print("Running test replacement feeperkb...") + self.log.info("Running test replacement feeperkb...") self.test_replacement_feeperkb() - print("Running test spends of conflicting outputs...") + self.log.info("Running test spends of conflicting outputs...") self.test_spends_of_conflicting_outputs() - print("Running test new unconfirmed inputs...") + self.log.info("Running test new unconfirmed inputs...") self.test_new_unconfirmed_inputs() - print("Running test too many replacements...") + self.log.info("Running test too many replacements...") self.test_too_many_replacements() - print("Running test opt-in...") + self.log.info("Running test opt-in...") self.test_opt_in() - print("Running test prioritised transactions...") + self.log.info("Running test prioritised transactions...") self.test_prioritised_transactions() - print("Passed\n") + self.log.info("Passed") def test_simple_doublespend(self): """Simple doublespend""" @@ -460,7 +456,7 @@ class ReplaceByFeeTest(BitcoinTestFramework): except JSONRPCException as exp: assert_equal(exp.error['code'], -26) else: - print(tx1b_txid) + self.log.info(tx1b_txid) assert(False) tx1_outpoint = make_utxo(self.nodes[0], int(1.1*COIN)) diff --git a/qa/rpc-tests/rest.py b/qa/rpc-tests/rest.py index 9ca1cc187..776211d30 100755 --- a/qa/rpc-tests/rest.py +++ b/qa/rpc-tests/rest.py @@ -58,7 +58,7 @@ class RESTTest (BitcoinTestFramework): def run_test(self): url = urllib.parse.urlparse(self.nodes[0].url) - print("Mining blocks...") + self.log.info("Mining blocks...") self.nodes[0].generate(1) self.sync_all() diff --git a/qa/rpc-tests/rpcbind_test.py b/qa/rpc-tests/rpcbind_test.py index 499fe3367..220bf4ddd 100755 --- a/qa/rpc-tests/rpcbind_test.py +++ b/qa/rpc-tests/rpcbind_test.py @@ -61,7 +61,7 @@ class RPCBindTest(BitcoinTestFramework): break if non_loopback_ip is None: assert(not 'This test requires at least one non-loopback IPv4 interface') - print("Using interface %s for testing" % non_loopback_ip) + self.log.info("Using interface %s for testing" % non_loopback_ip) defaultport = rpc_port(0) diff --git a/qa/rpc-tests/segwit.py b/qa/rpc-tests/segwit.py index 761c00dc0..f480e5c3f 100755 --- a/qa/rpc-tests/segwit.py +++ b/qa/rpc-tests/segwit.py @@ -82,9 +82,9 @@ class SegWitTest(BitcoinTestFramework): def setup_network(self): self.nodes = [] - self.nodes.append(start_node(0, self.options.tmpdir, ["-logtimemicros", "-debug", "-walletprematurewitness", "-rpcserialversion=0"])) - self.nodes.append(start_node(1, self.options.tmpdir, ["-logtimemicros", "-debug", "-blockversion=4", "-promiscuousmempoolflags=517", "-prematurewitness", "-walletprematurewitness", "-rpcserialversion=1"])) - self.nodes.append(start_node(2, self.options.tmpdir, ["-logtimemicros", "-debug", "-blockversion=536870915", "-promiscuousmempoolflags=517", "-prematurewitness", "-walletprematurewitness"])) + self.nodes.append(start_node(0, self.options.tmpdir, ["-walletprematurewitness", "-rpcserialversion=0"])) + self.nodes.append(start_node(1, self.options.tmpdir, ["-blockversion=4", "-promiscuousmempoolflags=517", "-prematurewitness", "-walletprematurewitness", "-rpcserialversion=1"])) + self.nodes.append(start_node(2, self.options.tmpdir, ["-blockversion=536870915", "-promiscuousmempoolflags=517", "-prematurewitness", "-walletprematurewitness"])) connect_nodes(self.nodes[1], 0) connect_nodes(self.nodes[2], 1) connect_nodes(self.nodes[0], 2) @@ -124,7 +124,7 @@ class SegWitTest(BitcoinTestFramework): def run_test(self): self.nodes[0].generate(161) #block 161 - print("Verify sigops are counted in GBT with pre-BIP141 rules before the fork") + self.log.info("Verify sigops are counted in GBT with pre-BIP141 rules before the fork") txid = self.nodes[0].sendtoaddress(self.nodes[0].getnewaddress(), 1) tmpl = self.nodes[0].getblocktemplate({}) assert(tmpl['sizelimit'] == 1000000) @@ -173,7 +173,7 @@ class SegWitTest(BitcoinTestFramework): self.nodes[0].generate(260) #block 423 sync_blocks(self.nodes) - print("Verify default node can't accept any witness format txs before fork") + self.log.info("Verify default node can't accept any witness format txs before fork") # unsigned, no scriptsig self.fail_accept(self.nodes[0], wit_ids[NODE_0][WIT_V0][0], False) self.fail_accept(self.nodes[0], wit_ids[NODE_0][WIT_V1][0], False) @@ -188,7 +188,7 @@ class SegWitTest(BitcoinTestFramework): self.fail_accept(self.nodes[0], p2sh_ids[NODE_0][WIT_V0][0], True) self.fail_accept(self.nodes[0], p2sh_ids[NODE_0][WIT_V1][0], True) - print("Verify witness txs are skipped for mining before the fork") + self.log.info("Verify witness txs are skipped for mining before the fork") self.skip_mine(self.nodes[2], wit_ids[NODE_2][WIT_V0][0], True) #block 424 self.skip_mine(self.nodes[2], wit_ids[NODE_2][WIT_V1][0], True) #block 425 self.skip_mine(self.nodes[2], p2sh_ids[NODE_2][WIT_V0][0], True) #block 426 @@ -196,19 +196,19 @@ class SegWitTest(BitcoinTestFramework): # TODO: An old node would see these txs without witnesses and be able to mine them - print("Verify unsigned bare witness txs in versionbits-setting blocks are valid before the fork") + self.log.info("Verify unsigned bare witness txs in versionbits-setting blocks are valid before the fork") self.success_mine(self.nodes[2], wit_ids[NODE_2][WIT_V0][1], False) #block 428 self.success_mine(self.nodes[2], wit_ids[NODE_2][WIT_V1][1], False) #block 429 - print("Verify unsigned p2sh witness txs without a redeem script are invalid") + self.log.info("Verify unsigned p2sh witness txs without a redeem script are invalid") self.fail_accept(self.nodes[2], p2sh_ids[NODE_2][WIT_V0][1], False) self.fail_accept(self.nodes[2], p2sh_ids[NODE_2][WIT_V1][1], False) - print("Verify unsigned p2sh witness txs with a redeem script in versionbits-settings blocks are valid before the fork") + self.log.info("Verify unsigned p2sh witness txs with a redeem script in versionbits-settings blocks are valid before the fork") self.success_mine(self.nodes[2], p2sh_ids[NODE_2][WIT_V0][1], False, addlength(witness_script(0, self.pubkey[2]))) #block 430 self.success_mine(self.nodes[2], p2sh_ids[NODE_2][WIT_V1][1], False, addlength(witness_script(1, self.pubkey[2]))) #block 431 - print("Verify previous witness txs skipped for mining can now be mined") + self.log.info("Verify previous witness txs skipped for mining can now be mined") assert_equal(len(self.nodes[2].getrawmempool()), 4) block = self.nodes[2].generate(1) #block 432 (first block with new rules; 432 = 144 * 3) sync_blocks(self.nodes) @@ -216,7 +216,7 @@ class SegWitTest(BitcoinTestFramework): segwit_tx_list = self.nodes[2].getblock(block[0])["tx"] assert_equal(len(segwit_tx_list), 5) - print("Verify block and transaction serialization rpcs return differing serializations depending on rpc serialization flag") + self.log.info("Verify block and transaction serialization rpcs return differing serializations depending on rpc serialization flag") assert(self.nodes[2].getblock(block[0], False) != self.nodes[0].getblock(block[0], False)) assert(self.nodes[1].getblock(block[0], False) == self.nodes[2].getblock(block[0], False)) for i in range(len(segwit_tx_list)): @@ -227,19 +227,19 @@ class SegWitTest(BitcoinTestFramework): assert(self.nodes[1].getrawtransaction(segwit_tx_list[i]) == self.nodes[2].gettransaction(segwit_tx_list[i])["hex"]) assert(self.nodes[0].getrawtransaction(segwit_tx_list[i]) == bytes_to_hex_str(tx.serialize_without_witness())) - print("Verify witness txs without witness data are invalid after the fork") + self.log.info("Verify witness txs without witness data are invalid after the fork") self.fail_mine(self.nodes[2], wit_ids[NODE_2][WIT_V0][2], False) self.fail_mine(self.nodes[2], wit_ids[NODE_2][WIT_V1][2], False) self.fail_mine(self.nodes[2], p2sh_ids[NODE_2][WIT_V0][2], False, addlength(witness_script(0, self.pubkey[2]))) self.fail_mine(self.nodes[2], p2sh_ids[NODE_2][WIT_V1][2], False, addlength(witness_script(1, self.pubkey[2]))) - print("Verify default node can now use witness txs") + self.log.info("Verify default node can now use witness txs") self.success_mine(self.nodes[0], wit_ids[NODE_0][WIT_V0][0], True) #block 432 self.success_mine(self.nodes[0], wit_ids[NODE_0][WIT_V1][0], True) #block 433 self.success_mine(self.nodes[0], p2sh_ids[NODE_0][WIT_V0][0], True) #block 434 self.success_mine(self.nodes[0], p2sh_ids[NODE_0][WIT_V1][0], True) #block 435 - print("Verify sigops are counted in GBT with BIP141 rules after the fork") + self.log.info("Verify sigops are counted in GBT with BIP141 rules after the fork") txid = self.nodes[0].sendtoaddress(self.nodes[0].getnewaddress(), 1) tmpl = self.nodes[0].getblocktemplate({'rules':['segwit']}) assert(tmpl['sizelimit'] >= 3999577) # actual maximum size is lower due to minimum mandatory non-witness data @@ -248,11 +248,11 @@ class SegWitTest(BitcoinTestFramework): assert(tmpl['transactions'][0]['txid'] == txid) assert(tmpl['transactions'][0]['sigops'] == 8) - print("Non-segwit miners are not able to use GBT response after activation.") + self.log.info("Non-segwit miners are not able to use GBT response after activation.") send_to_witness(1, self.nodes[0], find_unspent(self.nodes[0], 50), self.pubkey[0], False, Decimal("49.998")) assert_raises_jsonrpc(-8, "Support for 'segwit' rule requires explicit client support", self.nodes[0].getblocktemplate, {}) - print("Verify behaviour of importaddress, addwitnessaddress and listunspent") + self.log.info("Verify behaviour of importaddress, addwitnessaddress and listunspent") # Some public keys to be used later pubkeys = [ diff --git a/qa/rpc-tests/sendheaders.py b/qa/rpc-tests/sendheaders.py index 16ca4a491..de7f5e084 100755 --- a/qa/rpc-tests/sendheaders.py +++ b/qa/rpc-tests/sendheaders.py @@ -229,7 +229,7 @@ class SendHeadersTest(BitcoinTestFramework): def setup_network(self): self.nodes = [] - self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, [["-debug", "-logtimemicros=1"]]*2) + self.nodes = start_nodes(self.num_nodes, self.options.tmpdir) connect_nodes(self.nodes[0], 1) # mine count blocks and return the new tip @@ -283,7 +283,7 @@ class SendHeadersTest(BitcoinTestFramework): # PART 1 # 1. Mine a block; expect inv announcements each time - print("Part 1: headers don't start before sendheaders message...") + self.log.info("Part 1: headers don't start before sendheaders message...") for i in range(4): old_tip = tip tip = self.mine_blocks(1) @@ -314,8 +314,8 @@ class SendHeadersTest(BitcoinTestFramework): inv_node.clear_last_announcement() test_node.clear_last_announcement() - print("Part 1: success!") - print("Part 2: announce blocks with headers after sendheaders message...") + self.log.info("Part 1: success!") + self.log.info("Part 2: announce blocks with headers after sendheaders message...") # PART 2 # 2. Send a sendheaders message and test that headers announcements # commence and keep working. @@ -376,9 +376,9 @@ class SendHeadersTest(BitcoinTestFramework): height += 1 block_time += 1 - print("Part 2: success!") + self.log.info("Part 2: success!") - print("Part 3: headers announcements can stop after large reorg, and resume after headers/inv from peer...") + self.log.info("Part 3: headers announcements can stop after large reorg, and resume after headers/inv from peer...") # PART 3. Headers announcements can stop after large reorg, and resume after # getheaders or inv from peer. @@ -440,9 +440,9 @@ class SendHeadersTest(BitcoinTestFramework): assert_equal(inv_node.check_last_announcement(inv=[tip]), True) assert_equal(test_node.check_last_announcement(headers=[tip]), True) - print("Part 3: success!") + self.log.info("Part 3: success!") - print("Part 4: Testing direct fetch behavior...") + self.log.info("Part 4: Testing direct fetch behavior...") tip = self.mine_blocks(1) height = self.nodes[0].getblockcount() + 1 last_time = self.nodes[0].getblock(self.nodes[0].getbestblockhash())['time'] @@ -523,12 +523,12 @@ class SendHeadersTest(BitcoinTestFramework): with mininode_lock: assert_equal(test_node.last_getdata, None) - print("Part 4: success!") + self.log.info("Part 4: success!") # Now deliver all those blocks we announced. [ test_node.send_message(msg_block(x)) for x in blocks ] - print("Part 5: Testing handling of unconnecting headers") + self.log.info("Part 5: Testing handling of unconnecting headers") # First we test that receipt of an unconnecting header doesn't prevent # chain sync. for i in range(10): @@ -595,7 +595,7 @@ class SendHeadersTest(BitcoinTestFramework): with mininode_lock: self.last_getheaders = True - print("Part 5: success!") + self.log.info("Part 5: success!") # Finally, check that the inv node never received a getdata request, # throughout the test diff --git a/qa/rpc-tests/smartfees.py b/qa/rpc-tests/smartfees.py index 9ce5b8e86..f7d692083 100755 --- a/qa/rpc-tests/smartfees.py +++ b/qa/rpc-tests/smartfees.py @@ -99,7 +99,7 @@ def check_estimates(node, fees_seen, max_invalid, print_estimates = True): """ all_estimates = [ node.estimatefee(i) for i in range(1,26) ] if print_estimates: - print([str(all_estimates[e-1]) for e in [1,2,3,6,15,25]]) + self.log.info([str(all_estimates[e-1]) for e in [1,2,3,6,15,25]]) delta = 1.0e-6 # account for rounding error last_e = max(fees_seen) for e in [x for x in all_estimates if x >= 0]: @@ -159,8 +159,8 @@ class EstimateFeeTest(BitcoinTestFramework): self.nodes.append(start_node(0, self.options.tmpdir, ["-maxorphantx=1000", "-whitelist=127.0.0.1"])) - print("This test is time consuming, please be patient") - print("Splitting inputs so we can generate tx's") + self.log.info("This test is time consuming, please be patient") + self.log.info("Splitting inputs so we can generate tx's") self.txouts = [] self.txouts2 = [] # Split a coinbase into two transaction puzzle outputs @@ -185,7 +185,7 @@ class EstimateFeeTest(BitcoinTestFramework): while (len(self.nodes[0].getrawmempool()) > 0): self.nodes[0].generate(1) reps += 1 - print("Finished splitting") + self.log.info("Finished splitting") # Now we can connect the other nodes, didn't want to connect them earlier # so the estimates would not be affected by the splitting transactions @@ -193,8 +193,7 @@ class EstimateFeeTest(BitcoinTestFramework): # NOTE: the CreateNewBlock code starts counting block size at 1,000 bytes, # (17k is room enough for 110 or so transactions) self.nodes.append(start_node(1, self.options.tmpdir, - ["-blockmaxsize=17000", - "-maxorphantx=1000", "-debug=estimatefee"])) + ["-blockmaxsize=17000", "-maxorphantx=1000"])) connect_nodes(self.nodes[1], 0) # Node2 is a stingy miner, that @@ -238,15 +237,15 @@ class EstimateFeeTest(BitcoinTestFramework): self.fees_per_kb = [] self.memutxo = [] self.confutxo = self.txouts # Start with the set of confirmed txouts after splitting - print("Will output estimates for 1/2/3/6/15/25 blocks") + self.log.info("Will output estimates for 1/2/3/6/15/25 blocks") for i in range(2): - print("Creating transactions and mining them with a block size that can't keep up") + self.log.info("Creating transactions and mining them with a block size that can't keep up") # Create transactions and mine 10 small blocks with node 2, but create txs faster than we can mine self.transact_and_mine(10, self.nodes[2]) check_estimates(self.nodes[1], self.fees_per_kb, 14) - print("Creating transactions and mining them at a block size that is just big enough") + self.log.info("Creating transactions and mining them at a block size that is just big enough") # Generate transactions while mining 10 more blocks, this time with node1 # which mines blocks with capacity just above the rate that transactions are being created self.transact_and_mine(10, self.nodes[1]) @@ -257,7 +256,7 @@ class EstimateFeeTest(BitcoinTestFramework): self.nodes[1].generate(1) sync_blocks(self.nodes[0:3], wait=.1) - print("Final estimates after emptying mempools") + self.log.info("Final estimates after emptying mempools") check_estimates(self.nodes[1], self.fees_per_kb, 2) if __name__ == '__main__': diff --git a/qa/rpc-tests/test_framework/blockstore.py b/qa/rpc-tests/test_framework/blockstore.py index 5280d18cd..4cfd682bb 100644 --- a/qa/rpc-tests/test_framework/blockstore.py +++ b/qa/rpc-tests/test_framework/blockstore.py @@ -8,6 +8,8 @@ from .mininode import * from io import BytesIO import dbm.dumb as dbmd +logger = logging.getLogger("TestFramework.blockstore") + class BlockStore(object): """BlockStore helper class. @@ -86,7 +88,7 @@ class BlockStore(object): try: self.blockDB[repr(block.sha256)] = bytes(block.serialize()) except TypeError as e: - print("Unexpected error: ", sys.exc_info()[0], e.args) + logger.exception("Unexpected error") self.currentBlock = block.sha256 self.headers_map[block.sha256] = CBlockHeader(block) @@ -156,7 +158,7 @@ class TxStore(object): try: self.txDB[repr(tx.sha256)] = bytes(tx.serialize()) except TypeError as e: - print("Unexpected error: ", sys.exc_info()[0], e.args) + logger.exception("Unexpected error") def get_transactions(self, inv): responses = [] diff --git a/qa/rpc-tests/test_framework/comptool.py b/qa/rpc-tests/test_framework/comptool.py index b617895ca..70d1d700e 100755 --- a/qa/rpc-tests/test_framework/comptool.py +++ b/qa/rpc-tests/test_framework/comptool.py @@ -21,6 +21,10 @@ from .mininode import * from .blockstore import BlockStore, TxStore from .util import p2p_port +import logging + +logger=logging.getLogger("TestFramework.comptool") + global mininode_lock class RejectResult(object): @@ -209,7 +213,6 @@ class TestManager(object): # --> error if not requested if not wait_until(blocks_requested, attempts=20*num_blocks): - # print [ c.cb.block_request_map for c in self.connections ] raise AssertionError("Not all nodes requested block") # Send getheaders message @@ -231,7 +234,6 @@ class TestManager(object): # --> error if not requested if not wait_until(transaction_requested, attempts=20*num_events): - # print [ c.cb.tx_request_map for c in self.connections ] raise AssertionError("Not all nodes requested transaction") # Get the mempool @@ -258,13 +260,12 @@ class TestManager(object): if c.cb.bestblockhash == blockhash: return False if blockhash not in c.cb.block_reject_map: - print('Block not in reject map: %064x' % (blockhash)) + logger.error('Block not in reject map: %064x' % (blockhash)) return False if not outcome.match(c.cb.block_reject_map[blockhash]): - print('Block rejected with %s instead of expected %s: %064x' % (c.cb.block_reject_map[blockhash], outcome, blockhash)) + logger.error('Block rejected with %s instead of expected %s: %064x' % (c.cb.block_reject_map[blockhash], outcome, blockhash)) return False elif ((c.cb.bestblockhash == blockhash) != outcome): - # print c.cb.bestblockhash, blockhash, outcome return False return True @@ -280,19 +281,17 @@ class TestManager(object): if outcome is None: # Make sure the mempools agree with each other if c.cb.lastInv != self.connections[0].cb.lastInv: - # print c.rpc.getrawmempool() return False elif isinstance(outcome, RejectResult): # Check that tx was rejected w/ code if txhash in c.cb.lastInv: return False if txhash not in c.cb.tx_reject_map: - print('Tx not in reject map: %064x' % (txhash)) + logger.error('Tx not in reject map: %064x' % (txhash)) return False if not outcome.match(c.cb.tx_reject_map[txhash]): - print('Tx rejected with %s instead of expected %s: %064x' % (c.cb.tx_reject_map[txhash], outcome, txhash)) + logger.error('Tx rejected with %s instead of expected %s: %064x' % (c.cb.tx_reject_map[txhash], outcome, txhash)) return False elif ((txhash in c.cb.lastInv) != outcome): - # print c.rpc.getrawmempool(), c.cb.lastInv return False return True @@ -402,7 +401,7 @@ class TestManager(object): if (not self.check_mempool(tx.sha256, tx_outcome)): raise AssertionError("Mempool test failed at test %d" % test_number) - print("Test %d: PASS" % test_number, [ c.rpc.getblockcount() for c in self.connections ]) + logger.info("Test %d: PASS" % test_number) test_number += 1 [ c.disconnect_node() for c in self.connections ] diff --git a/qa/rpc-tests/test_framework/mininode.py b/qa/rpc-tests/test_framework/mininode.py index b2292f647..aace17a04 100755 --- a/qa/rpc-tests/test_framework/mininode.py +++ b/qa/rpc-tests/test_framework/mininode.py @@ -51,6 +51,8 @@ NODE_GETUTXO = (1 << 1) NODE_BLOOM = (1 << 2) NODE_WITNESS = (1 << 3) +logger = logging.getLogger("TestFramework.mininode") + # Keep our own socket map for asyncore, so that we can track disconnects # ourselves (to workaround an issue with closing an asyncore socket when # using select) @@ -1502,8 +1504,7 @@ class NodeConnCB(object): try: getattr(self, 'on_' + message.command.decode('ascii'))(conn, message) except: - print("ERROR delivering %s (%s)" % (repr(message), - sys.exc_info()[0])) + logger.exception("ERROR delivering %s" % repr(message)) def on_version(self, conn, message): if message.nVersion >= 209: @@ -1615,7 +1616,6 @@ class NodeConn(asyncore.dispatcher): def __init__(self, dstaddr, dstport, rpc, callback, net="regtest", services=NODE_NETWORK, send_version=True): asyncore.dispatcher.__init__(self, map=mininode_socket_map) - self.log = logging.getLogger("NodeConn(%s:%d)" % (dstaddr, dstport)) self.dstaddr = dstaddr self.dstport = dstport self.create_socket(socket.AF_INET, socket.SOCK_STREAM) @@ -1640,8 +1640,7 @@ class NodeConn(asyncore.dispatcher): vt.addrFrom.port = 0 self.send_message(vt, True) - print('MiniNode: Connecting to Bitcoin Node IP # ' + dstaddr + ':' \ - + str(dstport)) + logger.info('Connecting to Bitcoin Node: %s:%d' % (self.dstaddr, self.dstport)) try: self.connect((dstaddr, dstport)) @@ -1649,18 +1648,14 @@ class NodeConn(asyncore.dispatcher): self.handle_close() self.rpc = rpc - def show_debug_msg(self, msg): - self.log.debug(msg) - def handle_connect(self): if self.state != "connected": - self.show_debug_msg("MiniNode: Connected & Listening: \n") + logger.debug("Connected & Listening: %s:%d" % (self.dstaddr, self.dstport)) self.state = "connected" self.cb.on_open(self) def handle_close(self): - self.show_debug_msg("MiniNode: Closing Connection to %s:%d... " - % (self.dstaddr, self.dstport)) + logger.debug("Closing connection to: %s:%d" % (self.dstaddr, self.dstport)) self.state = "closed" self.recvbuf = b"" self.sendbuf = b"" @@ -1742,17 +1737,14 @@ class NodeConn(asyncore.dispatcher): t.deserialize(f) self.got_message(t) else: - self.show_debug_msg("Unknown command: '" + command + "' " + - repr(msg)) + logger.warning("Received unknown command from %s:%d: '%s' %s" % (self.dstaddr, self.dstport, command, repr(msg))) except Exception as e: - print('got_data:', repr(e)) - # import traceback - # traceback.print_tb(sys.exc_info()[2]) + logger.exception('got_data:', repr(e)) def send_message(self, message, pushbuf=False): if self.state != "connected" and not pushbuf: raise IOError('Not connected, no pushbuf') - self.show_debug_msg("Send %s" % repr(message)) + logger.debug("Send message to %s:%d: %s" % (self.dstaddr, self.dstport, repr(message))) command = message.command data = message.serialize() tmsg = self.MAGIC_BYTES[self.network] @@ -1774,7 +1766,7 @@ class NodeConn(asyncore.dispatcher): self.messagemap[b'ping'] = msg_ping_prebip31 if self.last_sent + 30 * 60 < time.time(): self.send_message(self.messagemap[b'ping']()) - self.show_debug_msg("Recv %s" % repr(message)) + logger.debug("Received message from %s:%d: %s" % (self.dstaddr, self.dstport, repr(message))) self.cb.deliver(self, message) def disconnect_node(self): diff --git a/qa/rpc-tests/test_framework/test_framework.py b/qa/rpc-tests/test_framework/test_framework.py index c5e9c6a65..d7072fa78 100755 --- a/qa/rpc-tests/test_framework/test_framework.py +++ b/qa/rpc-tests/test_framework/test_framework.py @@ -42,7 +42,7 @@ class BitcoinTestFramework(object): pass def setup_chain(self): - print("Initializing test directory "+self.options.tmpdir) + self.log.info("Initializing test directory "+self.options.tmpdir) if self.setup_clean_chain: initialize_chain_clean(self.options.tmpdir, self.num_nodes) else: @@ -112,6 +112,8 @@ class BitcoinTestFramework(object): help="Directory for caching pregenerated datadirs") parser.add_option("--tmpdir", dest="tmpdir", default=tempfile.mkdtemp(prefix="test"), help="Root directory for datadirs") + parser.add_option("-l", "--loglevel", dest="loglevel", default="INFO", + help="log events at this level and higher to the console. Can be set to DEBUG, INFO, WARNING, ERROR or CRITICAL. Passing --loglevel DEBUG will output all logs to console. Note that logs at all levels are always written to the test_framework.log file in the temporary test directory.") parser.add_option("--tracerpc", dest="trace_rpc", default=False, action="store_true", help="Print out all RPC calls as they are made") parser.add_option("--portseed", dest="port_seed", default=os.getpid(), type='int', @@ -124,9 +126,6 @@ class BitcoinTestFramework(object): # backup dir variable for removal at cleanup self.options.root, self.options.tmpdir = self.options.tmpdir, self.options.tmpdir + '/' + str(self.options.port_seed) - if self.options.trace_rpc: - logging.basicConfig(level=logging.DEBUG, stream=sys.stdout) - if self.options.coveragedir: enable_coverage(self.options.coveragedir) @@ -136,41 +135,41 @@ class BitcoinTestFramework(object): check_json_precision() + # Set up temp directory and start logging + os.makedirs(self.options.tmpdir, exist_ok=False) + self._start_logging() + success = False + try: - os.makedirs(self.options.tmpdir, exist_ok=False) self.setup_chain() self.setup_network() self.run_test() success = True except JSONRPCException as e: - print("JSONRPC error: "+e.error['message']) - traceback.print_tb(sys.exc_info()[2]) + self.log.exception("JSONRPC error") except AssertionError as e: - print("Assertion failed: " + str(e)) - traceback.print_tb(sys.exc_info()[2]) + self.log.exception("Assertion failed") except KeyError as e: - print("key not found: "+ str(e)) - traceback.print_tb(sys.exc_info()[2]) + self.log.exception("Key error") except Exception as e: - print("Unexpected exception caught during testing: " + repr(e)) - traceback.print_tb(sys.exc_info()[2]) + self.log.exception("Unexpected exception caught during testing") except KeyboardInterrupt as e: - print("Exiting after " + repr(e)) + self.log.warning("Exiting after keyboard interrupt") if not self.options.noshutdown: - print("Stopping nodes") + self.log.info("Stopping nodes") stop_nodes(self.nodes) else: - print("Note: bitcoinds were not stopped and may still be running") + self.log.info("Note: bitcoinds were not stopped and may still be running") if not self.options.nocleanup and not self.options.noshutdown and success: - print("Cleaning up") + self.log.info("Cleaning up") shutil.rmtree(self.options.tmpdir) if not os.listdir(self.options.root): os.rmdir(self.options.root) else: - print("Not cleaning up dir %s" % self.options.tmpdir) + self.log.warning("Not cleaning up dir %s" % self.options.tmpdir) if os.getenv("PYTHON_DEBUG", ""): # Dump the end of the debug logs, to aid in debugging rare # travis failures. @@ -182,12 +181,39 @@ class BitcoinTestFramework(object): from collections import deque print("".join(deque(open(f), MAX_LINES_TO_PRINT))) if success: - print("Tests successful") + self.log.info("Tests successful") sys.exit(0) else: - print("Failed") + self.log.error("Test failed. Test logging available at %s/test_framework.log", self.options.tmpdir) + logging.shutdown() sys.exit(1) + def _start_logging(self): + # Add logger and logging handlers + self.log = logging.getLogger('TestFramework') + self.log.setLevel(logging.DEBUG) + # Create file handler to log all messages + fh = logging.FileHandler(self.options.tmpdir + '/test_framework.log') + fh.setLevel(logging.DEBUG) + # Create console handler to log messages to stderr. By default this logs only error messages, but can be configured with --loglevel. + ch = logging.StreamHandler(sys.stdout) + # User can provide log level as a number or string (eg DEBUG). loglevel was caught as a string, so try to convert it to an int + ll = int(self.options.loglevel) if self.options.loglevel.isdigit() else self.options.loglevel.upper() + ch.setLevel(ll) + # Format logs the same as bitcoind's debug.log with microprecision (so log files can be concatenated and sorted) + formatter = logging.Formatter(fmt = '%(asctime)s.%(msecs)03d000 %(name)s (%(levelname)s): %(message)s', datefmt='%Y-%m-%d %H:%M:%S') + fh.setFormatter(formatter) + ch.setFormatter(formatter) + # add the handlers to the logger + self.log.addHandler(fh) + self.log.addHandler(ch) + + if self.options.trace_rpc: + rpc_logger = logging.getLogger("BitcoinRPC") + rpc_logger.setLevel(logging.DEBUG) + rpc_handler = logging.StreamHandler(sys.stdout) + rpc_handler.setLevel(logging.DEBUG) + rpc_logger.addHandler(rpc_handler) # Test framework for doing p2p comparison testing, which sets up some bitcoind # binaries: @@ -213,6 +239,6 @@ class ComparisonTestFramework(BitcoinTestFramework): def setup_network(self): self.nodes = start_nodes( self.num_nodes, self.options.tmpdir, - extra_args=[['-debug', '-whitelist=127.0.0.1']] * self.num_nodes, + extra_args=[['-whitelist=127.0.0.1']] * self.num_nodes, binary=[self.options.testbinary] + [self.options.refbinary]*(self.num_nodes-1)) diff --git a/qa/rpc-tests/test_framework/util.py b/qa/rpc-tests/test_framework/util.py index ba56fddd7..23ac32451 100644 --- a/qa/rpc-tests/test_framework/util.py +++ b/qa/rpc-tests/test_framework/util.py @@ -19,12 +19,15 @@ import tempfile import time import re import errno +import logging from . import coverage from .authproxy import AuthServiceProxy, JSONRPCException COVERAGE_DIR = None +logger = logging.getLogger("TestFramework.utils") + # The maximum number of nodes a single test can spawn MAX_NODES = 8 # Don't assign rpc or p2p ports lower than this @@ -237,6 +240,7 @@ def initialize_chain(test_dir, num_nodes, cachedir): break if create_cache: + logger.debug("Creating data directories from cached datadir") #find and delete old cache directories if any exist for i in range(MAX_NODES): @@ -250,11 +254,9 @@ def initialize_chain(test_dir, num_nodes, cachedir): if i > 0: args.append("-connect=127.0.0.1:"+str(p2p_port(0))) bitcoind_processes[i] = subprocess.Popen(args) - if os.getenv("PYTHON_DEBUG", ""): - print("initialize_chain: bitcoind started, waiting for RPC to come up") + logger.debug("initialize_chain: bitcoind started, waiting for RPC to come up") wait_for_bitcoind_start(bitcoind_processes[i], rpc_url(i), i) - if os.getenv("PYTHON_DEBUG", ""): - print("initialize_chain: RPC successfully started") + logger.debug("initialize_chain: RPC successfully started") rpcs = [] for i in range(MAX_NODES): @@ -313,15 +315,13 @@ def start_node(i, dirname, extra_args=None, rpchost=None, timewait=None, binary= datadir = os.path.join(dirname, "node"+str(i)) if binary is None: binary = os.getenv("BITCOIND", "bitcoind") - args = [ binary, "-datadir="+datadir, "-server", "-keypool=1", "-discover=0", "-rest", "-mocktime="+str(get_mocktime()) ] + args = [ binary, "-datadir="+datadir, "-server", "-keypool=1", "-discover=0", "-rest", "-logtimemicros", "-debug", "-mocktime="+str(get_mocktime()) ] if extra_args is not None: args.extend(extra_args) bitcoind_processes[i] = subprocess.Popen(args, stderr=stderr) - if os.getenv("PYTHON_DEBUG", ""): - print("start_node: bitcoind started, waiting for RPC to come up") + logger.debug("initialize_chain: bitcoind started, waiting for RPC to come up") url = rpc_url(i, rpchost) wait_for_bitcoind_start(bitcoind_processes[i], url, i) - if os.getenv("PYTHON_DEBUG", ""): - print("start_node: RPC successfully started") + logger.debug("initialize_chain: RPC successfully started") proxy = get_rpc_proxy(url, i, timeout=timewait) if COVERAGE_DIR: @@ -367,10 +367,11 @@ def log_filename(dirname, n_node, logname): return os.path.join(dirname, "node"+str(n_node), "regtest", logname) def stop_node(node, i): + logger.debug("Stopping node %d" % i) try: node.stop() except http.client.CannotSendRequest as e: - print("WARN: Unable to stop node: " + repr(e)) + logger.exception("Unable to stop node") return_code = bitcoind_processes[i].wait(timeout=BITCOIND_PROC_WAIT_TIMEOUT) assert_equal(return_code, 0) del bitcoind_processes[i] diff --git a/qa/rpc-tests/wallet-hd.py b/qa/rpc-tests/wallet-hd.py index 1dcfe5300..c40662dc3 100755 --- a/qa/rpc-tests/wallet-hd.py +++ b/qa/rpc-tests/wallet-hd.py @@ -68,7 +68,7 @@ class WalletHDTest(BitcoinTestFramework): self.sync_all() assert_equal(self.nodes[1].getbalance(), num_hd_adds + 1) - print("Restore backup ...") + self.log.info("Restore backup ...") self.stop_node(1) os.remove(self.options.tmpdir + "/node1/regtest/wallet.dat") shutil.copyfile(tmpdir + "/hd.bak", tmpdir + "/node1/regtest/wallet.dat") diff --git a/qa/rpc-tests/wallet.py b/qa/rpc-tests/wallet.py index ddeac657e..00fe37563 100755 --- a/qa/rpc-tests/wallet.py +++ b/qa/rpc-tests/wallet.py @@ -35,7 +35,7 @@ class WalletTest (BitcoinTestFramework): assert_equal(len(self.nodes[1].listunspent()), 0) assert_equal(len(self.nodes[2].listunspent()), 0) - print("Mining blocks...") + self.log.info("Mining blocks...") self.nodes[0].generate(1) @@ -332,7 +332,7 @@ class WalletTest (BitcoinTestFramework): ] chainlimit = 6 for m in maintenance: - print("check " + m) + self.log.info("check " + m) stop_nodes(self.nodes) # set lower ancestor limit for later self.nodes = start_nodes(3, self.options.tmpdir, [[m, "-limitancestorcount="+str(chainlimit)]] * 3) diff --git a/qa/rpc-tests/walletbackup.py b/qa/rpc-tests/walletbackup.py index ea249096c..af1718572 100755 --- a/qa/rpc-tests/walletbackup.py +++ b/qa/rpc-tests/walletbackup.py @@ -34,8 +34,6 @@ and confirm again balances are correct. from test_framework.test_framework import BitcoinTestFramework from test_framework.util import * from random import randint -import logging -logging.basicConfig(format='%(levelname)s: %(message)s', level=logging.INFO, stream=sys.stdout) class WalletBackupTest(BitcoinTestFramework): @@ -100,7 +98,7 @@ class WalletBackupTest(BitcoinTestFramework): os.remove(self.options.tmpdir + "/node2/regtest/wallet.dat") def run_test(self): - logging.info("Generating initial blockchain") + self.log.info("Generating initial blockchain") self.nodes[0].generate(1) sync_blocks(self.nodes) self.nodes[1].generate(1) @@ -115,12 +113,12 @@ class WalletBackupTest(BitcoinTestFramework): assert_equal(self.nodes[2].getbalance(), 50) assert_equal(self.nodes[3].getbalance(), 0) - logging.info("Creating transactions") + self.log.info("Creating transactions") # Five rounds of sending each other transactions. for i in range(5): self.do_one_round() - logging.info("Backing up") + self.log.info("Backing up") tmpdir = self.options.tmpdir self.nodes[0].backupwallet(tmpdir + "/node0/wallet.bak") self.nodes[0].dumpwallet(tmpdir + "/node0/wallet.dump") @@ -129,7 +127,7 @@ class WalletBackupTest(BitcoinTestFramework): self.nodes[2].backupwallet(tmpdir + "/node2/wallet.bak") self.nodes[2].dumpwallet(tmpdir + "/node2/wallet.dump") - logging.info("More transactions") + self.log.info("More transactions") for i in range(5): self.do_one_round() @@ -150,7 +148,7 @@ class WalletBackupTest(BitcoinTestFramework): ## # Test restoring spender wallets from backups ## - logging.info("Restoring using wallet.dat") + self.log.info("Restoring using wallet.dat") self.stop_three() self.erase_three() @@ -163,7 +161,7 @@ class WalletBackupTest(BitcoinTestFramework): shutil.copyfile(tmpdir + "/node1/wallet.bak", tmpdir + "/node1/regtest/wallet.dat") shutil.copyfile(tmpdir + "/node2/wallet.bak", tmpdir + "/node2/regtest/wallet.dat") - logging.info("Re-starting nodes") + self.log.info("Re-starting nodes") self.start_three() sync_blocks(self.nodes) @@ -171,7 +169,7 @@ class WalletBackupTest(BitcoinTestFramework): assert_equal(self.nodes[1].getbalance(), balance1) assert_equal(self.nodes[2].getbalance(), balance2) - logging.info("Restoring using dumped wallet") + self.log.info("Restoring using dumped wallet") self.stop_three() self.erase_three() diff --git a/qa/rpc-tests/zapwallettxes.py b/qa/rpc-tests/zapwallettxes.py index 9597d05f3..ce446e44a 100755 --- a/qa/rpc-tests/zapwallettxes.py +++ b/qa/rpc-tests/zapwallettxes.py @@ -32,7 +32,7 @@ class ZapWalletTXesTest (BitcoinTestFramework): self.sync_all() def run_test (self): - print("Mining blocks...") + self.log.info("Mining blocks...") self.nodes[0].generate(1) self.sync_all() self.nodes[1].generate(101) diff --git a/qa/rpc-tests/zmq_test.py b/qa/rpc-tests/zmq_test.py index 1e2f06bd5..e6f18b0b9 100755 --- a/qa/rpc-tests/zmq_test.py +++ b/qa/rpc-tests/zmq_test.py @@ -36,7 +36,7 @@ class ZMQTest (BitcoinTestFramework): genhashes = self.nodes[0].generate(1) self.sync_all() - print("listen...") + self.log.info("listen...") msg = self.zmqSubSocket.recv_multipart() topic = msg[0] assert_equal(topic, b"hashtx") |