fuzz: investigate test adequacy (unit and fuzz) via mutation testing

agroce commented at 3:54 pm on August 12, 2021: contributor

@MarcoFalke / @practicalswift I’m starting some mutation analysis using https://github.com/agroce/universalmutator

A couple of questions:

At random I picked tx_verify.cpp as a file with high coverage that is likely critical, where any missed non-equivalent mutants should be carefully investigated. Is this a good choice to get the workflow going on?
Is there any mapping from fuzz targets to code expected to be covered? I can run all targets, of course, but knowing which ones might possibly detect tx_verify.cppmutants would be helpful.

agroce added the label Feature on Aug 12, 2021

agroce commented at 6:46 pm on August 12, 2021: contributor

Hmm. make check is thu far killing 0% of tx_verify.cpp mutants. That seems odd…

agroce commented at 7:18 pm on August 12, 2021: contributor

I’m using make; make check to build the changed code and then test, it’s taking a couple of minutes to run the tests. But some of these are extreme enough it must just be that the unit tests don’t check the tx_verify code or I’m doing something wrong…

agroce commented at 4:32 am on August 17, 2021: contributor

@MarcoFalke @practicalswift

is it expected the make check unit tests detected 0 mutants of tx_verify.cpp?

agroce commented at 6:24 pm on August 18, 2021: contributor

@MarcoFalke @practicalswift I’m also getting 0 mutant kills on tx_verify.cpp with FUZZ=process_messages and the process_messages_tx corpus.

Have I just chosen a bad target? Does testing turn off tx verification (at least this kind)?

agroce commented at 8:36 pm on August 18, 2021: contributor

@MarcoFalke and @practicalswift

Never mind on fuzzing – I spoke too soon, there are killed mutants, just a very low rate, 1 in 37 runs. The mutant detected changed an assertion:

 0MUTANT: mutants/tx_verify.mutant.357.cpp
 1*** Original
 2--- Mutant
 3***************
 4*** 177,183 ****
 5      for (unsigned int i = 0; i < tx.vin.size(); ++i) {
 6          const COutPoint &prevout = tx.vin[i].prevout;
 7          const Coin& coin = inputs.AccessCoin(prevout);
 8!         assert(!coin.IsSpent());
 9  
10          // If prev is coinbase, check that it's matured
11          if (coin.IsCoinBase() && nSpendHeight - coin.nHeight < COINBASE_MATURITY) {
12--- 177,183 ----
13      for (unsigned int i = 0; i < tx.vin.size(); ++i) {
14          const COutPoint &prevout = tx.vin[i].prevout;
15          const Coin& coin = inputs.AccessCoin(prevout);
16!         assert(coin.IsSpent());
17  
18          // If prev is coinbase, check that it's matured
19          if (coin.IsCoinBase() && nSpendHeight - coin.nHeight < COINBASE_MATURITY) {

That gets detected in < 30s, counting recompiling the file and copying the corpus.

agroce commented at 9:48 pm on August 18, 2021: contributor

OK, the fuzzing does indeed kill maybe 5% of mutants. And not just a broken assertion, but removing a return statement and some things. This does suggest the unit tests do in fact not kill any?

MarcoFalke commented at 5:38 pm on August 22, 2021: member

For more context-dependent checks, the functional tests might provide higher coverage.

Due to the general nature of the fuzz tests, they might be less suited to detect unwanted consensus changes.

Finally, some mutants might survive because they modify redundant code. For example #22761.

agroce commented at 5:47 pm on August 22, 2021: contributor

Aha. The functional tests are what I need to look to, then, to prune. Thanks!

agroce commented at 6:34 pm on August 22, 2021: contributor

(the idea is to see if anything serious escapes ALL tests, and looks suitable for fuzzing; if it’s not suitable for fuzzing, it is a likely candidate for additional functional testing, of course)

agroce commented at 10:01 pm on August 25, 2021: contributor

At about 14% done, functional tests are killiing ~60% of the mutants not killed by fuzzing for ’tx_verify.cpp'

more anon (Venn diagram of which methods kill what, and some close analysis of the survivors)

agroce commented at 10:06 pm on August 25, 2021: contributor

(since fuzzing killed 10-12% maybe, this means about a 70% kill ratio, which is probably very good; chances are most of those left over are functionally equivalent or otherwise invalid, though probably some deserve covering tests)

agroce commented at 8:43 pm on August 27, 2021: contributor

ok, functional tests may actually be > 70% effective, on their own.

agroce commented at 10:04 pm on August 28, 2021: contributor

Gotta back up the run a bit; the functional tests don’t clean up /tmp, so eventually it caused failures due to space usage. Unlike fuzzing, this isn’t a “problem” just something future users of the functional tests in an automated loop need to know. I’m going to write up a mutation testing primer/FAQ – where should that go? Into the same place as doc/fuzzing.md etc.? Is there a propr place for a higher level link to that?

MarcoFalke commented at 7:37 am on August 29, 2021: member

Jup, there is the doc/README where you can put the link

agroce commented at 8:33 pm on August 31, 2021: contributor

Ok, functional tests look solid, definitely high kill rate.

AND, which is worth knowing, there ARE mutants the fuzzing can kill that functional tests cannot.

Analysis to follow when all runs are done.

agroce commented at 11:26 pm on August 31, 2021: contributor

Functional tests catch 326 of 430 valid mutants of tx_verify.cpp (75.8%). Fuzzing catches an additional two mutants.

Fuzzing overall catches 50 of 430 mutants (11.6%), which is pretty respectable with an oracle presumably mostly limited to crashes, sanitizer issues, and internal asserts.

agroce commented at 11:33 pm on August 31, 2021: contributor

The two mutants only fuzzing detects are:

 0********************************************************************************
 1MUTANT [#1](/bitcoin-bitcoin/1/):
 2tx_verify.mutant.379.cpp: src/consensus/tx_verify.cpp:185
 3*** Original
 4--- Mutant
 5***************
 6*** 182,188 ****
 7          // If prev is coinbase, check that it's matured
 8          if (coin.IsCoinBase() && nSpendHeight - coin.nHeight < COINBASE_MATURITY) {
 9              return state.Invalid(TxValidationResult::TX_PREMATURE_SPEND, "bad-txns-premature-spend-of-coinbase",
10!                 strprintf("tried to spend coinbase at depth %d", nSpendHeight - coin.nHeight));
11          }
12  
13          // Check for negative or overflow input values
14--- 182,188 ----
15          // If prev is coinbase, check that it's matured
16          if (coin.IsCoinBase() && nSpendHeight - coin.nHeight < COINBASE_MATURITY) {
17              return state.Invalid(TxValidationResult::TX_PREMATURE_SPEND, "bad-txns-premature-spend-of-coinbase",
18!                 strprintf("tried to spend coinbase at depth %d", nSpendHeight / coin.nHeight));
19          }
20  
21          // Check for negative or overflow input values
22
23
24********************************************************************************
25MUTANT [#2](/bitcoin-bitcoin/2/):
26tx_verify.mutant.380.cpp: src/consensus/tx_verify.cpp:185
27*** Original
28--- Mutant
29***************
30*** 182,188 ****
31          // If prev is coinbase, check that it's matured
32          if (coin.IsCoinBase() && nSpendHeight - coin.nHeight < COINBASE_MATURITY) {
33              return state.Invalid(TxValidationResult::TX_PREMATURE_SPEND, "bad-txns-premature-spend-of-coinbase",
34!                 strprintf("tried to spend coinbase at depth %d", nSpendHeight - coin.nHeight));
35          }
36  
37          // Check for negative or overflow input values
38--- 182,188 ----
39          // If prev is coinbase, check that it's matured
40          if (coin.IsCoinBase() && nSpendHeight - coin.nHeight < COINBASE_MATURITY) {
41              return state.Invalid(TxValidationResult::TX_PREMATURE_SPEND, "bad-txns-premature-spend-of-coinbase",
42!                 strprintf("tried to spend coinbase at depth %d", nSpendHeight % coin.nHeight));
43          }
44  
45          // Check for negative or overflow input values

bitcoin deleted a comment on Sep 1, 2021

agroce commented at 0:25 am on September 1, 2021: contributor

Ah! This may not be the full power of the functional tests. I speculate that the fuzzing may not be the cause of detection here, but the fact my initial functional run was without any sanitizers, in order to kill the easily killed mutants quickly. I’ll run a sanitizer functional run (I assume CI does that at some point?) on the remaining mutants soon.

agroce commented at 1:36 pm on September 1, 2021: contributor

Yes, I don’t know how many, but there are additional mutants the functional tests catch with sanitizers. Probably no more than an additional 10-20 mutants, but that will reduce the challenge of analyzing the 100+ unkilled.

agroce commented at 5:15 pm on September 5, 2021: contributor

Mutant #379 and #380 above appear to be genuinely unique to fuzzing, in particular coins_view fuzzing. Not killed via sanitizer run of functional tests, either. Final kill for functional tests with sanitizer is 78.6% of mutants. Now running valgrind to see if it adds a few more.

agroce commented at 5:45 pm on September 5, 2021: contributor

Here’s a Venn diagram of the pre-Valgrind results (the * is because I only ran the sanitizer tests on things functional hadn’t killed yet, though you can obviously assume it shares all functional-alone kills)

venn_result17745

agroce commented at 5:48 pm on September 5, 2021: contributor

Hmm. Valgrind complains a lot on the functional tests without any mutants, I’ll see if the tests still pass…

agroce commented at 7:16 pm on September 5, 2021: contributor

hmm, how do I actually get the functional tests to run under valgrind, vs valgrind checking the python? I’m sure in doc, but not an option to test_runner that I see…

MarcoFalke commented at 7:35 pm on September 5, 2021: member

You’ll just pass --valgrind to the test runner. Though the suppressions file is only tested on Ubuntu: https://github.com/bitcoin/bitcoin/blob/0ebd88fe0bf45d872883b4d361147f5c047b1a46/contrib/valgrind.supp#L16

agroce commented at 8:48 pm on September 5, 2021: contributor

thanks!

hmm, I’m on ubuntu (in docker) but –valgrind –failfast is failing on wallet_hd.py --legacy-wallet even for the base, ok, code.

agroce commented at 9:20 pm on September 5, 2021: contributor

Yeah, the suppressions just don’t seem to be working in my (20.04 I am fairly sure) ubuntu docker.

agroce commented at 2:10 am on September 6, 2021: contributor

OK!

https://github.com/agroce/bitcorpus/blob/master/mutation/prioritized_full_inspect.txt

is the full text of the mutants 1) not killed by anything (have not run valgrind yet) and 2) that are not, to my inspection, obviously semantically equivalent.

The main things I have pruned are weakenings or removals of assertions. I think some of these are also in that category. Can someone confirm the loops around assert(!coin.IsSpent()) are just checks, not doing anything, so (e.g.) iterating through fewer items is fine?

 0tx_verify.mutant.249.cpp: ./tx_verify.cpp:136
 1*** Original
 2--- Mutant
 3***************
 4*** 133,139 ****
 5          return 0;
 6  
 7      unsigned int nSigOps = 0;
 8!     for (unsigned int i = 0; i < tx.vin.size(); i++)
 9      {
10          const Coin& coin = inputs.AccessCoin(tx.vin[i].prevout);
11          assert(!coin.IsSpent());
12--- 133,139 ----
13          return 0;
14  
15      unsigned int nSigOps = 0;
16!     for (unsigned int i = (0+1); i < tx.vin.size(); i++)
17      {
18          const Coin& coin = inputs.AccessCoin(tx.vin[i].prevout);
19          assert(!coin.IsSpent());

There are also probably some equivalent comparisons, where an unsigned is <= not just ==. And some string replacements in failure messages that might be harmless.

But the rest here likely bears close examination as potential holes in testing.

agroce commented at 2:28 am on September 6, 2021: contributor

At least an 85.8% kill rate after pruning, which is solid. Presumably a large number of these are also not problems.

MarcoFalke commented at 11:09 am on September 6, 2021: member

With valgrind, you will also need to increase the timeout-factor a bit. What is the error you are seeing?

agroce commented at 4:43 pm on September 6, 2021: contributor

Aha. I see:

 0python3 test/functional/test_runner.py --extended --valgrind --failfast 
 1Temporary test directory at /tmp/test_runner_₿_🏃_20210906_092947
 2Running Unit Tests for Test Framework Modules
 3..........
 4----------------------------------------------------------------------
 5Ran 10 tests in 1.499s
 6
 7OK
 81/219 - wallet_hd.py --descriptors skipped
 92/219 - wallet_hd.py --legacy-wallet failed, Duration: 71 s                                                                           
10
11stdout:
122021-09-06T16:29:51.954000Z TestFramework (INFO): Initializing test directory /tmp/test_runner_₿_🏃_20210906_092947/wallet_hd_216
132021-09-06T16:30:55.211000Z TestFramework (ERROR): Assertion failed
14Traceback (most recent call last):
15  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 530, in start_nodes
16    node.wait_for_rpc_connection()
17  File "/root/bitcoin/test/functional/test_framework/test_node.py", line 283, in wait_for_rpc_connection
18    self._raise_assertion_error("Unable to connect to bitcoind after {}s".format(self.rpc_timeout))
19  File "/root/bitcoin/test/functional/test_framework/test_node.py", line 166, in _raise_assertion_error
20    raise AssertionError(self._node_msg(msg))
21AssertionError: [node 0] Unable to connect to bitcoind after 60s
22
23During handling of the above exception, another exception occurred:
24
25Traceback (most recent call last):
26  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 130, in main
27    self.setup()
28  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 285, in setup
29    self.setup_network()
30  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 379, in setup_network
31    self.setup_nodes()
32  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 404, in setup_nodes
33    self.start_nodes()
34  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 533, in start_nodes
35    self.stop_nodes()
36  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 548, in stop_nodes
37    node.stop_node(wait=wait, wait_until_stopped=False)
38  File "/root/bitcoin/test/functional/test_framework/test_node.py", line 323, in stop_node
39    self.stop(wait=wait)
40  File "/root/bitcoin/test/functional/test_framework/test_node.py", line 183, in __getattr__
41    assert self.rpc_connected and self.rpc is not None, self._node_msg("Error: no RPC connection")
42AssertionError: [node 0] Error: no RPC connection
432021-09-06T16:30:55.743000Z TestFramework (INFO): Stopping nodes
44[node 1] Cleaning up leftover process
45[node 0] Cleaning up leftover process
46
47
48stderr:
49Traceback (most recent call last):
50  File "/root/bitcoin/test/functional/wallet_hd.py", line 280, in <module>
51    WalletHDTest().main()
52  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 154, in main
53    exit_code = self.shutdown()
54  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 301, in shutdown
55    self.stop_nodes()
56  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 548, in stop_nodes
57    node.stop_node(wait=wait, wait_until_stopped=False)
58  File "/root/bitcoin/test/functional/test_framework/test_node.py", line 323, in stop_node
59    self.stop(wait=wait)
60  File "/root/bitcoin/test/functional/test_framework/test_node.py", line 183, in __getattr__
61    assert self.rpc_connected and self.rpc is not None, self._node_msg("Error: no RPC connection")
62AssertionError: [node 0] Error: no RPC connection
63
64
65Early exiting after test failure
66
67TEST                                               | STATUS    | DURATION
68
69wallet_hd.py --descriptors                         | ○ Skipped | 0 s
70wallet_hd.py --legacy-wallet                       | ✖ Failed  | 71 s
71
72ALL                                                | ✖ Failed  | 71 s (accumulated) 
73Runtime: 71 s
74
75Killed

agroce commented at 4:45 pm on September 6, 2021: contributor

When I try to use --timeout-factor to fix that I get:

0python3 test/functional/test_runner.py --extended --valgrind --failfast --timeout-factor 100
1Temporary test directory at /tmp/test_runner_₿_🏃_20210906_094537
2WARNING! Test '100' not found in full test list.
3No valid test scripts specified. Check that your test is in one of the test lists in test_runner.py, or run test_runner.py with no arguments to run all tests

MarcoFalke commented at 6:44 am on September 7, 2021: member

Does --timeout-factor=100 work?

agroce commented at 7:45 am on September 7, 2021: contributor

Aha! Yes!

agroce commented at 8:21 am on September 7, 2021: contributor

Well, sort of. It runs, though even with a 1000x factor I get:

 0Ran 10 tests in 0.773s
 1
 2OK
 31/219 - wallet_hd.py --descriptors skipped
 42/219 - feature_dbcrash.py failed, Duration: 55 s                                                            
 5
 6stdout:
 72021-09-07T08:05:42.904000Z TestFramework (INFO): Initializing test directory /tmp/test_runner_₿_🏃_20210907_010540/feature_dbcrash_217
 82021-09-07T08:06:38.157000Z TestFramework (ERROR): Unexpected exception caught during testing
 9Traceback (most recent call last):
10  File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 108, in _request
11    return self._get_response()
12  File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 168, in _get_response
13    http_response = self.__conn.getresponse()
14  File "/usr/lib/python3.8/http/client.py", line 1344, in getresponse
15    response.begin()
16  File "/usr/lib/python3.8/http/client.py", line 307, in begin
17    version, status, reason = self._read_status()
18  File "/usr/lib/python3.8/http/client.py", line 276, in _read_status
19    raise RemoteDisconnected("Remote end closed connection without"
20http.client.RemoteDisconnected: Remote end closed connection without response

which is different at least…

MarcoFalke commented at 8:29 am on September 7, 2021: member

Does ./test/functional/combine_logs.py /tmp/test_runner_₿_🏃_20210907_010540/feature_dbcrash_217 yield anything?

agroce commented at 2:01 pm on September 7, 2021: contributor

On a non-mutated version and some mutants it dies like this, more common actually:

  0rm -rf /tmp/test_runner*; make; python3 test/functional/test_runner.py --extended --valgrind --timeout-factor=0 --failfast
  1Making all in src
  2make[1]: Entering directory '/root/bitcoin/src'
  3make[2]: Entering directory '/root/bitcoin/src'
  4make[3]: Entering directory '/root/bitcoin'
  5make[3]: Leaving directory '/root/bitcoin'
  6  CXX      consensus/libbitcoin_server_a-tx_verify.o
  7  AR       libbitcoin_server.a
  8  CXXLD    bitcoind
  9  CXXLD    test/test_bitcoin
 10  CXXLD    bench/bench_bitcoin
 11  CXXLD    test/fuzz/fuzz
 12make[2]: Leaving directory '/root/bitcoin/src'
 13make[1]: Leaving directory '/root/bitcoin/src'
 14Making all in doc/man
 15make[1]: Entering directory '/root/bitcoin/doc/man'
 16make[1]: Nothing to be done for 'all'.
 17make[1]: Leaving directory '/root/bitcoin/doc/man'
 18make[1]: Entering directory '/root/bitcoin'
 19make[1]: Nothing to be done for 'all-am'.
 20make[1]: Leaving directory '/root/bitcoin'
 21Temporary test directory at /tmp/test_runner_₿_🏃_20210907_065517
 22Running Unit Tests for Test Framework Modules
 23..........
 24----------------------------------------------------------------------
 25Ran 10 tests in 1.061s
 26
 27OK
 281/219 - wallet_hd.py --descriptors skipped
 29..................................................................................................................................................                                                                                                                                                  2/219 - wallet_hd.py --legacy-wallet failed, Duration: 139 s                                                                    
 30
 31stdout:
 322021-09-07T13:55:20.310000Z TestFramework (INFO): Initializing test directory /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216
 332021-09-07T13:57:39.289000Z TestFramework (ERROR): Unexpected exception caught during testing
 34Traceback (most recent call last):
 35  File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 108, in _request
 36    return self._get_response()
 37  File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 168, in _get_response
 38    http_response = self.__conn.getresponse()
 39  File "/usr/lib/python3.8/http/client.py", line 1344, in getresponse
 40    response.begin()
 41  File "/usr/lib/python3.8/http/client.py", line 307, in begin
 42    version, status, reason = self._read_status()
 43  File "/usr/lib/python3.8/http/client.py", line 276, in _read_status
 44    raise RemoteDisconnected("Remote end closed connection without"
 45http.client.RemoteDisconnected: Remote end closed connection without response
 46
 47During handling of the above exception, another exception occurred:
 48
 49Traceback (most recent call last):
 50  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 130, in main
 51    self.setup()
 52  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 285, in setup
 53    self.setup_network()
 54  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 379, in setup_network
 55    self.setup_nodes()
 56  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 406, in setup_nodes
 57    self.import_deterministic_coinbase_privkeys()
 58  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 423, in import_deterministic_coinbase_privkeys
 59    self.init_wallet(i)
 60  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 431, in init_wallet
 61    n.importprivkey(privkey=n.get_deterministic_priv_key().key, label='coinbase')
 62  File "/root/bitcoin/test/functional/test_framework/test_node.py", line 689, in importprivkey
 63    return self.__getattr__('importprivkey')(privkey, label, rescan)
 64  File "/root/bitcoin/test/functional/test_framework/coverage.py", line 49, in __call__
 65    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
 66  File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 144, in __call__
 67    response, status = self._request('POST', self.__url.path, postdata.encode('utf-8'))
 68  File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 113, in _request
 69    self.__conn.request(method, path, postdata, headers)
 70  File "/usr/lib/python3.8/http/client.py", line 1252, in request
 71    self._send_request(method, url, body, headers, encode_chunked)
 72  File "/usr/lib/python3.8/http/client.py", line 1298, in _send_request
 73    self.endheaders(body, encode_chunked=encode_chunked)
 74  File "/usr/lib/python3.8/http/client.py", line 1247, in endheaders
 75    self._send_output(message_body, encode_chunked=encode_chunked)
 76  File "/usr/lib/python3.8/http/client.py", line 1007, in _send_output
 77    self.send(msg)
 78  File "/usr/lib/python3.8/http/client.py", line 947, in send
 79    self.connect()
 80  File "/usr/lib/python3.8/http/client.py", line 918, in connect
 81    self.sock = self._create_connection(
 82  File "/usr/lib/python3.8/socket.py", line 808, in create_connection
 83    raise err
 84  File "/usr/lib/python3.8/socket.py", line 796, in create_connection
 85    sock.connect(sa)
 86ConnectionRefusedError: [Errno 111] Connection refused
 872021-09-07T13:57:39.347000Z TestFramework (INFO): Stopping nodes
 882021-09-07T13:57:39.348000Z TestFramework.node0 (ERROR): Unable to stop node.
 89Traceback (most recent call last):
 90  File "/root/bitcoin/test/functional/test_framework/test_node.py", line 323, in stop_node
 91    self.stop(wait=wait)
 92  File "/root/bitcoin/test/functional/test_framework/coverage.py", line 49, in __call__
 93    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
 94  File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 144, in __call__
 95    response, status = self._request('POST', self.__url.path, postdata.encode('utf-8'))
 96  File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 107, in _request
 97    self.__conn.request(method, path, postdata, headers)
 98  File "/usr/lib/python3.8/http/client.py", line 1252, in request
 99    self._send_request(method, url, body, headers, encode_chunked)
100  File "/usr/lib/python3.8/http/client.py", line 1263, in _send_request
101    self.putrequest(method, url, **skips)
102  File "/usr/lib/python3.8/http/client.py", line 1089, in putrequest
103    raise CannotSendRequest(self.__state)
104http.client.CannotSendRequest: Request-sent
105[node 1] Cleaning up leftover process
106[node 0] Cleaning up leftover process
107
108
109stderr:
110Traceback (most recent call last):
111  File "/root/bitcoin/test/functional/wallet_hd.py", line 280, in <module>
112    WalletHDTest().main()
113  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 154, in main
114    exit_code = self.shutdown()
115  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 301, in shutdown
116    self.stop_nodes()
117  File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 548, in stop_nodes
118    node.stop_node(wait=wait, wait_until_stopped=False)
119  File "/root/bitcoin/test/functional/test_framework/test_node.py", line 337, in stop_node
120    raise AssertionError("Unexpected stderr {} != {}".format(stderr, expected_stderr))
121AssertionError: Unexpected stderr ==48855== Thread 13 b-httpworker.2:
122==48855== Conditional jump or move depends on uninitialised value(s)
123==48855==    at 0x5BFDBB: CWallet::ScanForWalletTransactions(uint256 const&, int, std::optional<int>, WalletRescanReserver const&, bool) (wallet.cpp:1653)
124==48855==    by 0x5C07CB: CWallet::RescanFromTime(long, WalletRescanReserver const&, bool) (wallet.cpp:1556)
125==48855==    by 0x60E5ED: RescanWallet(CWallet&, WalletRescanReserver const&, long, bool) (rpcdump.cpp:85)
126==48855==    by 0x628253: importprivkey()::{lambda(RPCHelpMan const&, JSONRPCRequest const&)#1}::operator()(RPCHelpMan const&, JSONRPCRequest const&) const [clone .isra.0] (rpcdump.cpp:187)
127==48855==    by 0x628554: std::_Function_handler<UniValue (RPCHelpMan const&, JSONRPCRequest const&), importprivkey()::{lambda(RPCHelpMan const&, JSONRPCRequest const&)#1}>::_M_invoke(std::_Any_data const&, RPCHelpMan const&, JSONRPCRequest const&) (std_function.h:286)
128==48855==    by 0x692115: operator() (std_function.h:688)
129==48855==    by 0x692115: RPCHelpMan::HandleRequest(JSONRPCRequest const&) const (util.cpp:575)
130==48855==    by 0x3471CB: CRPCCommand::CRPCCommand(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, RPCHelpMan (*)())::{lambda(JSONRPCRequest const&, UniValue&, bool)#1}::operator()(JSONRPCRequest const&, UniValue&, bool) const (server.h:110)
131==48855==    by 0x4E417B: wallet::(anonymous namespace)::WalletClientImpl::registerRpcs()::{lambda(JSONRPCRequest const&, UniValue&, bool)#1}::operator()(JSONRPCRequest const&, UniValue&, bool) const (std_function.h:688)
132==48855==    by 0x2BF324: operator() (std_function.h:688)
133==48855==    by 0x2BF324: operator() (interfaces.cpp:397)
134==48855==    by 0x2BF324: std::_Function_handler<bool (JSONRPCRequest const&, UniValue&, bool), node::(anonymous namespace)::RpcHandlerImpl::RpcHandlerImpl(CRPCCommand const&)::{lambda(JSONRPCRequest const&, UniValue&, bool)#1}>::_M_invoke(std::_Any_data const&, JSONRPCRequest const&, UniValue&, bool&&) (std_function.h:285)
135==48855==    by 0x3D9396: operator() (std_function.h:688)
136==48855==    by 0x3D9396: ExecuteCommand(CRPCCommand const&, JSONRPCRequest const&, UniValue&, bool) (server.cpp:480)
137==48855==    by 0x3D9FB6: ExecuteCommands(std::vector<CRPCCommand const*, std::allocator<CRPCCommand const*> > const&, JSONRPCRequest const&, UniValue&) [clone .constprop.0] (server.cpp:444)
138==48855==    by 0x3DA55D: CRPCTable::execute(JSONRPCRequest const&) const (server.cpp:464)
139==48855== 
140{
141   <insert_a_suppression_name_here>
142   Memcheck:Cond
143   fun:_ZN7CWallet25ScanForWalletTransactionsERK7uint256iSt8optionalIiERK20WalletRescanReserverb
144   fun:_ZN7CWallet14RescanFromTimeElRK20WalletRescanReserverb
145   fun:_ZL12RescanWalletR7CWalletRK20WalletRescanReserverlb
146   fun:_ZZ13importprivkeyvENKUlRK10RPCHelpManRK14JSONRPCRequestE_clES1_S4_.isra.0
147   fun:_ZNSt17_Function_handlerIF8UniValueRK10RPCHelpManRK14JSONRPCRequestEZ13importprivkeyvEUlS3_S6_E_E9_M_invokeERKSt9_Any_dataS3_S6_
148   fun:operator()
149   fun:_ZNK10RPCHelpMan13HandleRequestERK14JSONRPCRequest
150   fun:_ZZN11CRPCCommandC4ENSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEPF10RPCHelpManvEENKUlRK14JSONRPCRequestR8UniValuebE_clESB_SD_b
151   fun:_ZZN6wallet12_GLOBAL__N_116WalletClientImpl12registerRpcsEvENKUlRK14JSONRPCRequestR8UniValuebE_clES4_S6_b
152   fun:operator()
153   fun:operator()
154   fun:_ZNSt17_Function_handlerIFbRK14JSONRPCRequestR8UniValuebEZN4node12_GLOBAL__N_114RpcHandlerImplC4ERK11CRPCCommandEUlS2_S4_bE_E9_M_invokeERKSt9_Any_dataS2_S4_Ob
155   fun:operator()
156   fun:_ZL14ExecuteCommandRK11CRPCCommandRK14JSONRPCRequestR8UniValueb
157   fun:_ZL15ExecuteCommandsRKSt6vectorIPK11CRPCCommandSaIS2_EERK14JSONRPCRequestR8UniValue.constprop.0
158   fun:_ZNK9CRPCTable7executeERK14JSONRPCRequest
159}
160==48855== 
161==48855== Exit program on first error (--exit-on-first-error=yes) != 
162
163
164Early exiting after test failure
165
166TEST                                               | STATUS    | DURATION
167
168wallet_hd.py --descriptors                         | ○ Skipped | 0 s
169wallet_hd.py --legacy-wallet                       | ✖ Failed  | 139 s
170
171ALL                                                | ✖ Failed  | 139 s (accumulated) 
172Runtime: 139 s
173
174Killed
175root@53f441e8d7b7:~/bitcoin# ./test/functional/combine_logs.py /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/
176 test  2021-09-07T13:55:20.309000Z TestFramework (DEBUG): PRNG seed is: 4065656687483736910 
177 test  2021-09-07T13:55:20.309000Z TestFramework (DEBUG): Setting up network thread 
178 test  2021-09-07T13:55:20.310000Z TestFramework (INFO): Initializing test directory /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216 
179 test  2021-09-07T13:55:20.315000Z TestFramework.node0 (DEBUG): bitcoind started, waiting for RPC to come up 
180 test  2021-09-07T13:55:20.320000Z TestFramework.node1 (DEBUG): bitcoind started, waiting for RPC to come up 
181 node0 2021-09-07T13:56:06.935968Z [init] [init/common.cpp:165] [LogPackageVersion] Bitcoin Core version v22.99.0-9948f114f8e6-dirty (release build) 
182 node0 2021-09-07T13:56:07.196264Z [init] [init.cpp:635] [InitParameterInteraction] InitParameterInteraction: parameter interaction: -bind set -> setting -listen=1 
183 node0 2021-09-07T13:56:07.665759Z [init] [init.cpp:894] [AppInitParameterInteraction] Validating signatures for all blocks. 
184 node0 2021-09-07T13:56:07.678041Z [init] [init.cpp:905] [AppInitParameterInteraction] Setting nMinimumChainWork=0000000000000000000000000000000000000000000000000000000000000000 
185 node0 2021-09-07T13:56:08.867738Z [init] [init/common.cpp:29] [SetGlobals] Using the 'sse4(1way),sse41(4way),avx2(8way)' SHA256 implementation 
186 node0 2021-09-07T13:56:08.872269Z [init] [random.cpp:103] [ReportHardwareRand] Using RdRand as an additional entropy source 
187 node0 2021-09-07T13:56:17.801824Z [init] [init/common.cpp:136] [StartLogging] Default data directory /root/.bitcoin 
188 node0 2021-09-07T13:56:17.819558Z [init] [init/common.cpp:137] [StartLogging] Using data directory /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest 
189 node0 2021-09-07T13:56:17.843184Z [init] [init/common.cpp:142] [StartLogging] Config file: /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/bitcoin.conf 
190 node0 2021-09-07T13:56:17.882798Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: regtest="1" 
191 node0 2021-09-07T13:56:17.917085Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] bind="127.0.0.1" 
192 node0 2021-09-07T13:56:17.917851Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] connect="0" 
193 node0 2021-09-07T13:56:17.920743Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] discover="0" 
194 node0 2021-09-07T13:56:17.921267Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] dnsseed="0" 
195 node0 2021-09-07T13:56:17.921679Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] fallbackfee="0.0002" 
196 node0 2021-09-07T13:56:17.925587Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] fixedseeds="0" 
197 node0 2021-09-07T13:56:17.926333Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] keypool="1" 
198 node0 2021-09-07T13:56:17.926941Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] listenonion="0" 
199 node0 2021-09-07T13:56:17.932689Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] natpmp="0" 
200 node0 2021-09-07T13:56:17.933435Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] port="13592" 
201 node0 2021-09-07T13:56:17.934006Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] printtoconsole="0" 
202 node0 2021-09-07T13:56:17.941317Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] rpcport="18592" 
203 node0 2021-09-07T13:56:17.941764Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] server="1" 
204 node0 2021-09-07T13:56:17.945603Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] shrinkdebugfile="0" 
205 node0 2021-09-07T13:56:17.950130Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] unsafesqlitesync="1" 
206 node0 2021-09-07T13:56:17.950775Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] upnp="0" 
207 node0 2021-09-07T13:56:17.961095Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: datadir="/tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0" 
208 node0 2021-09-07T13:56:17.967528Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: debug="" 
209 node0 2021-09-07T13:56:17.968359Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: debugexclude="libevent" 
210 node0 2021-09-07T13:56:17.968785Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: debugexclude="leveldb" 
211 node0 2021-09-07T13:56:17.975666Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: logsourcelocations="" 
212 node0 2021-09-07T13:56:17.976403Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: logthreadnames="" 
213 node0 2021-09-07T13:56:17.977104Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: logtimemicros="" 
214 node0 2021-09-07T13:56:17.983332Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: uacomment="testnode0" 
215 node0 2021-09-07T13:56:18.001812Z [init] [init.cpp:1081] [AppInitMain] Using at most 125 automatic connections (1048564 file descriptors available) 
216 node1 2021-09-07T13:56:19.664512Z [init] [init/common.cpp:165] [LogPackageVersion] Bitcoin Core version v22.99.0-9948f114f8e6-dirty (release build) 
217 node1 2021-09-07T13:56:20.409849Z [init] [init.cpp:635] [InitParameterInteraction] InitParameterInteraction: parameter interaction: -bind set -> setting -listen=1 
218 node1 2021-09-07T13:56:20.867233Z [init] [init.cpp:894] [AppInitParameterInteraction] Validating signatures for all blocks. 
219 node1 2021-09-07T13:56:20.990075Z [init] [init.cpp:905] [AppInitParameterInteraction] Setting nMinimumChainWork=0000000000000000000000000000000000000000000000000000000000000000 
220 node0 2021-09-07T13:56:22.068187Z [init] [script/sigcache.cpp:101] [InitSignatureCache] Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements 
221 node1 2021-09-07T13:56:26.898616Z [init] [init/common.cpp:29] [SetGlobals] Using the 'sse4(1way),sse41(4way),avx2(8way)' SHA256 implementation 
222 node1 2021-09-07T13:56:26.957534Z [init] [random.cpp:103] [ReportHardwareRand] Using RdRand as an additional entropy source 
223 node0 2021-09-07T13:56:27.300549Z [init] [validation.cpp:1371] [InitScriptExecutionCache] Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements 
224 node0 2021-09-07T13:56:27.347787Z [init] [init.cpp:1108] [AppInitMain] Script verification uses 7 additional threads 
225 node0 2021-09-07T13:56:32.545649Z [scheduler] [util/thread.cpp:17] [TraceThread] scheduler thread start 
226 node1 2021-09-07T13:56:39.688847Z [init] [init/common.cpp:136] [StartLogging] Default data directory /root/.bitcoin 
227 node1 2021-09-07T13:56:39.735887Z [init] [init/common.cpp:137] [StartLogging] Using data directory /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node1/regtest 
228 node1 2021-09-07T13:56:39.784951Z [init] [init/common.cpp:142] [StartLogging] Config file: /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node1/bitcoin.conf 
229 node1 2021-09-07T13:56:39.860548Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: regtest="1" 
230 node1 2021-09-07T13:56:39.865511Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] bind="127.0.0.1" 
231 node1 2021-09-07T13:56:39.890011Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] connect="0" 
232 node1 2021-09-07T13:56:39.891165Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] discover="0" 
233 node1 2021-09-07T13:56:39.892218Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] dnsseed="0" 
234 node1 2021-09-07T13:56:39.923316Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] fallbackfee="0.0002" 
235 node1 2021-09-07T13:56:39.924016Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] fixedseeds="0" 
236 node1 2021-09-07T13:56:40.142828Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] keypool="1" 
237 node1 2021-09-07T13:56:40.143739Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] listenonion="0" 
238 node1 2021-09-07T13:56:40.166353Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] natpmp="0" 
239 node1 2021-09-07T13:56:40.167765Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] port="13593" 
240 node1 2021-09-07T13:56:40.168796Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] printtoconsole="0" 
241 node1 2021-09-07T13:56:40.169547Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] rpcport="18593" 
242 node1 2021-09-07T13:56:40.170271Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] server="1" 
243 node1 2021-09-07T13:56:40.187957Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] shrinkdebugfile="0" 
244 node1 2021-09-07T13:56:40.189017Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] unsafesqlitesync="1" 
245 node1 2021-09-07T13:56:40.189946Z [init] [util/system.cpp:1041] [logArgsPrefix] Config file arg: [regtest] upnp="0" 
246 node1 2021-09-07T13:56:40.209049Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: datadir="/tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node1" 
247 node1 2021-09-07T13:56:40.211108Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: debug="" 
248 node1 2021-09-07T13:56:40.231056Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: debugexclude="libevent" 
249 node1 2021-09-07T13:56:40.231794Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: debugexclude="leveldb" 
250 node1 2021-09-07T13:56:40.232977Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: keypool="0" 
251 node1 2021-09-07T13:56:40.233782Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: logsourcelocations="" 
252 node1 2021-09-07T13:56:40.234453Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: logthreadnames="" 
253 node1 2021-09-07T13:56:40.235061Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: logtimemicros="" 
254 node1 2021-09-07T13:56:40.261083Z [init] [util/system.cpp:1041] [logArgsPrefix] Command-line arg: uacomment="testnode1" 
255 node1 2021-09-07T13:56:40.316717Z [init] [init.cpp:1081] [AppInitMain] Using at most 125 automatic connections (1048564 file descriptors available) 
256 node1 2021-09-07T13:56:41.813963Z [init] [script/sigcache.cpp:101] [InitSignatureCache] Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements 
257 node1 2021-09-07T13:56:42.890949Z [init] [validation.cpp:1371] [InitScriptExecutionCache] Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements 
258 node1 2021-09-07T13:56:42.896969Z [init] [init.cpp:1108] [AppInitMain] Script verification uses 7 additional threads 
259 node1 2021-09-07T13:56:47.832157Z [scheduler] [util/thread.cpp:17] [TraceThread] scheduler thread start 
260 node0 2021-09-07T13:57:09.451400Z [init] [httpserver.cpp:180] [InitHTTPAllowList] Allowing HTTP connections from: 127.0.0.0/8 ::1/128 
261 node0 2021-09-07T13:57:09.831978Z [init] [httpserver.cpp:316] [HTTPBindAddresses] Binding RPC on address ::1 port 18592 
262 node0 2021-09-07T13:57:09.949957Z [init] [httpserver.cpp:346] [libevent_log_cb] libevent: getaddrinfo: address family for nodename not supported 
263 node0 2021-09-07T13:57:09.967851Z [init] [httpserver.cpp:325] [HTTPBindAddresses] Binding RPC on address ::1 port 18592 failed. 
264 node0 2021-09-07T13:57:09.973666Z [init] [httpserver.cpp:316] [HTTPBindAddresses] Binding RPC on address 127.0.0.1 port 18592 
265 node0 2021-09-07T13:57:10.049649Z [init] [httpserver.cpp:391] [InitHTTPServer] Initialized HTTP server 
266 node0 2021-09-07T13:57:10.062719Z [init] [httpserver.cpp:393] [InitHTTPServer] HTTP: creating work queue of depth 16 
267 node0 2021-09-07T13:57:10.086949Z [init] [rpc/server.cpp:292] [StartRPC] Starting RPC 
268 node0 2021-09-07T13:57:10.235111Z [init] [httprpc.cpp:294] [StartHTTPRPC] Starting HTTP RPC server 
269 node0 2021-09-07T13:57:10.247861Z [init] [httprpc.cpp:246] [InitRPCAuthentication] Using random cookie authentication. 
270 node0 2021-09-07T13:57:10.334449Z [init] [rpc/request.cpp:101] [GenerateAuthCookie] Generated RPC authentication cookie /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest/.cookie 
271 node0 2021-09-07T13:57:10.390215Z [init] [httpserver.cpp:635] [RegisterHTTPHandler] Registering HTTP handler for / (exactmatch 1) 
272 node0 2021-09-07T13:57:10.503791Z [init] [httpserver.cpp:635] [RegisterHTTPHandler] Registering HTTP handler for /wallet/ (exactmatch 0) 
273 node0 2021-09-07T13:57:10.523827Z [init] [httpserver.cpp:421] [StartHTTPServer] Starting HTTP server 
274 node0 2021-09-07T13:57:10.527761Z [init] [httpserver.cpp:423] [StartHTTPServer] HTTP: starting 4 worker threads 
275 node0 2021-09-07T13:57:10.950373Z [http] [httpserver.cpp:282] [ThreadHTTP] Entering http event loop 
276 node0 2021-09-07T13:57:13.239373Z [init] [wallet/load.cpp:40] [VerifyWallets] Using wallet directory /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest/wallets 
277 node0 2021-09-07T13:57:13.283893Z [init] [noui.cpp:56] [noui_InitMessage] init message: Verifying wallet(s)… 
278 node0 2021-09-07T13:57:13.553405Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading banlist… 
279 node0 2021-09-07T13:57:14.433623Z [init] [banman.cpp:27] [BanMan] Recreating the banlist database 
280 node0 2021-09-07T13:57:14.777974Z [init] [banman.cpp:54] [DumpBanlist] Flushed 0 banned node addresses/subnets to disk  249ms 
281 node0 2021-09-07T13:57:14.813418Z [init] [net.cpp:1796] [SetTryNewOutboundPeer] net: setting try another outbound peer=false 
282 node0 2021-09-07T13:57:15.222911Z [init] [net.cpp:2443] [SetNetworkActive] SetNetworkActive: true 
283 node0 2021-09-07T13:57:15.408359Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37230 
284 node0 2021-09-07T13:57:15.482771Z [init] [policy/fees.cpp:530] [CBlockPolicyEstimator] Failed to read fee estimates from /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest/fee_estimates.dat. Continue anyway. 
285 node0 2021-09-07T13:57:16.795892Z [init] [init.cpp:1294] [AppInitMain] Using /16 prefix for IP bucketing 
286 node0 2021-09-07T13:57:16.815381Z [init] [init.cpp:1330] [AppInitMain] Cache configuration: 
287 node0 2021-09-07T13:57:16.898518Z [init] [init.cpp:1331] [AppInitMain] * Using 2.0 MiB for block index database 
288 node0 2021-09-07T13:57:16.910571Z [init] [init.cpp:1339] [AppInitMain] * Using 8.0 MiB for chain state database 
289 node0 2021-09-07T13:57:16.979730Z [init] [init.cpp:1340] [AppInitMain] * Using 440.0 MiB for in-memory UTXO set (plus up to 286.1 MiB of unused mempool space) 
290 node0 2021-09-07T13:57:16.995518Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading block index… 
291 node0 2021-09-07T13:57:17.024124Z [init] [validation.cpp:4693] [InitializeChainstate] Switching active chainstate to Chainstate [ibd] @ height -1 (null) 
292 node0 2021-09-07T13:57:17.126877Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
293 node0 2021-09-07T13:57:17.924400Z [init] [dbwrapper.cpp:137] [CDBWrapper] Opening LevelDB in /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest/blocks/index 
294 node0 2021-09-07T13:57:19.213440Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37244 
295 node0 2021-09-07T13:57:19.223686Z [httpworker.2] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
296 node0 2021-09-07T13:57:19.425879Z [init] [dbwrapper.cpp:141] [CDBWrapper] Opened LevelDB successfully 
297 node0 2021-09-07T13:57:19.618900Z [init] [dbwrapper.cpp:166] [CDBWrapper] Using obfuscation key for /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest/blocks/index: 0000000000000000 
298 node0 2021-09-07T13:57:19.632098Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37248 
299 node0 2021-09-07T13:57:19.638342Z [httpworker.0] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
300 node0 2021-09-07T13:57:20.104391Z [init] [validation.cpp:3765] [LoadBlockIndexDB] LoadBlockIndexDB: last block file = 0 
301 node0 2021-09-07T13:57:20.120763Z [init] [validation.cpp:3769] [LoadBlockIndexDB] LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=0, size=0, heights=0...0, time=1970-01-01...1970-01-01) 
302 node0 2021-09-07T13:57:20.146437Z [init] [validation.cpp:3780] [LoadBlockIndexDB] Checking all blk files are present... 
303 node0 2021-09-07T13:57:20.147555Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37252 
304 node0 2021-09-07T13:57:20.162222Z [httpworker.3] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
305 node0 2021-09-07T13:57:20.279115Z [init] [validation.cpp:4116] [LoadBlockIndex] Initializing databases... 
306 node0 2021-09-07T13:57:20.416546Z [init] [flatfile.cpp:69] [Allocate] Pre-allocating up to position 0x1000000 in blk00000.dat 
307 node0 2021-09-07T13:57:20.510269Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37256 
308 node0 2021-09-07T13:57:20.600687Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
309 node0 2021-09-07T13:57:20.624614Z [init] [dbwrapper.cpp:137] [CDBWrapper] Opening LevelDB in /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest/chainstate 
310 node0 2021-09-07T13:57:20.757770Z [init] [dbwrapper.cpp:141] [CDBWrapper] Opened LevelDB successfully 
311 node0 2021-09-07T13:57:20.866792Z [init] [dbwrapper.cpp:163] [CDBWrapper] Wrote new obfuscate key for /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest/chainstate: 9831a575612aa084 
312 node0 2021-09-07T13:57:20.873942Z [init] [dbwrapper.cpp:166] [CDBWrapper] Using obfuscation key for /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest/chainstate: 9831a575612aa084 
313 node0 2021-09-07T13:57:21.279722Z [init] [init.cpp:1519] [AppInitMain]  block index            4256ms 
314 node0 2021-09-07T13:57:21.743837Z [loadblk] [util/thread.cpp:17] [TraceThread] loadblk thread start 
315 node1 2021-09-07T13:57:21.797508Z [init] [httpserver.cpp:180] [InitHTTPAllowList] Allowing HTTP connections from: 127.0.0.0/8 ::1/128 
316 node0 2021-09-07T13:57:21.862132Z [loadblk] [validation.cpp:2367] [ConnectTip]   - Load block from disk: 68.23ms [0.07s] 
317 node0 2021-09-07T13:57:21.975736Z [loadblk] [validationinterface.cpp:248] [BlockChecked] BlockChecked: block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 state=Valid 
318 node0 2021-09-07T13:57:22.038696Z [loadblk] [validation.cpp:2379] [ConnectTip]   - Connect total: 183.08ms [0.18s (183.08ms/blk)] 
319 node0 2021-09-07T13:57:22.066766Z [loadblk] [validation.cpp:2384] [ConnectTip]   - Flush: 31.90ms [0.03s (31.90ms/blk)] 
320 node0 2021-09-07T13:57:22.169693Z [loadblk] [validation.cpp:2390] [ConnectTip]   - Writing chainstate: 61.07ms [0.06s (61.07ms/blk)] 
321 node0 2021-09-07T13:57:22.420105Z [loadblk] [validation.cpp:2224] [UpdateTip] UpdateTip: new best=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 height=0 version=0x00000001 log2_work=1.000000 tx=1 date='2011-02-02T23:16:42Z' progress=1.000000 cache=0.0MiB(0txo) 
322 node0 2021-09-07T13:57:22.457718Z [loadblk] [validation.cpp:2401] [ConnectTip]   - Connect postprocess: 333.39ms [0.33s (333.39ms/blk)] 
323 node0 2021-09-07T13:57:22.509004Z [loadblk] [validation.cpp:2402] [ConnectTip] - Connect block: 677.67ms [0.68s (677.67ms/blk)] 
324 node0 2021-09-07T13:57:22.561556Z [loadblk] [txmempool.cpp:691] [check] Checking mempool with 0 transactions and 0 inputs 
325 node0 2021-09-07T13:57:22.685999Z [loadblk] [validationinterface.cpp:224] [BlockConnected] Enqueuing BlockConnected: block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 block height=0 
326 node0 2021-09-07T13:57:22.710758Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37260 
327 node0 2021-09-07T13:57:22.726058Z [scheduler] [validationinterface.cpp:224] [operator()] BlockConnected: block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 block height=0 
328 node0 2021-09-07T13:57:22.805888Z [httpworker.2] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
329 node0 2021-09-07T13:57:22.877361Z [loadblk] [validationinterface.cpp:196] [UpdatedBlockTip] Enqueuing UpdatedBlockTip: new block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 fork block hash=null (in IBD=true) 
330 node0 2021-09-07T13:57:23.127233Z [init] [init.cpp:1661] [AppInitMain] block tree size = 1 
331 node0 2021-09-07T13:57:23.130210Z [init] [init.cpp:1673] [AppInitMain] nBestHeight = 0 
332 node0 2021-09-07T13:57:23.327826Z [init] [net.cpp:2376] [BindListenPort] Bound to 127.0.0.1:13592 
333 node0 2021-09-07T13:57:23.391577Z [scheduler] [validationinterface.cpp:196] [operator()] UpdatedBlockTip: new block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 fork block hash=null (in IBD=true) 
334 node1 2021-09-07T13:57:23.422606Z [init] [httpserver.cpp:316] [HTTPBindAddresses] Binding RPC on address ::1 port 18593 
335 node0 2021-09-07T13:57:23.551249Z [init] [net.cpp:2373] [BindListenPort] Unable to bind to 127.0.0.1:18445 on this computer. Bitcoin Core is probably already running. 
336 node1 2021-09-07T13:57:23.626397Z [init] [httpserver.cpp:346] [libevent_log_cb] libevent: getaddrinfo: address family for nodename not supported 
337 node0 2021-09-07T13:57:23.643950Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading P2P addresses… 
338 node1 2021-09-07T13:57:23.665530Z [init] [httpserver.cpp:325] [HTTPBindAddresses] Binding RPC on address ::1 port 18593 failed. 
339 node1 2021-09-07T13:57:23.669433Z [init] [httpserver.cpp:316] [HTTPBindAddresses] Binding RPC on address 127.0.0.1 port 18593 
340 node0 2021-09-07T13:57:23.691027Z [init] [addrdb.cpp:174] [DeserializeFileDB] Missing or invalid file /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest/peers.dat 
341 node1 2021-09-07T13:57:23.808986Z [init] [httpserver.cpp:391] [InitHTTPServer] Initialized HTTP server 
342 node0 2021-09-07T13:57:23.832718Z [init] [net.cpp:2545] [Start] Recreating peers.dat 
343 node1 2021-09-07T13:57:23.832916Z [init] [httpserver.cpp:393] [InitHTTPServer] HTTP: creating work queue of depth 16 
344 node1 2021-09-07T13:57:23.888004Z [init] [rpc/server.cpp:292] [StartRPC] Starting RPC 
345 node0 2021-09-07T13:57:23.912846Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37266 
346 node0 2021-09-07T13:57:23.918825Z [loadblk] [validation.cpp:4496] [LoadMempool] Failed to open mempool file from disk. Continuing anyway. 
347 node0 2021-09-07T13:57:23.927562Z [loadblk] [util/thread.cpp:19] [TraceThread] loadblk thread exit 
348 node0 2021-09-07T13:57:24.229740Z [httpworker.0] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
349 node1 2021-09-07T13:57:24.241799Z [init] [httprpc.cpp:294] [StartHTTPRPC] Starting HTTP RPC server 
350 node0 2021-09-07T13:57:24.308306Z [init] [net.cpp:1767] [DumpAddresses] Flushed 0 addresses to peers.dat  417ms 
351 node1 2021-09-07T13:57:24.334791Z [init] [httprpc.cpp:246] [InitRPCAuthentication] Using random cookie authentication. 
352 node0 2021-09-07T13:57:24.343752Z [init] [noui.cpp:56] [noui_InitMessage] init message: Starting network threads… 
353 node1 2021-09-07T13:57:24.559539Z [init] [rpc/request.cpp:101] [GenerateAuthCookie] Generated RPC authentication cookie /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node1/regtest/.cookie 
354 node1 2021-09-07T13:57:24.681570Z [init] [httpserver.cpp:635] [RegisterHTTPHandler] Registering HTTP handler for / (exactmatch 1) 
355 node1 2021-09-07T13:57:24.735133Z [init] [httpserver.cpp:635] [RegisterHTTPHandler] Registering HTTP handler for /wallet/ (exactmatch 0) 
356 node1 2021-09-07T13:57:24.771386Z [init] [httpserver.cpp:421] [StartHTTPServer] Starting HTTP server 
357 node1 2021-09-07T13:57:24.800696Z [init] [httpserver.cpp:423] [StartHTTPServer] HTTP: starting 4 worker threads 
358 node0 2021-09-07T13:57:24.874591Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37274 
359 node0 2021-09-07T13:57:24.875615Z [httpworker.3] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
360 node0 2021-09-07T13:57:24.885237Z [net] [util/thread.cpp:17] [TraceThread] net thread start 
361 node0 2021-09-07T13:57:24.958358Z [init] [net.cpp:2589] [Start] DNS seeding disabled 
362 node0 2021-09-07T13:57:25.563751Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37278 
363 node0 2021-09-07T13:57:25.565539Z [addcon] [util/thread.cpp:17] [TraceThread] addcon thread start 
364 node1 2021-09-07T13:57:25.642169Z [http] [httpserver.cpp:282] [ThreadHTTP] Entering http event loop 
365 node0 2021-09-07T13:57:27.111865Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
366 node0 2021-09-07T13:57:27.151684Z [init] [noui.cpp:56] [noui_InitMessage] init message: Done loading 
367 node0 2021-09-07T13:57:27.304194Z [msghand] [util/thread.cpp:17] [TraceThread] msghand thread start 
368 node0 2021-09-07T13:57:27.568758Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37290 
369 node0 2021-09-07T13:57:27.570382Z [httpworker.2] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
370 node1 2021-09-07T13:57:27.699964Z [init] [wallet/load.cpp:40] [VerifyWallets] Using wallet directory /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node1/regtest/wallets 
371 node0 2021-09-07T13:57:27.751237Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37290 
372 node0 2021-09-07T13:57:27.752990Z [httpworker.0] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getmempoolinfo user=__cookie__ 
373 node1 2021-09-07T13:57:27.862732Z [init] [noui.cpp:56] [noui_InitMessage] init message: Verifying wallet(s)… 
374 test  2021-09-07T13:57:28.202000Z TestFramework.node0 (DEBUG): RPC successfully started 
375 node1 2021-09-07T13:57:29.091523Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading banlist… 
376 node1 2021-09-07T13:57:29.113932Z [init] [banman.cpp:27] [BanMan] Recreating the banlist database 
377 node1 2021-09-07T13:57:29.724503Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:35146 
378 node1 2021-09-07T13:57:29.827696Z [httpworker.0] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
379 node1 2021-09-07T13:57:29.977769Z [init] [banman.cpp:54] [DumpBanlist] Flushed 0 banned node addresses/subnets to disk  824ms 
380 node1 2021-09-07T13:57:30.055667Z [init] [net.cpp:1796] [SetTryNewOutboundPeer] net: setting try another outbound peer=false 
381 node1 2021-09-07T13:57:30.122550Z [init] [net.cpp:2443] [SetNetworkActive] SetNetworkActive: true 
382 node1 2021-09-07T13:57:30.284579Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:35156 
383 node1 2021-09-07T13:57:30.295812Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
384 node1 2021-09-07T13:57:30.301008Z [init] [policy/fees.cpp:530] [CBlockPolicyEstimator] Failed to read fee estimates from /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node1/regtest/fee_estimates.dat. Continue anyway. 
385 node1 2021-09-07T13:57:30.430442Z [init] [init.cpp:1294] [AppInitMain] Using /16 prefix for IP bucketing 
386 node1 2021-09-07T13:57:30.438784Z [init] [init.cpp:1330] [AppInitMain] Cache configuration: 
387 node1 2021-09-07T13:57:30.465210Z [init] [init.cpp:1331] [AppInitMain] * Using 2.0 MiB for block index database 
388 node1 2021-09-07T13:57:30.473203Z [init] [init.cpp:1339] [AppInitMain] * Using 8.0 MiB for chain state database 
389 node1 2021-09-07T13:57:30.498934Z [init] [init.cpp:1340] [AppInitMain] * Using 440.0 MiB for in-memory UTXO set (plus up to 286.1 MiB of unused mempool space) 
390 node1 2021-09-07T13:57:30.502418Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading block index… 
391 node1 2021-09-07T13:57:30.542945Z [init] [validation.cpp:4693] [InitializeChainstate] Switching active chainstate to Chainstate [ibd] @ height -1 (null) 
392 node1 2021-09-07T13:57:30.676789Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:35162 
393 node1 2021-09-07T13:57:31.068678Z [init] [dbwrapper.cpp:137] [CDBWrapper] Opening LevelDB in /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node1/regtest/blocks/index 
394 node1 2021-09-07T13:57:31.175371Z [httpworker.2] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
395 node1 2021-09-07T13:57:31.441259Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:35172 
396 node1 2021-09-07T13:57:31.442924Z [httpworker.3] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
397 node1 2021-09-07T13:57:31.738188Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:35176 
398 node1 2021-09-07T13:57:31.825641Z [httpworker.0] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
399 node1 2021-09-07T13:57:31.970139Z [init] [dbwrapper.cpp:141] [CDBWrapper] Opened LevelDB successfully 
400 node1 2021-09-07T13:57:32.067722Z [init] [dbwrapper.cpp:166] [CDBWrapper] Using obfuscation key for /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node1/regtest/blocks/index: 0000000000000000 
401 node1 2021-09-07T13:57:32.148264Z [init] [validation.cpp:3765] [LoadBlockIndexDB] LoadBlockIndexDB: last block file = 0 
402 node1 2021-09-07T13:57:32.197162Z [init] [validation.cpp:3769] [LoadBlockIndexDB] LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=0, size=0, heights=0...0, time=1970-01-01...1970-01-01) 
403 node1 2021-09-07T13:57:32.210105Z [init] [validation.cpp:3780] [LoadBlockIndexDB] Checking all blk files are present... 
404 node1 2021-09-07T13:57:32.232674Z [init] [validation.cpp:4116] [LoadBlockIndex] Initializing databases... 
405 node1 2021-09-07T13:57:32.273238Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:35180 
406 node1 2021-09-07T13:57:32.275911Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
407 node1 2021-09-07T13:57:32.288601Z [init] [flatfile.cpp:69] [Allocate] Pre-allocating up to position 0x1000000 in blk00000.dat 
408 node1 2021-09-07T13:57:32.534851Z [init] [dbwrapper.cpp:137] [CDBWrapper] Opening LevelDB in /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node1/regtest/chainstate 
409 node1 2021-09-07T13:57:32.568685Z [init] [dbwrapper.cpp:141] [CDBWrapper] Opened LevelDB successfully 
410 node0 2021-09-07T13:57:32.616713Z [scheduler] [random.cpp:523] [SeedPeriodic] Feeding 17283 bytes of dynamic environment data into RNG 
411 node1 2021-09-07T13:57:32.647204Z [init] [dbwrapper.cpp:163] [CDBWrapper] Wrote new obfuscate key for /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node1/regtest/chainstate: 8a10a9d90b4fb6d7 
412 node1 2021-09-07T13:57:32.649261Z [init] [dbwrapper.cpp:166] [CDBWrapper] Using obfuscation key for /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node1/regtest/chainstate: 8a10a9d90b4fb6d7 
413 node1 2021-09-07T13:57:32.688104Z [init] [init.cpp:1519] [AppInitMain]  block index            2181ms 
414 node1 2021-09-07T13:57:32.833181Z [loadblk] [util/thread.cpp:17] [TraceThread] loadblk thread start 
415 node1 2021-09-07T13:57:32.977798Z [loadblk] [validation.cpp:2367] [ConnectTip]   - Load block from disk: 55.28ms [0.06s] 
416 node1 2021-09-07T13:57:33.093695Z [loadblk] [validationinterface.cpp:248] [BlockChecked] BlockChecked: block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 state=Valid 
417 node1 2021-09-07T13:57:33.147168Z [loadblk] [validation.cpp:2379] [ConnectTip]   - Connect total: 212.62ms [0.21s (212.62ms/blk)] 
418 node1 2021-09-07T13:57:33.150760Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:35186 
419 node1 2021-09-07T13:57:33.175520Z [loadblk] [validation.cpp:2384] [ConnectTip]   - Flush: 47.14ms [0.05s (47.14ms/blk)] 
420 node1 2021-09-07T13:57:33.225933Z [loadblk] [validation.cpp:2390] [ConnectTip]   - Writing chainstate: 41.99ms [0.04s (41.99ms/blk)] 
421 node1 2021-09-07T13:57:33.270161Z [loadblk] [validation.cpp:2224] [UpdateTip] UpdateTip: new best=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 height=0 version=0x00000001 log2_work=1.000000 tx=1 date='2011-02-02T23:16:42Z' progress=1.000000 cache=0.0MiB(0txo) 
422 node1 2021-09-07T13:57:33.298504Z [loadblk] [validation.cpp:2401] [ConnectTip]   - Connect postprocess: 79.31ms [0.08s (79.31ms/blk)] 
423 node1 2021-09-07T13:57:33.300964Z [loadblk] [validation.cpp:2402] [ConnectTip] - Connect block: 436.35ms [0.44s (436.35ms/blk)] 
424 node1 2021-09-07T13:57:33.325638Z [loadblk] [txmempool.cpp:691] [check] Checking mempool with 0 transactions and 0 inputs 
425 node1 2021-09-07T13:57:33.339820Z [loadblk] [validationinterface.cpp:224] [BlockConnected] Enqueuing BlockConnected: block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 block height=0 
426 node1 2021-09-07T13:57:33.378950Z [loadblk] [validationinterface.cpp:196] [UpdatedBlockTip] Enqueuing UpdatedBlockTip: new block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 fork block hash=null (in IBD=true) 
427 node1 2021-09-07T13:57:33.548166Z [init] [init.cpp:1661] [AppInitMain] block tree size = 1 
428 node1 2021-09-07T13:57:33.556792Z [init] [init.cpp:1673] [AppInitMain] nBestHeight = 0 
429 node1 2021-09-07T13:57:33.885723Z [init] [net.cpp:2376] [BindListenPort] Bound to 127.0.0.1:13593 
430 node1 2021-09-07T13:57:33.972750Z [init] [net.cpp:2373] [BindListenPort] Unable to bind to 127.0.0.1:18445 on this computer. Bitcoin Core is probably already running. 
431 node1 2021-09-07T13:57:33.999124Z [init] [noui.cpp:56] [noui_InitMessage] init message: Loading P2P addresses… 
432 node1 2021-09-07T13:57:34.052180Z [init] [addrdb.cpp:174] [DeserializeFileDB] Missing or invalid file /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node1/regtest/peers.dat 
433 node1 2021-09-07T13:57:34.074013Z [init] [net.cpp:2545] [Start] Recreating peers.dat 
434 node1 2021-09-07T13:57:34.212576Z [scheduler] [validationinterface.cpp:224] [operator()] BlockConnected: block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 block height=0 
435 node1 2021-09-07T13:57:34.398569Z [init] [net.cpp:1767] [DumpAddresses] Flushed 0 addresses to peers.dat  314ms 
436 node1 2021-09-07T13:57:34.405508Z [init] [noui.cpp:56] [noui_InitMessage] init message: Starting network threads… 
437 node1 2021-09-07T13:57:34.632975Z [init] [net.cpp:2589] [Start] DNS seeding disabled 
438 node1 2021-09-07T13:57:34.962240Z [net] [util/thread.cpp:17] [TraceThread] net thread start 
439 node1 2021-09-07T13:57:34.978698Z [msghand] [util/thread.cpp:17] [TraceThread] msghand thread start 
440 node1 2021-09-07T13:57:34.987257Z [init] [noui.cpp:56] [noui_InitMessage] init message: Done loading 
441 node1 2021-09-07T13:57:35.033508Z [addcon] [util/thread.cpp:17] [TraceThread] addcon thread start 
442 node1 2021-09-07T13:57:35.062112Z [httpworker.2] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getblockcount user=__cookie__ 
443 node1 2021-09-07T13:57:35.137026Z [loadblk] [validation.cpp:4496] [LoadMempool] Failed to open mempool file from disk. Continuing anyway. 
444 node1 2021-09-07T13:57:35.143933Z [loadblk] [util/thread.cpp:19] [TraceThread] loadblk thread exit 
445 node1 2021-09-07T13:57:35.187840Z [scheduler] [validationinterface.cpp:196] [operator()] UpdatedBlockTip: new block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 fork block hash=null (in IBD=true) 
446 node1 2021-09-07T13:57:35.210357Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:35186 
447 node1 2021-09-07T13:57:35.216239Z [httpworker.3] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getmempoolinfo user=__cookie__ 
448 test  2021-09-07T13:57:35.249000Z TestFramework.node1 (DEBUG): RPC successfully started 
449 node0 2021-09-07T13:57:35.253602Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37290 
450 node0 2021-09-07T13:57:35.267245Z [httpworker.3] [rpc/request.cpp:174] [parse] ThreadRPCServer method=createwallet user=__cookie__ 
451 node0 2021-09-07T13:57:35.342394Z [httpworker.3] [wallet/bdb.cpp:263] [Verify] Using BerkeleyDB version Berkeley DB 5.3.28: (September  9, 2013) 
452 node0 2021-09-07T13:57:35.344129Z [httpworker.3] [wallet/bdb.cpp:264] [Verify] Using wallet /tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest/wallets/wallet.dat 
453 node0 2021-09-07T13:57:35.358589Z [httpworker.3] [wallet/bdb.cpp:143] [Open] BerkeleyEnvironment::Open: LogDir=/tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest/wallets/database ErrorFile=/tmp/test_runner_₿_🏃_20210907_065517/wallet_hd_216/node0/regtest/wallets/db.log 
454 node0 2021-09-07T13:57:35.712488Z [httpworker.3] [noui.cpp:56] [noui_InitMessage] init message: Loading wallet… 
455 node0 2021-09-07T13:57:36.996061Z [httpworker.3] [wallet/wallet.h:826] [WalletLogPrintf] [default wallet] Wallet File Version = 10500 
456 node0 2021-09-07T13:57:37.006487Z [httpworker.3] [wallet/wallet.h:826] [WalletLogPrintf] [default wallet] Keys: 0 plaintext, 0 encrypted, 0 w/ metadata, 0 total. Unknown wallet records: 0 
457 node0 2021-09-07T13:57:37.915740Z [httpworker.3] [wallet/scriptpubkeyman.h:244] [WalletLogPrintf] [default wallet] keypool added 2 keys (1 internal), size=2 (1 internal) 
458 node0 2021-09-07T13:57:37.929966Z [httpworker.3] [wallet/scriptpubkeyman.h:244] [WalletLogPrintf] [default wallet] LegacyScriptPubKeyMan::NewKeyPool rewrote keypool 
459 node0 2021-09-07T13:57:38.018919Z [httpworker.3] [wallet/wallet.h:826] [WalletLogPrintf] [default wallet] Wallet completed loading in            2298ms 
460 node0 2021-09-07T13:57:38.052556Z [httpworker.3] [wallet/wallet.h:826] [WalletLogPrintf] [default wallet] setKeyPool.size() = 2 
461 node0 2021-09-07T13:57:38.057586Z [httpworker.3] [wallet/wallet.h:826] [WalletLogPrintf] [default wallet] mapWallet.size() = 0 
462 node0 2021-09-07T13:57:38.059772Z [httpworker.3] [wallet/wallet.h:826] [WalletLogPrintf] [default wallet] m_address_book.size() = 0 
463 node0 2021-09-07T13:57:38.133420Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37290 
464 node0 2021-09-07T13:57:38.135066Z [httpworker.1] [rpc/request.cpp:174] [parse] ThreadRPCServer method=getwalletinfo user=__cookie__ 
465 node0 2021-09-07T13:57:38.287181Z [http] [httpserver.cpp:236] [http_request_cb] Received a POST request for / from 127.0.0.1:37290 
466 node0 2021-09-07T13:57:38.290967Z [httpworker.2] [rpc/request.cpp:174] [parse] ThreadRPCServer method=importprivkey user=__cookie__ 
467 node0 2021-09-07T13:57:38.691672Z [httpworker.2] [wallet/scriptpubkeyman.h:244] [WalletLogPrintf] [default wallet] Already have script 00142b4569203694fc997e13f2c0a1383b9e16c77a0d, skipping 
468 node0 2021-09-07T13:57:38.721144Z [httpworker.2] [wallet/wallet.h:826] [WalletLogPrintf] [default wallet] RescanFromTime: Rescanning last 1 blocks 
469 node0 2021-09-07T13:57:38.736585Z [httpworker.2] [wallet/wallet.h:826] [WalletLogPrintf] [default wallet] Rescan started from block 0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206... 
470 test  2021-09-07T13:57:39.289000Z TestFramework (ERROR): Unexpected exception caught during testing 
471                                   Traceback (most recent call last):
472                                     File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 108, in _request
473                                       return self._get_response()
474                                     File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 168, in _get_response
475                                       http_response = self.__conn.getresponse()
476                                     File "/usr/lib/python3.8/http/client.py", line 1344, in getresponse
477                                       response.begin()
478                                     File "/usr/lib/python3.8/http/client.py", line 307, in begin
479                                       version, status, reason = self._read_status()
480                                     File "/usr/lib/python3.8/http/client.py", line 276, in _read_status
481                                       raise RemoteDisconnected("Remote end closed connection without"
482                                   http.client.RemoteDisconnected: Remote end closed connection without response
483                                   During handling of the above exception, another exception occurred:
484                                   Traceback (most recent call last):
485                                     File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 130, in main
486                                       self.setup()
487                                     File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 285, in setup
488                                       self.setup_network()
489                                     File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 379, in setup_network
490                                       self.setup_nodes()
491                                     File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 406, in setup_nodes
492                                       self.import_deterministic_coinbase_privkeys()
493                                     File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 423, in import_deterministic_coinbase_privkeys
494                                       self.init_wallet(i)
495                                     File "/root/bitcoin/test/functional/test_framework/test_framework.py", line 431, in init_wallet
496                                       n.importprivkey(privkey=n.get_deterministic_priv_key().key, label='coinbase')
497                                     File "/root/bitcoin/test/functional/test_framework/test_node.py", line 689, in importprivkey
498                                       return self.__getattr__('importprivkey')(privkey, label, rescan)
499                                     File "/root/bitcoin/test/functional/test_framework/coverage.py", line 49, in __call__
500                                       return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
501                                     File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 144, in __call__
502                                       response, status = self._request('POST', self.__url.path, postdata.encode('utf-8'))
503                                     File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 113, in _request
504                                       self.__conn.request(method, path, postdata, headers)
505                                     File "/usr/lib/python3.8/http/client.py", line 1252, in request
506                                       self._send_request(method, url, body, headers, encode_chunked)
507                                     File "/usr/lib/python3.8/http/client.py", line 1298, in _send_request
508                                       self.endheaders(body, encode_chunked=encode_chunked)
509                                     File "/usr/lib/python3.8/http/client.py", line 1247, in endheaders
510                                       self._send_output(message_body, encode_chunked=encode_chunked)
511                                     File "/usr/lib/python3.8/http/client.py", line 1007, in _send_output
512                                       self.send(msg)
513                                     File "/usr/lib/python3.8/http/client.py", line 947, in send
514                                       self.connect()
515                                     File "/usr/lib/python3.8/http/client.py", line 918, in connect
516                                       self.sock = self._create_connection(
517                                     File "/usr/lib/python3.8/socket.py", line 808, in create_connection
518                                       raise err
519                                     File "/usr/lib/python3.8/socket.py", line 796, in create_connection
520                                       sock.connect(sa)
521                                   ConnectionRefusedError: [Errno 111] Connection refused
522 test  2021-09-07T13:57:39.295000Z TestFramework (DEBUG): Closing down network thread 
523 test  2021-09-07T13:57:39.347000Z TestFramework (INFO): Stopping nodes 
524 test  2021-09-07T13:57:39.347000Z TestFramework.node0 (DEBUG): Stopping node 
525 test  2021-09-07T13:57:39.348000Z TestFramework.node0 (ERROR): Unable to stop node. 
526                                   Traceback (most recent call last):
527                                     File "/root/bitcoin/test/functional/test_framework/test_node.py", line 323, in stop_node
528                                       self.stop(wait=wait)
529                                     File "/root/bitcoin/test/functional/test_framework/coverage.py", line 49, in __call__
530                                       return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
531                                     File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 144, in __call__
532                                       response, status = self._request('POST', self.__url.path, postdata.encode('utf-8'))
533                                     File "/root/bitcoin/test/functional/test_framework/authproxy.py", line 107, in _request
534                                       self.__conn.request(method, path, postdata, headers)
535                                     File "/usr/lib/python3.8/http/client.py", line 1252, in request
536                                       self._send_request(method, url, body, headers, encode_chunked)
537                                     File "/usr/lib/python3.8/http/client.py", line 1263, in _send_request
538                                       self.putrequest(method, url, **skips)
539                                     File "/usr/lib/python3.8/http/client.py", line 1089, in putrequest
540                                       raise CannotSendRequest(self.__state)
541                                   http.client.CannotSendRequest: Request-sent
542
543 node0 stderr ==48855== Thread 13 b-httpworker.2:
544==48855== Conditional jump or move depends on uninitialised value(s)
545==48855==    at 0x5BFDBB: CWallet::ScanForWalletTransactions(uint256 const&, int, std::optional<int>, WalletRescanReserver const&, bool) (wallet.cpp:1653)
546==48855==    by 0x5C07CB: CWallet::RescanFromTime(long, WalletRescanReserver const&, bool) (wallet.cpp:1556)
547==48855==    by 0x60E5ED: RescanWallet(CWallet&, WalletRescanReserver const&, long, bool) (rpcdump.cpp:85)
548==48855==    by 0x628253: importprivkey()::{lambda(RPCHelpMan const&, JSONRPCRequest const&)#1}::operator()(RPCHelpMan const&, JSONRPCRequest const&) const [clone .isra.0] (rpcdump.cpp:187)
549==48855==    by 0x628554: std::_Function_handler<UniValue (RPCHelpMan const&, JSONRPCRequest const&), importprivkey()::{lambda(RPCHelpMan const&, JSONRPCRequest const&)#1}>::_M_invoke(std::_Any_data const&, RPCHelpMan const&, JSONRPCRequest const&) (std_function.h:286)
550==48855==    by 0x692115: operator() (std_function.h:688)
551==48855==    by 0x692115: RPCHelpMan::HandleRequest(JSONRPCRequest const&) const (util.cpp:575)
552==48855==    by 0x3471CB: CRPCCommand::CRPCCommand(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, RPCHelpMan (*)())::{lambda(JSONRPCRequest const&, UniValue&, bool)#1}::operator()(JSONRPCRequest const&, UniValue&, bool) const (server.h:110)
553==48855==    by 0x4E417B: wallet::(anonymous namespace)::WalletClientImpl::registerRpcs()::{lambda(JSONRPCRequest const&, UniValue&, bool)#1}::operator()(JSONRPCRequest const&, UniValue&, bool) const (std_function.h:688)
554==48855==    by 0x2BF324: operator() (std_function.h:688)
555==48855==    by 0x2BF324: operator() (interfaces.cpp:397)
556==48855==    by 0x2BF324: std::_Function_handler<bool (JSONRPCRequest const&, UniValue&, bool), node::(anonymous namespace)::RpcHandlerImpl::RpcHandlerImpl(CRPCCommand const&)::{lambda(JSONRPCRequest const&, UniValue&, bool)#1}>::_M_invoke(std::_Any_data const&, JSONRPCRequest const&, UniValue&, bool&&) (std_function.h:285)
557==48855==    by 0x3D9396: operator() (std_function.h:688)
558==48855==    by 0x3D9396: ExecuteCommand(CRPCCommand const&, JSONRPCRequest const&, UniValue&, bool) (server.cpp:480)
559==48855==    by 0x3D9FB6: ExecuteCommands(std::vector<CRPCCommand const*, std::allocator<CRPCCommand const*> > const&, JSONRPCRequest const&, UniValue&) [clone .constprop.0] (server.cpp:444)
560==48855==    by 0x3DA55D: CRPCTable::execute(JSONRPCRequest const&) const (server.cpp:464)
561==48855== 
562{
563   <insert_a_suppression_name_here>
564   Memcheck:Cond
565   fun:_ZN7CWallet25ScanForWalletTransactionsERK7uint256iSt8optionalIiERK20WalletRescanReserverb
566   fun:_ZN7CWallet14RescanFromTimeElRK20WalletRescanReserverb
567   fun:_ZL12RescanWalletR7CWalletRK20WalletRescanReserverlb
568   fun:_ZZ13importprivkeyvENKUlRK10RPCHelpManRK14JSONRPCRequestE_clES1_S4_.isra.0
569   fun:_ZNSt17_Function_handlerIF8UniValueRK10RPCHelpManRK14JSONRPCRequestEZ13importprivkeyvEUlS3_S6_E_E9_M_invokeERKSt9_Any_dataS3_S6_
570   fun:operator()
571   fun:_ZNK10RPCHelpMan13HandleRequestERK14JSONRPCRequest
572   fun:_ZZN11CRPCCommandC4ENSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEPF10RPCHelpManvEENKUlRK14JSONRPCRequestR8UniValuebE_clESB_SD_b
573   fun:_ZZN6wallet12_GLOBAL__N_116WalletClientImpl12registerRpcsEvENKUlRK14JSONRPCRequestR8UniValuebE_clES4_S6_b
574   fun:operator()
575   fun:operator()
576   fun:_ZNSt17_Function_handlerIFbRK14JSONRPCRequestR8UniValuebEZN4node12_GLOBAL__N_114RpcHandlerImplC4ERK11CRPCCommandEUlS2_S4_bE_E9_M_invokeERKSt9_Any_dataS2_S4_Ob
577   fun:operator()
578   fun:_ZL14ExecuteCommandRK11CRPCCommandRK14JSONRPCRequestR8UniValueb
579   fun:_ZL15ExecuteCommandsRKSt6vectorIPK11CRPCCommandSaIS2_EERK14JSONRPCRequestR8UniValue.constprop.0
580   fun:_ZNK9CRPCTable7executeERK14JSONRPCRequest
581}
582==48855== 
583==48855== Exit program on first error (--exit-on-first-error=yes)

MarcoFalke commented at 12:02 pm on September 8, 2021: member

Hmm, that looks like a valgrind false positive. You can work around it by adding a suppression to contrib/valgrind.supp.

agroce commented at 6:54 pm on September 14, 2021: contributor

Any chance of anyone expert in tx validation or the testing thereof getting a chance to look at the mutants? They are pretty easy to understand if you know context, I would guess, in many cases.

agroce commented at 7:30 pm on October 11, 2021: contributor

@practicalswift and @MarcoFalke a draft of the report on my efforts, as an ICSE SEIP paper (https://conf.researchr.org/track/icse-2021/icse-2021-Software-Engineering-in-Practice) is up here:

https://github.com/agroce/icseseip21/blob/master/currentdraft.pdf

Your comments if there are any glaring inaccuracies or points that you’d like to see elaborated on, would be VERY welcome. Our deadline (there are other authors, doing the mutation & coverage analysis with me, not yet added in to the author list) is end of this week, Friday the 15th

MarcoFalke commented at 9:41 am on October 13, 2021: member

Thanks for the writeup. Now I have something to point to if someone asks about the state of fuzzing in Bitcoin Core.

Some minor comments:

ran the first mutation analysis of Bitcoin Core code

While the efforts aren’t documented, this has been done numerous times before. Especially for consensus code. Though, you might have been the first one to run mutation testing against the fuzz tests.

At the time, the basic strategy was to run libFuzzer on each of these for 100,000 iterations.

This is the default in the test runner. Though, personally I am running a modified version of the test runner. I believe that others (Evan from Chaincode or #20752) are also running with a modified version. Obviously, 100k iterations for serious fuzzing is not enough, so your claim still holds in essence. Edit: nvm, just read the next section, Evan seems to have adjusted it based on your feedback.

The most obvious solution when fuzzer A

I think some readers might not be able to infer the meaning of “fuzzer” based on the context. Generally, it can mean “fuzz target” or “fuzz engine”, depending on context. Might be clearer to just use “fuzz engine” here. See also https://github.com/google/fuzzing/blob/master/docs/glossary.md#fuzzer This applies throughout the paper.

Building a one-off verson

version

Also in this section “Ensemble fuzzing”, I believe this is already done by us. I read section 2.3 of the reference [5] you linked to, and the authors seem to be misunderstanding how OSS-Fuzz works. OSS-Fuzz doesn’t run the same instance of libFuzzer on all VMs. Instead it runs different fuzzing engines (afl, honggfuzz, libFuzzer) with different compilation flags (32-bit, 64-bit), as well as sanitizers (msan, asan, ubsan). On my servers I am also running with different flags. Our fuzz inputs are already synced via the qa-assets repo, which serves as ensemble fuzzing. Maybe I am just misunderstanding, but some readers might benefit from a minor clarification/distinction here.

it simply generates an arbitrary string that will be parsed as a message type, a nondeter-ministic number of times

Hopefully our fuzzing is deterministic ;) Maybe you meant to write indeterminate or unlimited?

dynamic parser to use in-filght data

in-flight

and72.6% of branches

missing space

Firstly, bitcoin reached out to the first author to investigate the quality of their test suite

I wonder which language bitcoin spoke in ;)

we spent more time was spent

grammar

CONCLUSIONS

empty section?

agroce commented at 1:00 pm on October 13, 2021: contributor

“bitcoin reached out” – now “money talks” is literal!

agroce commented at 1:01 pm on October 13, 2021: contributor

Thanks a million! Yes, this is great info. Conclusions is always the last thing I write, but it’s never very exciting.

agroce commented at 1:16 pm on October 13, 2021: contributor

Good point that there is already a form of ensemble fuzzing going on. On-the-fly direction of the specific cross-seeds that a particular engine is missing adds value (I think, that’s my reading of the literature and some limited experiments of my own) but the basic thing is there via qa-assets.

By nondeterministic I mean “fuzzer chosen”; it’s a common use in testing lit, but yeah, it is easily mixed up with bad nondeterminism like test flakiness or threads. The field needs a new term.

agroce commented at 1:20 pm on October 13, 2021: contributor

The mutation section’s comparison part is under a lot of editing, we’ll probably add and subtract typos there until Friday :)

BTW, I want to add you all to the Acknowledgements, I have Jonas and Evan’s names – how would you, @MarcoFalke and @practicalswift, like to be credited? I assume “Marco Falke” but “Practical Swift” is probably not right!

sipa commented at 1:23 pm on October 13, 2021: member

I haven’t followed the entire discussion here, but in the libsecp256k1 code (implementation of ECDSA and related algorithms, subtreed into Bitcoin Core), (manual) mutation testing is occasionally done to find/verify the adequacy of included test vectors. I explained one (unexpected) result of this here: https://mobile.twitter.com/pwuille/status/1348835954396516353

agroce commented at 1:39 pm on October 13, 2021: contributor

@sipa – nice! I convinced Richard Hipp to mutate the code for SQLite years ago, and his main result was finding a small but nice opportunity for optimization. We’ve written a little about that in some work on automatic resource adaptation, with my former student Arpit Christi.

MarcoFalke commented at 2:42 pm on October 13, 2021: member

You can just credit me as “anonymous reviewer”, if you like

agroce commented at 3:54 pm on October 13, 2021: contributor

I’ll do that if that’s what you prefer; I bow to your wishes here, just want to ack the huge help you’ve been!

agroce commented at 12:40 pm on October 14, 2021: contributor

@MarcoFalke

While looking at all, this, I noticed https://marcofalke.github.io/btc_cov/total.coverage/src/consensus/tx_verify.cpp.gcov.html vs. https://marcofalke.github.io/btc_cov/fuzz.coverage/src/consensus/tx_verify.cpp.gcov.html

– same code, but different line counts and branch counts for unit/functional vs. fuzz coverage. Any idea what’s going on there?

MarcoFalke commented at 12:47 pm on October 14, 2021: member

Jup, one is compiled with gcc the other with clang. The only difference should be the order of branches and whether control statements are counted as a line.

agroce commented at 12:55 pm on October 14, 2021: contributor

Ah, makes sense. The annotated code is pretty easy to compare.

MarcoFalke commented at 5:02 pm on November 10, 2021: member

If the pdf is done, feel free to add a link to it to our fuzzing doc. It might offer newcomers an intro to our fuzzing.

Maybe we can also link to https://blog.regehr.org/archives/1687 as general guidelines?

agroce commented at 6:00 pm on November 10, 2021: contributor

John’s post is definitely a good overview of how devs can help make/keep the fuzzing solid. The pdf is “done” but in submission; it’ll likely get some useful input from reviewers, but since it’s not even blinded, I think a link would be a good idea. I’ll PR right now.

adamjonas commented at 0:40 am on August 2, 2022: member

Closing this based on lack of further comments and after the addition of https://github.com/bitcoin/bitcoin/pull/23482/.

adamjonas closed this on Aug 2, 2022

bitcoin locked this on Aug 2, 2023

fuzz: investigate test adequacy (unit and fuzz) via mutation testing #22690