From 6d7894c6c539c6970581ad6b71df263a216acc18 Mon Sep 17 00:00:00 2001 From: "Wladimir J. van der Laan" Date: Wed, 22 Jul 2020 18:04:51 +0200 Subject: [PATCH 1/8] Merge #19370: Static asserts for consistency of fee defaults 1554b54d47d7e24ce2491f57d24e56d38ceb7649 Static asserts for consistency of fee defaults. (Daniel Kraft) Pull request description: This adds `static_assert`'s that ensure that the default values given for fee levels in the wallet (minimum fee and incremental feerate increase) are at least as high as the corresponding levels configured in the core node policy. Since the core policy values are enforced by the network, it makes sense for the wallet to be conservative and above (or at least not below) this. ACKs for top commit: laanwj: code review ACK 1554b54d47d7e24ce2491f57d24e56d38ceb7649, these assumptions seem straightforward Tree-SHA512: 50e5adf082f467062334377f82a3ee75bcfd436afc65bd0eb33c8d0549d6d90fd1f48c31f60cabe523eb59be9efa8ae0879e9e09cd51ca9c1bd466631ce03cf4 --- src/wallet/test/wallet_tests.cpp | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/src/wallet/test/wallet_tests.cpp b/src/wallet/test/wallet_tests.cpp index 382235ef8002..eb9cd1919630 100644 --- a/src/wallet/test/wallet_tests.cpp +++ b/src/wallet/test/wallet_tests.cpp @@ -39,6 +39,11 @@ extern UniValue addmultisigaddress(const JSONRPCRequest& request); extern RecursiveMutex cs_wallets; +// Ensure that fee levels defined in the wallet are at least as high +// as the default levels for node policy. +static_assert(DEFAULT_TRANSACTION_MINFEE >= DEFAULT_MIN_RELAY_TX_FEE, "wallet minimum fee is smaller than default relay fee"); +static_assert(WALLET_INCREMENTAL_RELAY_FEE >= DEFAULT_INCREMENTAL_RELAY_FEE, "wallet incremental fee is smaller than default incremental relay fee"); + BOOST_FIXTURE_TEST_SUITE(wallet_tests, WalletTestingSetup) namespace { From c69474a72fee404254ea782b8ee5a359e2a8d331 Mon Sep 17 00:00:00 2001 From: fanquake Date: Wed, 22 Jul 2020 17:44:00 +0800 Subject: [PATCH 2/8] Merge #19562: test: Fix fuzzer compilation on macOS MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit c8992e89594a54edf283e4916f794475070b5114 test: Fix fuzzer compilation on macOS fixes #19557 (freenancial) Pull request description: fixes #19557 Before the fix: ``` ➜ bitcoin git:(fix-fuzzer-macos) make Making all in src CXX test/fuzz/addition_overflow-addition_overflow.o In file included from test/fuzz/addition_overflow.cpp:7: ./test/fuzz/util.h:335:13: error: no matching function for call to 'AdditionOverflow' if (AdditionOverflow((uint64_t)fuzzed_file->m_offset, random_bytes.size())) { ^~~~~~~~~~~~~~~~ ./test/fuzz/util.h:201:16: note: candidate template ignored: deduced conflicting types for parameter 'T' ('unsigned long long' vs. 'unsigned long') NODISCARD bool AdditionOverflow(const T i, const T j) noexcept ^ ./test/fuzz/util.h:346:13: error: no matching function for call to 'AdditionOverflow' if (AdditionOverflow(fuzzed_file->m_offset, n)) { ^~~~~~~~~~~~~~~~ ./test/fuzz/util.h:201:16: note: candidate template ignored: deduced conflicting types for parameter 'T' ('long long' vs. 'long') NODISCARD bool AdditionOverflow(const T i, const T j) noexcept ^ ``` After the fix: ``` ➜ bitcoin git:(fix-fuzzer-macos) ./configure --enable-fuzz --with-sanitizers=fuzzer,address,undefined CC=/usr/local/opt/llvm/bin/clang CXX=/usr/local/opt/llvm/bin/clang++ --disable-asm && make clean && make -j5 ... ... CXXLD test/fuzz/uint256_deserialize Making all in doc/man make[1]: Nothing to be done for `all'. make[1]: Nothing to be done for `all-am'. ``` ACKs for top commit: fanquake: ACK c8992e89594a54edf283e4916f794475070b5114 - tested that compiling works on macOS. MarcoFalke: review ACK c8992e89594a54edf283e4916f794475070b5114 Tree-SHA512: 965cdc61b30db0e2209c91b29f0d42de927a9a5b85e1e70f22d1452e0955f876726c7a8c1d1a5f448f12bf24eec3000802071cd4ae28d8605343fd43d174ca84 --- src/test/fuzz/util.h | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/test/fuzz/util.h b/src/test/fuzz/util.h index db0359aa8d3e..344125a0864c 100644 --- a/src/test/fuzz/util.h +++ b/src/test/fuzz/util.h @@ -409,7 +409,7 @@ class FuzzedFileProvider return 0; } std::memcpy(buf, random_bytes.data(), random_bytes.size()); - if (AdditionOverflow(static_cast(fuzzed_file->m_offset), random_bytes.size())) { + if (AdditionOverflow(fuzzed_file->m_offset, (int64_t)random_bytes.size())) { return fuzzed_file->m_fuzzed_data_provider.ConsumeBool() ? 0 : -1; } fuzzed_file->m_offset += random_bytes.size(); @@ -421,7 +421,7 @@ class FuzzedFileProvider FuzzedFileProvider* fuzzed_file = (FuzzedFileProvider*)cookie; SetFuzzedErrNo(fuzzed_file->m_fuzzed_data_provider); const ssize_t n = fuzzed_file->m_fuzzed_data_provider.ConsumeIntegralInRange(0, size); - if (AdditionOverflow(static_cast(fuzzed_file->m_offset), n)) { + if (AdditionOverflow(fuzzed_file->m_offset, (int64_t)n)) { return fuzzed_file->m_fuzzed_data_provider.ConsumeBool() ? 0 : -1; } fuzzed_file->m_offset += n; From edf178993599943b85efe4a2cb2fee57435290bd Mon Sep 17 00:00:00 2001 From: MarcoFalke Date: Wed, 24 Jun 2020 15:57:29 -0400 Subject: [PATCH 3/8] Merge #19272: net, test: invalid p2p messages and test framework improvements MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 56010f92564a94b0ca6c008c0e6f74a19fad4a2a test: hoist p2p values to test framework constants (Jon Atack) 75447f0893f9ad9bf83d182b301d139430d8de1c test: improve msg sends and p2p disconnections in p2p_invalid_messages (Jon Atack) 57960192a5362ff1a7b996995332535f4c2a25c3 test: refactor test_large_inv() into 3 tests with common method (Jon Atack) e2b21d8a597c536a8617408d43958bfe9f98a442 test: add p2p_invalid_messages logging (Jon Atack) 9fa494dc0969c61d5ef33708a08923cca19ce091 net: update misbehavior logging for oversized messages (Jon Atack) Pull request description: ...seen while reviewing #19264, #19252, #19304 and #19107: in `net_processing.cpp` - make the debug logging for oversized message size misbehavior the same for `addr`, `getdata`, `headers` and `inv` messages in `p2p_invalid_messages` - add missing logging - improve assertions/message sends, move cleanup disconnections outside the assertion scopes - split a slowish 3-part test into 3 order-independent tests - add a few p2p constants to the test framework ACKs for top commit: troygiorshev: reACK 56010f92564a94b0ca6c008c0e6f74a19fad4a2a MarcoFalke: ACK 56010f9256 🎛 Tree-SHA512: db67b70278f8d4c318907e105af54b54eb3afd15500f9aa0c98034f6fd4bd1cf9ad1663037bd9b237ff4890f3059b37291a6498d8d6ae2cc38efb9f045f73310 --- src/net_processing.cpp | 5 +- test/functional/p2p_addr_relay.py | 2 +- test/functional/p2p_invalid_messages.py | 68 +++++++++++++--------- test/functional/test_framework/messages.py | 4 ++ test/functional/test_framework/p2p.py | 4 +- 5 files changed, 52 insertions(+), 31 deletions(-) diff --git a/src/net_processing.cpp b/src/net_processing.cpp index f1af6ca544fb..fd8f84f4db5a 100644 --- a/src/net_processing.cpp +++ b/src/net_processing.cpp @@ -3279,7 +3279,7 @@ void PeerManagerImpl::ProcessMessage( vRecv >> vInv; if (vInv.size() > MAX_INV_SZ) { - Misbehaving(pfrom.GetId(), 20, strprintf("message inv size() = %u", vInv.size())); + Misbehaving(pfrom.GetId(), 20, strprintf("inv message size = %u", vInv.size())); return; } @@ -3374,7 +3374,8 @@ void PeerManagerImpl::ProcessMessage( vRecv >> vInv; if (vInv.size() > MAX_INV_SZ) { - Misbehaving(pfrom.GetId(), 20, strprintf("message getdata size() = %u", vInv.size())); + + Misbehaving(pfrom.GetId(), 20, strprintf("getdata message size = %u", vInv.size())); return; } diff --git a/test/functional/p2p_addr_relay.py b/test/functional/p2p_addr_relay.py index 3f39e327e7a0..7c5bc99387cd 100755 --- a/test/functional/p2p_addr_relay.py +++ b/test/functional/p2p_addr_relay.py @@ -45,7 +45,7 @@ def run_test(self): addr_source = self.nodes[0].add_p2p_connection(P2PInterface()) msg = msg_addr() - self.log.info('Send too large addr message') + self.log.info('Send too-large addr message') msg.addrs = ADDRS * 101 with self.nodes[0].assert_debug_log(['addr message size = 1010']): addr_source.send_and_ping(msg) diff --git a/test/functional/p2p_invalid_messages.py b/test/functional/p2p_invalid_messages.py index 54cb8425da37..40126817e14a 100755 --- a/test/functional/p2p_invalid_messages.py +++ b/test/functional/p2p_invalid_messages.py @@ -10,6 +10,9 @@ CInv, msg_ping, ser_string, + MAX_HEADERS_RESULTS, + MAX_INV_SIZE, + MAX_PROTOCOL_MESSAGE_LENGTH, msg_getdata, msg_headers, msg_inv, @@ -23,8 +26,7 @@ assert_equal, ) -MSG_LIMIT = 3 * 1024 * 1024 # 3MB, per MAX_PROTOCOL_MESSAGE_LENGTH -VALID_DATA_LIMIT = MSG_LIMIT - 5 # Account for the 5-byte length prefix +VALID_DATA_LIMIT = MAX_PROTOCOL_MESSAGE_LENGTH - 5 # Account for the 5-byte length prefix class msg_unrecognized: """Nonsensical message. Modeled after similar types in test_framework.messages.""" @@ -52,11 +54,13 @@ def run_test(self): self.test_checksum() self.test_size() self.test_msgtype() - self.test_large_inv() + self.test_oversized_inv_msg() + self.test_oversized_getdata_msg() + self.test_oversized_headers_msg() self.test_resource_exhaustion() def test_buffer(self): - self.log.info("Test message with header split across two buffers, should be received") + self.log.info("Test message with header split across two buffers is received") conn = self.nodes[0].add_p2p_connection(P2PDataStore()) # Create valid message msg = conn.build_message(msg_ping(nonce=12345)) @@ -75,6 +79,7 @@ def test_buffer(self): self.nodes[0].disconnect_p2ps() def test_magic_bytes(self): + self.log.info("Test message with invalid magic bytes disconnects peer") conn = self.nodes[0].add_p2p_connection(P2PDataStore()) with self.nodes[0].assert_debug_log(['HEADER ERROR - MESSAGESTART (badmsg, 2 bytes), received ffffffff']): msg = conn.build_message(msg_unrecognized(str_data="d")) @@ -82,9 +87,10 @@ def test_magic_bytes(self): msg = b'\xff' * 4 + msg[4:] conn.send_raw_message(msg) conn.wait_for_disconnect(timeout=5) - self.nodes[0].disconnect_p2ps() + self.nodes[0].disconnect_p2ps() def test_checksum(self): + self.log.info("Test message with invalid checksum logs an error") conn = self.nodes[0].add_p2p_connection(P2PDataStore()) with self.nodes[0].assert_debug_log(['CHECKSUM ERROR (badmsg, 2 bytes), expected 78df0a04 was ffffffff']): msg = conn.build_message(msg_unrecognized(str_data="d")) @@ -94,19 +100,20 @@ def test_checksum(self): msg = msg[:cut_len] + b'\xff' * 4 + msg[cut_len + 4:] conn.send_raw_message(msg) conn.sync_with_ping(timeout=1) - self.nodes[0].disconnect_p2ps() + self.nodes[0].disconnect_p2ps() def test_size(self): + self.log.info("Test message with oversized payload disconnects peer") conn = self.nodes[0].add_p2p_connection(P2PDataStore()) with self.nodes[0].assert_debug_log(['']): - # Create a message with oversized payload msg = msg_unrecognized(str_data="d"*(VALID_DATA_LIMIT + 1)) msg = conn.build_message(msg) conn.send_raw_message(msg) conn.wait_for_disconnect(timeout=5) - self.nodes[0].disconnect_p2ps() + self.nodes[0].disconnect_p2ps() def test_msgtype(self): + self.log.info("Test message with invalid message type logs an error") conn = self.nodes[0].add_p2p_connection(P2PDataStore()) with self.nodes[0].assert_debug_log(['HEADER ERROR - COMMAND']): msg = msg_unrecognized(str_data="d") @@ -115,42 +122,51 @@ def test_msgtype(self): msg = msg[:7] + b'\x00' + msg[7 + 1:] conn.send_raw_message(msg) conn.sync_with_ping(timeout=1) - self.nodes[0].disconnect_p2ps() - - def test_large_inv(self): - conn = self.nodes[0].add_p2p_connection(P2PInterface()) - with self.nodes[0].assert_debug_log(['Misbehaving', '(0 -> 20): message inv size() = 50001']): - msg = msg_inv([CInv(MSG_TX, 1)] * 50001) - conn.send_and_ping(msg) - with self.nodes[0].assert_debug_log(['Misbehaving', '(20 -> 40): message getdata size() = 50001']): - msg = msg_getdata([CInv(MSG_TX, 1)] * 50001) - conn.send_and_ping(msg) - with self.nodes[0].assert_debug_log(['Misbehaving', '(40 -> 60): headers message size = 2001']): - msg = msg_headers([CBlockHeader()] * 2001) - conn.send_and_ping(msg) self.nodes[0].disconnect_p2ps() + def test_oversized_msg(self, msg, size): + msg_type = msg.msgtype.decode('ascii') + self.log.info("Test {} message of size {} is logged as misbehaving".format(msg_type, size)) + with self.nodes[0].assert_debug_log(['Misbehaving', '{} message size = {}'.format(msg_type, size)]): + self.nodes[0].add_p2p_connection(P2PInterface()).send_and_ping(msg) + self.nodes[0].disconnect_p2ps() + + def test_oversized_inv_msg(self): + size = MAX_INV_SIZE + 1 + self.test_oversized_msg(msg_inv([CInv(MSG_TX, 1)] * size), size) + + def test_oversized_getdata_msg(self): + size = MAX_INV_SIZE + 1 + self.test_oversized_msg(msg_getdata([CInv(MSG_TX, 1)] * size), size) + + def test_oversized_headers_msg(self): + size = MAX_HEADERS_RESULTS + 1 + self.test_oversized_msg(msg_headers([CBlockHeader()] * size), size) + def test_resource_exhaustion(self): + self.log.info("Test node stays up despite many large junk messages") conn = self.nodes[0].add_p2p_connection(P2PDataStore()) conn2 = self.nodes[0].add_p2p_connection(P2PDataStore()) msg_at_size = msg_unrecognized(str_data="b" * VALID_DATA_LIMIT) - assert len(msg_at_size.serialize()) == MSG_LIMIT - self.log.info("Sending a bunch of large, junk messages to test memory exhaustion. May take a bit...") + assert len(msg_at_size.serialize()) == MAX_PROTOCOL_MESSAGE_LENGTH - # Run a bunch of times to test for memory exhaustion. + self.log.info("(a) Send 80 messages, each of maximum valid data size (4MB)") for _ in range(80): conn.send_message(msg_at_size) # Check that, even though the node is being hammered by nonsense from one # connection, it can still service other peers in a timely way. + self.log.info("(b) Check node still services peers in a timely way") for _ in range(20): conn2.sync_with_ping(timeout=2) - # Peer 1, despite being served up a bunch of nonsense, should still be connected. - self.log.info("Waiting for node to drop junk messages.") + self.log.info("(c) Wait for node to drop junk messages, while remaining connected") conn.sync_with_ping(timeout=400) + + # Despite being served up a bunch of nonsense, the peers should still be connected. assert conn.is_connected + assert conn2.is_connected self.nodes[0].disconnect_p2ps() diff --git a/test/functional/test_framework/messages.py b/test/functional/test_framework/messages.py index ddf3c292326a..e40b898f213b 100755 --- a/test/functional/test_framework/messages.py +++ b/test/functional/test_framework/messages.py @@ -46,6 +46,10 @@ BIP125_SEQUENCE_NUMBER = 0xfffffffd # Sequence number that is BIP 125 opt-in and BIP 68-opt-out +MAX_PROTOCOL_MESSAGE_LENGTH = 3 * 1024 * 1024 # Maximum length of incoming protocol messages +MAX_HEADERS_RESULTS = 2000 # Number of headers sent in one getheaders result +MAX_INV_SIZE = 50000 # Maximum number of entries in an 'inv' protocol message + NODE_NETWORK = (1 << 0) NODE_BLOOM = (1 << 2) NODE_COMPACT_FILTERS = (1 << 6) diff --git a/test/functional/test_framework/p2p.py b/test/functional/test_framework/p2p.py index 51945f392449..f453511e5986 100755 --- a/test/functional/test_framework/p2p.py +++ b/test/functional/test_framework/p2p.py @@ -31,6 +31,7 @@ from test_framework.messages import ( CBlockHeader, CompressibleBlockHeader, + MAX_HEADERS_RESULTS, MIN_VERSION_SUPPORTED, NODE_HEADERS_COMPRESSED, msg_addr, @@ -630,7 +631,6 @@ def _compute_requested_block_headers(self, locator, hash_stop): return headers_list = [self.block_store[self.last_block_hash]] - maxheaders = 2000 while headers_list[-1].sha256 not in locator.vHave: # Walk back through the block store, adding headers to headers_list # as we go. @@ -646,7 +646,7 @@ def _compute_requested_block_headers(self, locator, hash_stop): break # Truncate the list if there are too many headers - headers_list = headers_list[:-maxheaders - 1:-1] + headers_list = headers_list[:-MAX_HEADERS_RESULTS - 1:-1] return headers_list From 0ac06c1d7b4b27411889a8f2f17636de162072cd Mon Sep 17 00:00:00 2001 From: "Wladimir J. van der Laan" Date: Wed, 15 Jul 2020 15:12:59 +0200 Subject: [PATCH 4/8] Merge #19214: Auto-detect SHA256 implementation in benchmarks addf18da951439f696dba163ae1c73458d43ea03 Call SHA256AutoDetect in benchmark setup (Pieter Wuille) Pull request description: It seems `SHA256AutoDetect()` was not being called in benchmarks, making the numbers only reflect the naive implementation. Fix this by calling it in bench_bitcoin's setup. ACKs for top commit: fjahr: tested ACK addf18da951439f696dba163ae1c73458d43ea03 pstratem: ACK addf18da951439f696dba163ae1c73458d43ea03 laanwj: ACK addf18da951439f696dba163ae1c73458d43ea03 Tree-SHA512: 3ba4b068145942df1429bf5913e3f685511e6ebeae2c1a3f9b8ac0144f6db1c7df456f88f480a2129f3e1602e3bf6a39530bb96e2c74c03ddb19324cec6799c7 --- src/bench/bench_bitcoin.cpp | 1 + 1 file changed, 1 insertion(+) diff --git a/src/bench/bench_bitcoin.cpp b/src/bench/bench_bitcoin.cpp index f8449c3b06ce..8b7b7f55c74a 100644 --- a/src/bench/bench_bitcoin.cpp +++ b/src/bench/bench_bitcoin.cpp @@ -41,6 +41,7 @@ int main(int argc, char** argv) { ArgsManager argsman; SetupBenchArgs(argsman); + SHA256AutoDetect(); std::string error; if (!argsman.ParseParameters(argc, argv, error)) { tfm::format(std::cerr, "Error parsing command line arguments: %s\n", error); From 13d7f0098e5e72cbdf55efc7abce53c5b5f67057 Mon Sep 17 00:00:00 2001 From: MarcoFalke Date: Tue, 14 Jul 2020 17:08:16 +0200 Subject: [PATCH 5/8] Merge #19429: test: Fix intermittent failure in wallet_encryption fabd33b5416f2a2cd635d02b85d5bc2681cfaf17 test: Fix intermittent failure in wallet_encryption (MarcoFalke) Pull request description: Iterating all crypted keys might take time. E.g. ``` node0 2020-07-01T14:41:19.227367Z [httpworker.0] ThreadRPCServer method=walletpassphrase user=__cookie__ node0 2020-07-01T14:41:24.377142Z [httpworker.0] queue run of timer lockwallet() in 100000000 seconds (using HTTP) ... test 2020-07-01T14:41:24.379000Z TestFramework (ERROR): Assertion failed Traceback (most recent call last): File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 117, in main self.run_test() File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/wallet_encryption.py", line 88, in run_test assert_greater_than(expected_time + 5, actual_time) # 5 second buffer File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/util.py", line 54, in assert_greater_than raise AssertionError("%s <= %s" % (str(thing1), str(thing2))) AssertionError: 1693614483 <= 1693614484 ``` https://cirrus-ci.com/task/5322429885054976?command=ci#L4517 ACKs for top commit: achow101: ACK fabd33b5416f2a2cd635d02b85d5bc2681cfaf17 Tree-SHA512: 7a3ccdfc0cdc05fef1f942d3167d100ed63422eb54c05405c884ed91162b7bdb5ce54cb5a981b99a6df2e4af1ea834ccd7d5156531c8c14ea13e735becd6b377 --- test/functional/wallet_encryption.py | 18 +++++++++++++----- 1 file changed, 13 insertions(+), 5 deletions(-) diff --git a/test/functional/wallet_encryption.py b/test/functional/wallet_encryption.py index 41ece8e64928..66b58d675c6f 100755 --- a/test/functional/wallet_encryption.py +++ b/test/functional/wallet_encryption.py @@ -14,6 +14,7 @@ assert_greater_than_or_equal, ) + class WalletEncryptionTest(BitcoinTestFramework): def set_test_params(self): self.setup_clean_chain = True @@ -70,20 +71,27 @@ def run_test(self): # Test timeout bounds assert_raises_rpc_error(-8, "Timeout cannot be negative.", self.nodes[0].walletpassphrase, passphrase2, -10) - # Check the timeout - # Check a time less than the limit + + self.log.info('Check a timeout less than the limit') MAX_VALUE = 100000000 expected_time = self.mocktime + MAX_VALUE - 600 self.nodes[0].walletpassphrase(passphrase2, MAX_VALUE - 600) + self.bump_mocktime(1) + # give buffer for walletpassphrase, since it iterates over all crypted keys + expected_time_with_buffer = self.mocktime + MAX_VALUE - 600 actual_time = self.nodes[0].getwalletinfo()['unlocked_until'] assert_greater_than_or_equal(actual_time, expected_time) - assert_greater_than(expected_time + 5, actual_time) # 5 second buffer - # Check a time greater than the limit + assert_greater_than(expected_time_with_buffer, actual_time) + + self.log.info('Check a timeout greater than the limit') expected_time = self.mocktime + MAX_VALUE - 1 self.nodes[0].walletpassphrase(passphrase2, MAX_VALUE + 1000) + self.bump_mocktime(1) + expected_time_with_buffer = self.mocktime + MAX_VALUE actual_time = self.nodes[0].getwalletinfo()['unlocked_until'] assert_greater_than_or_equal(actual_time, expected_time) - assert_greater_than(expected_time + 5, actual_time) # 5 second buffer + assert_greater_than(expected_time_with_buffer, actual_time) + if __name__ == '__main__': WalletEncryptionTest().main() From 4bcbb8db30a3b74f59ac3092fc477e215f32db13 Mon Sep 17 00:00:00 2001 From: MarcoFalke Date: Tue, 14 Jul 2020 16:14:29 +0200 Subject: [PATCH 6/8] Merge #18990: log: Properly log txs rejected from mempool fa9f20b6477a206adf5089398803b45d1a114b6f log: Properly log txs rejected from mempool (MarcoFalke) Pull request description: Currently `CheckTxInputs` rejections from the mempool are the only rejections that log directly and unconditionally to debug.log instead of leaving it to the caller. This has multiple issues: * A rejected RPC transaction will log a redundant failure reason to debug log. All other failures are merely reported to the RPC user. * A rejected p2p transaction will log the failure twice. Once with the `MEMPOOLREJ` flag, and once unconditionally. * A rejected orphan transaction will log no failure. Fix all issues by simply returning the state to the caller, like it is done for all other rejections. The patch includes whitespace fixups to highlight relevant parts of the codebase and simplify review. ACKs for top commit: naumenkogs: utACK fa9f20b6477a206adf5089398803b45d1a114b6f rajarshimaitra: Concept ACK. Compiled and ran tests. `fa9f20b` jnewbery: code review ACK fa9f20b6477a206adf5089398803b45d1a114b6f Tree-SHA512: 86cc17b2a9239c01c4fc3f254ad48ee1d3883266966b9811030176338b9ac3deaea7ea5babfb8bbf739d7440154e30011fede8f9313175f199d4a062af6494f7 --- src/net_processing.cpp | 8 +++++--- src/validation.cpp | 5 +++-- 2 files changed, 8 insertions(+), 5 deletions(-) diff --git a/src/net_processing.cpp b/src/net_processing.cpp index fd8f84f4db5a..8461ebfeee30 100644 --- a/src/net_processing.cpp +++ b/src/net_processing.cpp @@ -2582,7 +2582,10 @@ void PeerManagerImpl::ProcessOrphanTx(std::set& orphan_work_set) break; } else if (state.GetResult() != TxValidationResult::TX_MISSING_INPUTS) { if (state.IsInvalid()) { - LogPrint(BCLog::MEMPOOL, " invalid orphan tx %s\n", orphanHash.ToString()); + LogPrint(BCLog::MEMPOOL, " invalid orphan tx %s from peer=%d. %s\n", + orphanHash.ToString(), + orphan_it->second.fromPeer, + state.ToString()); // Maybe punish peer that gave us an invalid orphan tx MaybePunishNodeForTx(orphan_it->second.fromPeer, state); } @@ -3742,8 +3745,7 @@ void PeerManagerImpl::ProcessMessage( // peer simply for relaying a tx that our m_recent_rejects has caught, // regardless of false positives. - if (state.IsInvalid()) - { + if (state.IsInvalid()) { LogPrint(BCLog::MEMPOOLREJ, "%s from peer=%d was not accepted: %s\n", tx.GetHash().ToString(), pfrom.GetId(), state.ToString()); diff --git a/src/validation.cpp b/src/validation.cpp index dc1f5242676d..dae414e5456b 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -648,8 +648,9 @@ bool MemPoolAccept::PreChecks(ATMPArgs& args, Workspace& ws) std::unique_ptr& entry = ws.m_entry; CAmount& nModifiedFees = ws.m_modified_fees; - if (!CheckTransaction(tx, state)) + if (!CheckTransaction(tx, state)) { return false; // state filled in by CheckTransaction + } assert(std::addressof(::ChainstateActive()) == std::addressof(m_active_chainstate)); if (!ContextualCheckTransaction(tx, state, chainparams.GetConsensus(), m_active_chainstate.m_chain.Tip())) @@ -761,7 +762,7 @@ bool MemPoolAccept::PreChecks(ATMPArgs& args, Workspace& ws) assert(std::addressof(g_chainman.m_blockman) == std::addressof(m_active_chainstate.m_blockman)); if (!Consensus::CheckTxInputs(tx, state, m_view, m_active_chainstate.m_blockman.GetSpendHeight(m_view), ws.m_base_fees)) { - return error("%s: Consensus::CheckTxInputs: %s, %s", __func__, tx.GetHash().ToString(), state.ToString()); + return false; // state filled in by CheckTxInputs } // Check for non-standard pay-to-script-hash in inputs From 8038be14ac2195b5a6231ea2587d3178a8fe8b04 Mon Sep 17 00:00:00 2001 From: MarcoFalke Date: Fri, 22 Jan 2021 13:12:44 +0100 Subject: [PATCH 7/8] Merge #20927: [refactor] [net] Clean up InactivityCheck() MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit bf100f8170770544fb39ae6802175c564cde532f [net] Cleanup InactivityChecks() and add commenting about time (John Newbery) 06fa85cd50b718fecd69f0481740d2b8714a1397 [net] InactivityCheck() takes a CNode reference (John Newbery) Pull request description: This is a pure refactor and should not change any behavior. It clarifies and documents the InactivityCheck() function This makes #20721 easier to review. In particular, this function uses a mixture of (unmockable) system time and mockable time. It's important to understand where those are being used when reviewing #20721. #20721 doesn't require this change, so if others don't agree that it's useful and makes review easier, then I'm happy to close this and just do #20721 directly. ACKs for top commit: fanquake: ACK bf100f8170770544fb39ae6802175c564cde532f MarcoFalke: review ACK bf100f8170770544fb39ae6802175c564cde532f 💫 Tree-SHA512: 7b001de2a5fbe8a6dc37baeae930db5775290afb2e8a6aecdf13161f1e5b06ef813bc6291d8ee5cefcf1e430c955ea702833a8db84192eebe6e6acf0b9304cb2 --- src/net.cpp | 70 ++++++++++++++++++++++++++++++----------------------- src/net.h | 3 ++- 2 files changed, 42 insertions(+), 31 deletions(-) diff --git a/src/net.cpp b/src/net.cpp index 78630bd731f3..65aa66108caf 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -1487,37 +1487,47 @@ void CConnman::CalculateNumConnectionsChangedStats() statsClient.gauge("peers.torConnections", torNodes, 1.0f); } -void CConnman::InactivityCheck(CNode *pnode) const +bool CConnman::InactivityCheck(const CNode& node) const { - int64_t nTime = GetSystemTimeInSeconds(); - if (nTime - pnode->nTimeConnected > m_peer_connect_timeout) - { - if (pnode->nLastRecv == 0 || pnode->nLastSend == 0) - { - LogPrint(BCLog::NET, "socket no message in first %i seconds, %d %d from %d\n", m_peer_connect_timeout, pnode->nLastRecv != 0, pnode->nLastSend != 0, pnode->GetId()); - pnode->fDisconnect = true; - } - else if (nTime - pnode->nLastSend > TIMEOUT_INTERVAL) - { - LogPrintf("socket sending timeout: %is\n", nTime - pnode->nLastSend); - pnode->fDisconnect = true; - } - else if (nTime - pnode->nLastRecv > TIMEOUT_INTERVAL) - { - LogPrintf("socket receive timeout: %is\n", nTime - pnode->nLastRecv); - pnode->fDisconnect = true; - } - else if (pnode->nPingNonceSent && pnode->nPingUsecStart + TIMEOUT_INTERVAL * 1000000 < GetTimeMicros()) - { - LogPrintf("ping timeout: %fs\n", 0.000001 * (GetTimeMicros() - pnode->nPingUsecStart)); - pnode->fDisconnect = true; - } - else if (!pnode->fSuccessfullyConnected) - { - LogPrint(BCLog::NET, "version handshake timeout from %d\n", pnode->GetId()); - pnode->fDisconnect = true; - } + // Use non-mockable system time (otherwise these timers will pop when we + // use setmocktime in the tests). + int64_t now = GetSystemTimeInSeconds(); + + if (now <= node.nTimeConnected + m_peer_connect_timeout) { + // Only run inactivity checks if the peer has been connected longer + // than m_peer_connect_timeout. + return false; } + + if (node.nLastRecv == 0 || node.nLastSend == 0) { + LogPrint(BCLog::NET, "socket no message in first %i seconds, %d %d from %d\n", m_peer_connect_timeout, node.nLastRecv != 0, node.nLastSend != 0, node.GetId()); + return true; + } + + if (now > node.nLastSend + TIMEOUT_INTERVAL) { + LogPrintf("socket sending timeout: %is\n", now - node.nLastSend); + return true; + } + + if (now > node.nLastRecv + TIMEOUT_INTERVAL) { + LogPrintf("socket receive timeout: %is\n", now - node.nLastRecv); + return true; + } + + if (node.nPingNonceSent && node.nPingUsecStart.load() + TIMEOUT_INTERVAL * 1000000 < GetTimeMicros()) { + // We use mockable time for ping timeouts. This means that setmocktime + // may cause pings to time out for peers that have been connected for + // longer than m_peer_connect_timeout. + LogPrintf("ping timeout: %fs\n", 0.000001 * (GetTimeMicros() - node.nPingUsecStart)); + return true; + } + + if (!node.fSuccessfullyConnected) { + LogPrint(BCLog::NET, "version handshake timeout from %d\n", node.GetId()); + return true; + } + + return false; } bool CConnman::GenerateSelectSet(std::set &recv_set, std::set &send_set, std::set &error_set) @@ -2036,7 +2046,7 @@ void CConnman::ThreadSocketHandler() SocketHandler(); if (GetTimeMillis() - nLastCleanupNodes > 1000) { ForEachNode(AllNodes, [&](CNode* pnode) { - InactivityCheck(pnode); + if (InactivityCheck(*pnode)) pnode->fDisconnect = true; }); nLastCleanupNodes = GetTimeMillis(); } diff --git a/src/net.h b/src/net.h index b013ba183f71..1dde46a0d889 100644 --- a/src/net.h +++ b/src/net.h @@ -600,7 +600,8 @@ friend class CNode; void DisconnectNodes(); void NotifyNumConnectionsChanged(); void CalculateNumConnectionsChangedStats(); - void InactivityCheck(CNode *pnode) const; + /** Return true if the peer is inactive and should be disconnected. */ + bool InactivityCheck(const CNode& node) const; bool GenerateSelectSet(std::set &recv_set, std::set &send_set, std::set &error_set); #ifdef USE_KQUEUE void SocketEventsKqueue(std::set &recv_set, std::set &send_set, std::set &error_set, bool fOnlyPoll); From 18500eac2f26585e0a55bbea56dfbabcf739abc0 Mon Sep 17 00:00:00 2001 From: MarcoFalke Date: Wed, 2 Dec 2020 09:44:46 +0100 Subject: [PATCH 8/8] Merge #20507: sync: print proper lock order location when double lock is detected db058efeb0821cb5022e3b29e0aff3627d7aaf83 sync: use HasReason() in double lock tests (Vasil Dimov) a21dc469ccf076ca3b07b1adbd8bf667145f1c44 sync: const-qualify the argument of double_lock_detected() (Vasil Dimov) 6d3689fcf6cff397187028344570489db3e6ecf4 sync: print proper lock order location when double lock is detected (Vasil Dimov) Pull request description: Before: ``` Assertion failed: detected double lock at src/sync.cpp:153, details in debug log. ``` After: ``` Assertion failed: detected double lock for 'm' in src/test/sync_tests.cpp:40 (in thread ''), details in debug log. ``` ACKs for top commit: jonasschnelli: utACK db058efeb0821cb5022e3b29e0aff3627d7aaf83 ajtowns: ACK db058efeb0821cb5022e3b29e0aff3627d7aaf83 hebasto: ACK db058efeb0821cb5022e3b29e0aff3627d7aaf83, tested on Linux Mint 20 (x86_64). Tree-SHA512: 452ddb9a14e44bb174135b39f2219c76eadbb8a6c0e80d64a25f995780d6dbc7b570d9902616db94dbfabaee197b5828ba3475171a68240ac0958fb203a7acdb --- src/sync.cpp | 6 ++++-- src/test/sync_tests.cpp | 6 ++---- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/src/sync.cpp b/src/sync.cpp index d57bd79e7ece..7849ba9d84da 100644 --- a/src/sync.cpp +++ b/src/sync.cpp @@ -140,7 +140,7 @@ static void potential_deadlock_detected(const LockPair& mismatch, const LockStac throw std::logic_error(strprintf("potential deadlock detected: %s -> %s -> %s", mutex_b, mutex_a, mutex_b)); } -static void double_lock_detected(const void* mutex, LockStack& lock_stack) +static void double_lock_detected(const void* mutex, const LockStack& lock_stack) { LogPrintf("DOUBLE LOCK DETECTED\n"); LogPrintf("Lock order:\n"); @@ -151,7 +151,9 @@ static void double_lock_detected(const void* mutex, LockStack& lock_stack) LogPrintf(" %s\n", i.second.ToString()); } if (g_debug_lockorder_abort) { - tfm::format(std::cerr, "Assertion failed: detected double lock at %s:%i, details in debug log.\n", __FILE__, __LINE__); + tfm::format(std::cerr, + "Assertion failed: detected double lock for %s, details in debug log.\n", + lock_stack.back().second.ToString()); abort(); } throw std::logic_error("double lock detected"); diff --git a/src/test/sync_tests.cpp b/src/test/sync_tests.cpp index 25fca556a7ac..a076b872bd9e 100644 --- a/src/test/sync_tests.cpp +++ b/src/test/sync_tests.cpp @@ -62,10 +62,8 @@ void TestDoubleLock(bool should_throw) MutexType m; ENTER_CRITICAL_SECTION(m); if (should_throw) { - BOOST_CHECK_EXCEPTION( - TestDoubleLock2(m), std::logic_error, [](const std::logic_error& e) { - return strcmp(e.what(), "double lock detected") == 0; - }); + BOOST_CHECK_EXCEPTION(TestDoubleLock2(m), std::logic_error, + HasReason("double lock detected")); } else { BOOST_CHECK_NO_THROW(TestDoubleLock2(m)); }