Merge #9768: [qa] Add logging to test_framework.py

64c0800 Use logging in individual tests (John Newbery)
38ad281 Use logging in test_framework/comptool.py (John Newbery)
ff19073 Use logging in test_framework/blockstore.py (John Newbery)
2a9c7c7 Use logging in test_framework/util.py (John Newbery)
b0dec4a Remove manual debug settings in qa tests. (John Newbery)
af1363c Always enable debug log and microsecond logging for test nodes. (John Newbery)
6d0e325 Use logging in mininode.py (John Newbery)
553a976 Add logging to p2p-segwit.py (John Newbery)
0e6d23d Add logging to test_framework.py (John Newbery)

Tree-SHA512: 42ee2acbf444ec32d796f930f9f6e272da03c75e93d974a126d4ea9b2dbaa77cc57ab5e63ce3fd33d609049d884eb8d9f65272c08922d10f8db69d4a60ad05a3

1 files changed, 32 insertions, 33 deletions

diff --git a/qa/rpc-tests/p2p-segwit.py b/qa/rpc-tests/p2p-segwit.py
index 470a5398b6..0f844883b1 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)