test: add rpc_fundrawtransaction logging

Summary:
> test/functional/rpc_fundrawtransaction.py is fairly long to run and has no logging, so it can appear to be stalled.
>
> This commit adds info logging at each test to provide feedback on the test run.

This is a backport of Core [[bitcoin/bitcoin#17342 | PR17342]] [1/2]
bitcoin/bitcoin@94fcc08

Test Plan:
`ninja && test/functional/test_runner.py rpc_fundr*`

While the test is running, in another terminal:
`tail -f test/tmp/test_runner_₿₵_🏃_20201102_112740/rpc_fundrawtransaction_475/test_framework.log`

Reviewers: O1 Bitcoin ABC, #bitcoin_abc, jasonbcox

Reviewed By: O1 Bitcoin ABC, #bitcoin_abc, jasonbcox

Differential Revision: https://reviews.bitcoinabc.org/D8234

Author: jonatack

test/functional/rpc_fundrawtransaction.py

@@ -44,6 +44,7 @@ def setup_network(self):
         connect_nodes(self.nodes[0], self.nodes[3])
 
     def run_test(self):
+        self.log.info("Connect nodes, set fees, generate blocks, and sync")
         self.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
@@ -95,6 +96,7 @@ def run_test(self):
     def test_change_position(self):
         # ensure that setting changePosition in fundraw with an exact match is
         # handled properly
+        self.log.info("Test fundrawtxn changePosition option")
         rawmatch = self.nodes[2].createrawtransaction(
             [], {self.nodes[2].getnewaddress(): 50})
         rawmatch = self.nodes[2].fundrawtransaction(
@@ -130,6 +132,7 @@ def test_simple(self):
         #
         # simple test #
         #
+        self.log.info("Test fundrawtxn")
         inputs = []
         outputs = {self.nodes[0].getnewaddress(): 1.0}
         rawTx = self.nodes[2].createrawtransaction(inputs, outputs)
@@ -143,6 +146,7 @@ def test_simple_two_coins(self):
         #
         # simple test with two coins #
         #
+        self.log.info("Test fundrawtxn with 2 coins")
         inputs = []
         outputs = {self.nodes[0].getnewaddress(): 2.2}
         rawTx = self.nodes[2].createrawtransaction(inputs, outputs)
@@ -158,6 +162,7 @@ def test_simple_two_outputs(self):
         #
         # simple test with two outputs #
         #
+        self.log.info("Test fundrawtxn with 2 outputs")
         inputs = []
         outputs = {
             self.nodes[0].getnewaddress(): 2.6, self.nodes[1].getnewaddress(): 2.5}
@@ -177,6 +182,7 @@ def test_change(self):
         #
         # test a fundrawtransaction with a VIN greater than the required amount #
         #
+        self.log.info("Test fundrawtxn with a vin > required amount")
         utx = get_unspent(self.nodes[2].listunspent(), 5)
 
         inputs = [{'txid': utx['txid'], 'vout': utx['vout']}]
@@ -201,6 +207,7 @@ def test_no_change(self):
         #
         # test a fundrawtransaction with which will not get a change output #
         #
+        self.log.info("Test fundrawtxn not having a change output")
         utx = get_unspent(self.nodes[2].listunspent(), 5)
 
         inputs = [{'txid': utx['txid'], 'vout': utx['vout']}]
@@ -227,6 +234,7 @@ def test_invalid_option(self):
         #
         # test a fundrawtransaction with an invalid option #
         #
+        self.log.info("Test fundrawtxn with an invalid option")
         utx = get_unspent(self.nodes[2].listunspent(), 5)
 
         inputs = [{'txid': utx['txid'], 'vout': utx['vout']}]
@@ -247,6 +255,7 @@ def test_invalid_change_address(self):
         #
         # test a fundrawtransaction with an invalid change address #
         #
+        self.log.info("Test fundrawtxn with an invalid change address")
         utx = get_unspent(self.nodes[2].listunspent(), 5)
 
         inputs = [{'txid': utx['txid'], 'vout': utx['vout']}]
@@ -263,6 +272,7 @@ def test_valid_change_address(self):
         #
         # test a fundrawtransaction with a provided change address #
         #
+        self.log.info("Test fundrawtxn with a provided change address")
         utx = get_unspent(self.nodes[2].listunspent(), 5)
 
         inputs = [{'txid': utx['txid'], 'vout': utx['vout']}]
@@ -284,6 +294,7 @@ def test_coin_selection(self):
         #
         # test a fundrawtransaction with a VIN smaller than the required amount #
         #
+        self.log.info("Test fundrawtxn with a vin < required amount")
         utx = get_unspent(self.nodes[2].listunspent(), 1)
 
         inputs = [{'txid': utx['txid'], 'vout': utx['vout']}]
@@ -318,6 +329,7 @@ def test_two_vin(self):
         #
         # test a fundrawtransaction with two VINs #
         #
+        self.log.info("Test fundrawtxn with 2 vins")
         utx = get_unspent(self.nodes[2].listunspent(), 1)
         utx2 = get_unspent(self.nodes[2].listunspent(), 5)
 
@@ -353,6 +365,7 @@ def test_two_vin_two_vout(self):
         #
         # test a fundrawtransaction with two VINs and two vOUTs #
         #
+        self.log.info("Test fundrawtxn with 2 vins and 2 vouts")
         utx = get_unspent(self.nodes[2].listunspent(), 1)
         utx2 = get_unspent(self.nodes[2].listunspent(), 5)
 
@@ -380,7 +393,7 @@ def test_invalid_input(self):
         #
         # test a fundrawtransaction with invalid vin #
         #
-        # invalid vin!
+        self.log.info("Test fundrawtxn with an invalid vin")
         inputs = [
             {'txid': "1c7f966dab21119bac53213a2bc7532bff1fa844c124fd750a7d0b1332440bd1", 'vout': 0}]
         outputs = {self.nodes[0].getnewaddress(): 1.0}
@@ -393,6 +406,7 @@ def test_fee_p2pkh(self):
         #
         # compare fee of a standard pubkeyhash transaction
         #
+        self.log.info("Test fundrawtxn p2pkh fee")
         inputs = []
         outputs = {self.nodes[1].getnewaddress(): 1.1}
         rawTx = self.nodes[0].createrawtransaction(inputs, outputs)
@@ -411,11 +425,18 @@ def test_fee_p2pkh_multi_out(self):
         # compare fee of a standard pubkeyhash transaction with multiple
         # outputs
         #
+        self.log.info("Test fundrawtxn p2pkh fee with multiple outputs")
         inputs = []
-        outputs = {self.nodes[1].getnewaddress(): 1.1, self.nodes[1].getnewaddress(): 1.2, self.nodes[1].getnewaddress(): 0.1, self.nodes[
-            1].getnewaddress(): 1.3, self.nodes[1].getnewaddress(): 0.2, self.nodes[1].getnewaddress(): 0.3}
-        rawTx = self.nodes[0].createrawtransaction(inputs, outputs)
-        fundedTx = self.nodes[0].fundrawtransaction(rawTx)
+        outputs = {
+            self.nodes[1].getnewaddress(): 1.1,
+            self.nodes[1].getnewaddress(): 1.2,
+            self.nodes[1].getnewaddress(): 0.1,
+            self.nodes[1].getnewaddress(): 1.3,
+            self.nodes[1].getnewaddress(): 0.2,
+            self.nodes[1].getnewaddress(): 0.3,
+        }
+        rawtx = self.nodes[0].createrawtransaction(inputs, outputs)
+        fundedTx = self.nodes[0].fundrawtransaction(rawtx)
         # create same transaction over sendtoaddress
         txId = self.nodes[0].sendmany("", outputs)
         signedFee = self.nodes[0].getrawmempool(True)[txId]['fee']
@@ -456,6 +477,7 @@ def test_fee_4of5(self):
         #
         # compare fee of a standard pubkeyhash transaction
         #
+        self.log.info("Test fundrawtxn fee with 4-of-5 addresses")
 
         # create 4of5 addr
         addr1 = self.nodes[1].getnewaddress()
@@ -471,7 +493,15 @@ def test_fee_4of5(self):
         addr5Obj = self.nodes[1].getaddressinfo(addr5)
 
         mSigObj = self.nodes[1].addmultisigaddress(
-            4, [addr1Obj['pubkey'], addr2Obj['pubkey'], addr3Obj['pubkey'], addr4Obj['pubkey'], addr5Obj['pubkey']])['address']
+            4,
+            [
+                addr1Obj['pubkey'],
+                addr2Obj['pubkey'],
+                addr3Obj['pubkey'],
+                addr4Obj['pubkey'],
+                addr5Obj['pubkey'],
+            ]
+        )['address']
 
         inputs = []
         outputs = {mSigObj: 1.1}
@@ -490,6 +520,7 @@ def test_spend_2of2(self):
         #
         # spend a 2of2 multisig transaction over fundraw
         #
+        self.log.info("Test fundrawtxn spending 2-of-2 multisig")
 
         # create 2of2 addr
         addr1 = self.nodes[2].getnewaddress()
@@ -499,7 +530,12 @@ def test_spend_2of2(self):
         addr2Obj = self.nodes[2].getaddressinfo(addr2)
 
         mSigObj = self.nodes[2].addmultisigaddress(
-            2, [addr1Obj['pubkey'], addr2Obj['pubkey']])['address']
+            2,
+            [
+                addr1Obj['pubkey'],
+                addr2Obj['pubkey'],
+            ]
+        )['address']
 
         # send 1.2 BCH to msig addr
         self.nodes[0].sendtoaddress(mSigObj, 1.2)
@@ -527,6 +563,8 @@ def test_locked_wallet(self):
         #
         # locked wallet test
         #
+        self.log.info("Test fundrawtxn with locked wallet")
+
         self.nodes[1].encryptwallet("test")
         self.stop_nodes()
 
@@ -588,6 +626,7 @@ def test_many_inputs_fee(self):
         #
         # multiple (~19) inputs tx test | Compare fee #
         #
+        self.log.info("Test fundrawtxn fee with many inputs")
 
         # empty node1, send some small coins from node0 to node1
         self.nodes[1].sendtoaddress(
@@ -621,6 +660,7 @@ def test_many_inputs_send(self):
         #
         # multiple (~19) inputs tx test | sign/send #
         #
+        self.log.info("Test fundrawtxn sign+send with many inputs")
 
         # again, empty node1, send some small coins from node0 to node1
         self.nodes[1].sendtoaddress(
@@ -655,6 +695,7 @@ def test_op_return(self):
         #
         # test fundrawtransaction with OP_RETURN and no vin #
         #
+        self.log.info("Test fundrawtxn with OP_RETURN and no vin")
 
         rawTx = "0100000000010000000000000000066a047465737400000000"
         dec_tx = self.nodes[2].decoderawtransaction(rawTx)
@@ -674,6 +715,7 @@ def test_watchonly(self):
         #
         # test a fundrawtransaction using only watchonly #
         #
+        self.log.info("Test fundrawtxn using only watchonly")
 
         inputs = []
         outputs = {self.nodes[2].getnewaddress(): self.watchonly_amount / 2}
@@ -692,6 +734,7 @@ def test_all_watched_funds(self):
         #
         # test fundrawtransaction using the entirety of watched funds #
         #
+        self.log.info("Test fundrawtxn using entirety of watched funds")
 
         inputs = []
         outputs = {self.nodes[2].getnewaddress(): self.watchonly_amount}
@@ -721,6 +764,7 @@ def test_option_feerate(self):
         #
         # Test feeRate option #
         #
+        self.log.info("Test fundrawtxn feeRate option")
 
         # Make sure there is exactly one input so coin selection can't skew the
         # result
@@ -755,6 +799,7 @@ def test_address_reuse(self):
         #
         # Test no address reuse occurs #
         #
+        self.log.info("Test fundrawtxn does not reuse addresses")
 
         rawTx = self.nodes[3].createrawtransaction(
             inputs=[], outputs={self.nodes[3].getnewaddress(): 1})
@@ -773,6 +818,7 @@ def test_option_subtract_fee_from_outputs(self):
         #
         # Test subtractFeeFromOutputs option #
         #
+        self.log.info("Test fundrawtxn subtractFeeFromOutputs option")
 
         # Make sure there is exactly one input so coin selection can't skew the
         # result