Page MenuHomePhabricator

rpc, test: add sendmsgtopeer rpc and a test for net-level deadlock situation
AbandonedPublic

Authored by PiRK on Thu, Nov 14, 15:26.

Details

Reviewers
Fabien
Group Reviewers
Restricted Project
Summary

rpc: add test-only sendmsgtopeer rpc

This rpc can be used when we want a node to send a message, but
cannot use a python P2P object, for example for testing of low-level
net transport behavior.

test: add basic tests for sendmsgtopeer to rpc_net.py

test: add functional test for deadlock situation

Note that we need to pass a valid block message to make this deadlock test work as expected (=fail before the fix in D17138), because in Bitcoin ABC the non-block messages are limited to a smaller size which does not reliably trigger the deadlock.

This is a backport of core#28287
Depends on D17138

Test Plan

ninja all check-all

Test that this passes now and the same functional test sometimes fails before D17138 (>33% failure rate on my machine)
for i in {1..100}; do ~/dev/bitcoin-abc/build/test/functional/test_runner.py p2p_net_deadlock; done

Event Timeline

Tail of the build log:

[391/575] Building CXX object src/CMakeFiles/bitcoin-tx.dir/bitcoin-tx.cpp.o
[392/575] Linking CXX executable src/bitcoin-tx
[393/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/logging.cpp.o
[394/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/blockindex.cpp.o
[395/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/coins.cpp.o
[396/575] Building CXX object src/CMakeFiles/bitcoin-wallet.dir/bitcoin-wallet.cpp.o
[397/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/str.cpp.o
[398/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/random.cpp.o
[399/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/blockfilter.cpp.o
[400/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/transaction_utils.cpp.o
[401/575] Building CXX object src/CMakeFiles/server.dir/rpc/mining.cpp.o
[402/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/txmempool.cpp.o
[403/575] Building CXX object src/CMakeFiles/server.dir/net_processing.cpp.o
[404/575] Building CXX object src/CMakeFiles/server.dir/rpc/net.cpp.o
[405/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/context.cpp.o
[406/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/validation.cpp.o
[407/575] Building CXX object src/CMakeFiles/server.dir/torcontrol.cpp.o
[408/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/coinselection.cpp.o
[409/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/crypter.cpp.o
[410/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/bdb.cpp.o
[411/575] Building CXX object src/CMakeFiles/server.dir/wallet/init.cpp.o
[412/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/coincontrol.cpp.o
[413/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/wallet.cpp.o
[414/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/db.cpp.o
[415/575] Building CXX object src/CMakeFiles/server.dir/rpc/avalanche.cpp.o
[416/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/net.cpp.o
[417/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/mining.cpp.o
[418/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/load.cpp.o
[419/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/fees.cpp.o
[420/575] Building CXX object src/CMakeFiles/server.dir/rpc/blockchain.cpp.o
[421/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/receive.cpp.o
[422/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/interfaces.cpp.o
[423/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/rpc/signmessage.cpp.o
[424/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/rpc/encrypt.cpp.o
[425/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/rpc/util.cpp.o
[426/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/transaction.cpp.o
[427/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/salvage.cpp.o
[428/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/rpc/backup.cpp.o
[429/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/sqlite.cpp.o
[430/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/rpcwallet.cpp.o
[431/575] Building CXX object src/test/CMakeFiles/testutil.dir/util/setup_common.cpp.o
[432/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/scriptpubkeyman.cpp.o
[433/575] Building CXX object src/seeder/CMakeFiles/seeder-base.dir/dns.cpp.o
[434/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/walletutil.cpp.o
[435/575] Building CXX object src/iguana/CMakeFiles/iguana.dir/iguana_formatter.cpp.o
[436/575] Building CXX object src/iguana/CMakeFiles/iguana.dir/iguana_interpreter.cpp.o
[437/575] Building CXX object src/seeder/CMakeFiles/seeder-base.dir/options.cpp.o
[438/575] Building CXX object src/iguana/CMakeFiles/iguana.dir/iguana.cpp.o
[439/575] Linking CXX executable src/iguana/iguana
[440/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/spend.cpp.o
[441/575] Building CXX object src/seeder/CMakeFiles/seeder-base.dir/db.cpp.o
[442/575] Building CXX object src/wallet/CMakeFiles/wallet-tool.dir/wallettool.cpp.o
[443/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/walletdb.cpp.o
[444/575] Building CXX object src/wallet/CMakeFiles/wallet.dir/wallet.cpp.o
[445/575] Linking CXX static library src/wallet/libwallet.a
[446/575] Building CXX object src/CMakeFiles/server.dir/validation.cpp.o
[447/575] Building CXX object src/seeder/CMakeFiles/bitcoin-seeder.dir/main.cpp.o
[448/575] Building CXX object src/seeder/CMakeFiles/seeder-base.dir/bitcoin.cpp.o
ninja: build stopped: cannot make progress due to previous errors.
Build build-clang-tidy failed with exit code 1

Failed tests logs:

====== Bitcoin ABC functional tests: p2p_net_deadlock.py ======

------- Stdout: -------
2024-11-14T15:33:00.821000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-without-wallet/test/tmp/test_runner_₿₵_🏃_20241114_152923/p2p_net_deadlock_286
2024-11-14T15:33:01.167000Z TestFramework (INFO): Simultaneously send a large message on both sides
2024-11-14T15:33:01.403000Z TestFramework (INFO): Check whether a deadlock happened
2024-11-14T15:33:01.405000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 148, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 138, in _run_test_internal
    self.run_test()
  File "/work/test/functional/p2p_net_deadlock.py", line 36, in run_test
    self.generate(node0, 1)
  File "/work/test/functional/test_framework/test_framework.py", line 741, in generate
    sync_fun() if sync_fun else self.sync_all()
                                ^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_framework.py", line 825, in sync_all
    self.sync_blocks(nodes)
  File "/work/test/functional/test_framework/test_framework.py", line 774, in sync_blocks
    assert all(len(x.getpeerinfo()) for x in rpc_connections)
AssertionError
2024-11-14T15:33:01.456000Z TestFramework (INFO): Stopping nodes
2024-11-14T15:33:01.659000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-without-wallet/test/tmp/test_runner_₿₵_🏃_20241114_152923/p2p_net_deadlock_286
2024-11-14T15:33:01.659000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-without-wallet/test/tmp/test_runner_₿₵_🏃_20241114_152923/p2p_net_deadlock_286/test_framework.log
2024-11-14T15:33:01.660000Z TestFramework (ERROR): 
2024-11-14T15:33:01.660000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-without-wallet/test/tmp/test_runner_₿₵_🏃_20241114_152923/p2p_net_deadlock_286' to consolidate all logs
2024-11-14T15:33:01.660000Z TestFramework (ERROR): 
2024-11-14T15:33:01.660000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2024-11-14T15:33:01.661000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2024-11-14T15:33:01.661000Z TestFramework (ERROR):

Each failure log is accessible here:
Bitcoin ABC functional tests: p2p_net_deadlock.py

Failed tests logs:

====== Bitcoin ABC functional tests: p2p_net_deadlock.py ======

------- Stdout: -------
2024-11-14T15:38:19.194000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20241114_152841/p2p_net_deadlock_286
2024-11-14T15:38:20.370000Z TestFramework (INFO): Simultaneously send a large message on both sides
2024-11-14T15:38:20.699000Z TestFramework (INFO): Check whether a deadlock happened
2024-11-14T15:38:20.704000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 148, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 138, in _run_test_internal
    self.run_test()
  File "/work/test/functional/p2p_net_deadlock.py", line 36, in run_test
    self.generate(node0, 1)
  File "/work/test/functional/test_framework/test_framework.py", line 741, in generate
    sync_fun() if sync_fun else self.sync_all()
                                ^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_framework.py", line 825, in sync_all
    self.sync_blocks(nodes)
  File "/work/test/functional/test_framework/test_framework.py", line 774, in sync_blocks
    assert all(len(x.getpeerinfo()) for x in rpc_connections)
AssertionError
2024-11-14T15:38:20.755000Z TestFramework (INFO): Stopping nodes
2024-11-14T15:38:21.008000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20241114_152841/p2p_net_deadlock_286
2024-11-14T15:38:21.008000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20241114_152841/p2p_net_deadlock_286/test_framework.log
2024-11-14T15:38:21.009000Z TestFramework (ERROR): 
2024-11-14T15:38:21.009000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-debug/test/tmp/test_runner_₿₵_🏃_20241114_152841/p2p_net_deadlock_286' to consolidate all logs
2024-11-14T15:38:21.009000Z TestFramework (ERROR): 
2024-11-14T15:38:21.009000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2024-11-14T15:38:21.010000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2024-11-14T15:38:21.010000Z TestFramework (ERROR):

Each failure log is accessible here:
Bitcoin ABC functional tests: p2p_net_deadlock.py

Failed tests logs:

====== Bitcoin ABC functional tests: p2p_net_deadlock.py ======

------- Stdout: -------
2024-11-14T15:34:47.249000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20241114_152945/p2p_net_deadlock_286
2024-11-14T15:34:47.626000Z TestFramework (INFO): Simultaneously send a large message on both sides
2024-11-14T15:34:47.876000Z TestFramework (INFO): Check whether a deadlock happened
2024-11-14T15:34:47.879000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 148, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 138, in _run_test_internal
    self.run_test()
  File "/work/test/functional/p2p_net_deadlock.py", line 36, in run_test
    self.generate(node0, 1)
  File "/work/test/functional/test_framework/test_framework.py", line 741, in generate
    sync_fun() if sync_fun else self.sync_all()
                                ^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_framework.py", line 825, in sync_all
    self.sync_blocks(nodes)
  File "/work/test/functional/test_framework/test_framework.py", line 774, in sync_blocks
    assert all(len(x.getpeerinfo()) for x in rpc_connections)
AssertionError
2024-11-14T15:34:47.930000Z TestFramework (INFO): Stopping nodes
2024-11-14T15:34:48.033000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20241114_152945/p2p_net_deadlock_286
2024-11-14T15:34:48.033000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20241114_152945/p2p_net_deadlock_286/test_framework.log
2024-11-14T15:34:48.033000Z TestFramework (ERROR): 
2024-11-14T15:34:48.034000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20241114_152945/p2p_net_deadlock_286' to consolidate all logs
2024-11-14T15:34:48.034000Z TestFramework (ERROR): 
2024-11-14T15:34:48.034000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2024-11-14T15:34:48.034000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2024-11-14T15:34:48.035000Z TestFramework (ERROR):
====== Bitcoin ABC functional tests with the next upgrade activated: p2p_net_deadlock.py ======

------- Stdout: -------
2024-11-14T15:39:15.428000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20241114_153448/p2p_net_deadlock_286
2024-11-14T15:39:15.846000Z TestFramework (INFO): Simultaneously send a large message on both sides
2024-11-14T15:39:16.091000Z TestFramework (INFO): Check whether a deadlock happened
2024-11-14T15:39:16.094000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 148, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 138, in _run_test_internal
    self.run_test()
  File "/work/test/functional/p2p_net_deadlock.py", line 36, in run_test
    self.generate(node0, 1)
  File "/work/test/functional/test_framework/test_framework.py", line 741, in generate
    sync_fun() if sync_fun else self.sync_all()
                                ^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_framework.py", line 825, in sync_all
    self.sync_blocks(nodes)
  File "/work/test/functional/test_framework/test_framework.py", line 774, in sync_blocks
    assert all(len(x.getpeerinfo()) for x in rpc_connections)
AssertionError
2024-11-14T15:39:16.145000Z TestFramework (INFO): Stopping nodes
2024-11-14T15:39:16.248000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20241114_153448/p2p_net_deadlock_286
2024-11-14T15:39:16.248000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20241114_153448/p2p_net_deadlock_286/test_framework.log
2024-11-14T15:39:16.248000Z TestFramework (ERROR): 
2024-11-14T15:39:16.249000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-diff/test/tmp/test_runner_₿₵_🏃_20241114_153448/p2p_net_deadlock_286' to consolidate all logs
2024-11-14T15:39:16.249000Z TestFramework (ERROR): 
2024-11-14T15:39:16.249000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2024-11-14T15:39:16.250000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2024-11-14T15:39:16.250000Z TestFramework (ERROR):

Each failure log is accessible here:
Bitcoin ABC functional tests: p2p_net_deadlock.py
Bitcoin ABC functional tests with the next upgrade activated: p2p_net_deadlock.py

PiRK edited the test plan for this revision. (Show Details)

make the test work (fails ~50% of the time before D17138, always works after)

test/functional/p2p_net_deadlock.py
36 ↗(On Diff #50866)

we apparently still have an issue with pad_tx for very large txs. If I set exactly 1_000_000 here it overshoots by 2 bytes and the block is rejected for protocol violation.

We don't need precision here, we just want a large enough block to sometimes trigger the deadlock with this test before the fix, so I'm not going to fix pad_tx in this diff (and we have tests showing that it works for txs sizes up to 1000 bytes)

PiRK edited the test plan for this revision. (Show Details)

rebase and leverage D17158 to handle invalid hex in the new RPC

PiRK published this revision for review.Mon, Nov 18, 11:22
PiRK edited the summary of this revision. (Show Details)

remove fixme comment (now fixed)

Fabien requested changes to this revision.Mon, Nov 18, 19:49
Fabien added a subscriber: Fabien.

See comment in D17138

This revision now requires changes to proceed.Mon, Nov 18, 19:50