Repository: bitcoin
Issue: Spurious (?) valgrind failure for p2p_compactblocks.py
Labels: Tests,Upstream

Ubuntu 23.04 with g++ 12.2.0 and valgrind 3.19.0. Built without depends and without `--enable-debug`.

The failure is introduced by:
https://github.com/bitcoin/bitcoin/pull/27626/commits/cce96182ba2457335868c65dc16b081c3dee32ee

It can also be reproduced on master a13f3746dccd9c4ec16d6bfe9b33ebd26e3238e1.

Offending line in `RemoveBlockRequest`:

```cpp
if (from_peer && *from_peer != node_id) {
```

It seems to believe `from_peer` is uninitialized. Adding a log statement that prints `from_peer` makes the error go away. As does compiling with `--enable-debug`. Others were not able to reproduce this at all.

This seems like a Valgrind bug, not an actual problem with the code. 

node0/stderr/...:

```
==2894643== Thread 25 b-msghand:
==2894643== Conditional jump or move depends on uninitialised value(s)
==2894643==    at 0x24A6EC: (anonymous namespace)::PeerManagerImpl::RemoveBlockRequest(uint256 const&, std::optional<long>) [clone .isra.0] (in /home/sjors/dev/bitcoin/src/bitcoind)
==2894643==    by 0x25AAA1: (anonymous namespace)::PeerManagerImpl::ProcessBlock(CNode&, std::shared_ptr<CBlock const> const&, bool, bool) (in /home/sjors/dev/bitcoin/src/bitcoind)
==2894643==    by 0x2718A4: (anonymous namespace)::PeerManagerImpl::ProcessMessage(CNode&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, CDataStream&, std::chrono::duration<long, std::ratio<1l, 1000000l> >, std::atomic<bool> const&) (in /home/sjors/dev/bitcoin/src/bitcoind)
==2894643==    by 0x274E68: (anonymous namespace)::PeerManagerImpl::ProcessMessages(CNode*, std::atomic<bool>&) (in /home/sjors/dev/bitcoin/src/bitcoind)
==2894643==    by 0x22A9E7: CConnman::ThreadMessageHandler() (in /home/sjors/dev/bitcoin/src/bitcoind)
==2894643==    by 0x620BF5: util::TraceThread(std::basic_string_view<char, std::char_traits<char> >, std::function<void ()>) (in /home/sjors/dev/bitcoin/src/bitcoind)
==2894643==    by 0x22095C: std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)(std::basic_string_view<char, std::char_traits<char> >, std::function<void ()>), char const*, CConnman::Start(CScheduler&, CConnman::Options const&)::{lambda()#5}> > >::_M_run() (in /home/sjors/dev/bitcoin/src/bitcoind)
==2894643==    by 0x494F3E2: ??? (in /usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.31)
==2894643==    by 0x4C6F189: start_thread (pthread_create.c:444)
==2894643==    by 0x4CFDAF3: clone (clone.S:100)
==2894643== 
{
   <insert_a_suppression_name_here>
   Memcheck:Cond
   fun:_ZN12_GLOBAL__N_115PeerManagerImpl18RemoveBlockRequestERK7uint256St8optionalIlE.isra.0
   fun:_ZN12_GLOBAL__N_115PeerManagerImpl12ProcessBlockER5CNodeRKSt10shared_ptrIK6CBlockEbb
   fun:_ZN12_GLOBAL__N_115PeerManagerImpl14ProcessMessageER5CNodeRKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEER11CDataStreamNSt6chrono8durationIlSt5ratioILl1ELl1000000EEEERKSt6atomicIbE
   fun:_ZN12_GLOBAL__N_115PeerManagerImpl15ProcessMessagesEP5CNodeRSt6atomicIbE
   fun:_ZN8CConnman20ThreadMessageHandlerEv
   fun:_ZN4util11TraceThreadESt17basic_string_viewIcSt11char_traitsIcEESt8functionIFvvEE
   fun:_ZNSt6thread11_State_implINS_8_InvokerISt5tupleIJPFvSt17basic_string_viewIcSt11char_traitsIcEESt8functionIFvvEEEPKcZN8CConnman5StartER10CSchedulerRKNSE_7OptionsEEUlvE3_EEEEE6_M_runEv
   obj:/usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.31
   fun:start_thread
   fun:clone
}
==2894643== 
==2894643== Exit program on first error (--exit-on-first-error=yes)
```

Combined log shows where it happens in the test, right after receiving msg_sendcmpct at delivery_peer.send_and_ping(msg_cmpctblock(cmpct_block.to_p2p())).

```
2023-05-24T12:44:08.114000Z TestFramework (INFO): PRNG seed is: 6887258428905600896
2023-05-24T12:44:08.115000Z TestFramework (DEBUG): Setting up network thread
2023-05-24T12:44:08.115000Z TestFramework (INFO): Initializing test directory /tmp/bitcoin_func_test_zkozpx3h
2023-05-24T12:44:08.116000Z TestFramework.node0 (DEBUG): bitcoind started, waiting for RPC to come up
2023-05-24T12:44:11.558000Z TestFramework.node0 (DEBUG): RPC successfully started
2023-05-24T12:44:11.662000Z TestFramework.p2p (DEBUG): Connecting to Bitcoin Node: 127.0.0.1:12377
2023-05-24T12:44:11.663000Z TestFramework.p2p (DEBUG): Connected & Listening: 127.0.0.1:12377
2023-05-24T12:44:11.663000Z TestFramework.p2p (DEBUG): Send message to 127.0.0.1:12377: msg_version(nVersion=70016 nServices=9 nTime=Wed May 24 14:44:11 2023 addrTo=CAddress(nServices=1 net=IPv4 addr=127.0.0.1 port=12377) addrFrom=CAddress(nServices=1 net=IPv4 addr=0.0.0.0 port=0) nNonce=0x8B641D5BF26C25DE strSubVer=/python-p2p-tester:0.0.3/ nStartingHeight=-1 relay=1)
2023-05-24T12:44:11.702000Z TestFramework.p2p (DEBUG): Received message from 127.0.0.1:12377: msg_version(nVersion=70016 nServices=1033 nTime=Wed May 24 14:44:11 2023 addrTo=CAddress(nServices=0 net=IPv4 addr=0.0.0.0 port=0) addrFrom=CAddress(nServices=1033 net=IPv4 addr=0.0.0.0 port=0) nNonce=0xEBA5B51C154D242B strSubVer=/Satoshi:25.99.0(testnode0)/ nStartingHeight=0 relay=1)

[... cut because comments max 65536 chars ... ]

2023-05-24T12:44:18.001000Z TestFramework.p2p (DEBUG): Send message to 127.0.0.1:12377: msg_tx(tx=CTransaction(nVersion=2 vin=[CTxIn(prevout=COutPoint(hash=8f4329eaafed2c1755c9dd86d495e79a167cdd3e4dd5819125a6724febc20c17 n=0) scriptSig= nSequence=0)] vout=[CTxOut(nValue=4.99997000 scriptPubKey=51755175517551755175517551755175517551755175517551755175517551)] wit=CTxWitness() nLockTime=0))
2023-05-24T12:44:18.001000Z TestFramework.p2p (DEBUG): Send message to 127.0.0.1:12377: msg_tx(tx=CTransaction(nVersion=2 vin=[CTxIn(prevout=COutPoint(hash=46593581928ea644c434b3f459f0cd9f056761ce4e9b2d69e2691359ae031526 n=0) scriptSig= nSequence=0)] vout=[CTxOut(nValue=4.99996000 scriptPubKey=51755175517551755175517551755175517551755175517551755175517551)] wit=CTxWitness() nLockTime=0))
2023-05-24T12:44:18.001000Z TestFramework.p2p (DEBUG): Send message to 127.0.0.1:12377: msg_tx(tx=CTransaction(nVersion=2 vin=[CTxIn(prevout=COutPoint(hash=a799b1c2eef43346c704913c06e7323660bbb96bf25fd85d3416f9fd8eaedc2a n=0) scriptSig= nSequence=0)] vout=[CTxOut(nValue=4.99995000 scriptPubKey=51755175517551755175517551755175517551755175517551755175517551)] wit=CTxWitness() nLockTime=0))
2023-05-24T12:44:18.001000Z TestFramework.p2p (DEBUG): Send message to 127.0.0.1:12377: msg_ping(nonce=00000009)
2023-05-24T12:44:18.011000Z TestFramework.p2p (DEBUG): Received message from 127.0.0.1:12377: msg_pong(nonce=00000009)
2023-05-24T12:44:18.054000Z TestFramework.p2p (DEBUG): Send message to 127.0.0.1:12377: msg_cmpctblock(HeaderAndShortIDs=P2PHeaderAndShortIDs(header=CBlockHeader(nVersion=805306368 hashPrevBlock=47ed1663e361a06b9088c35faf83e39e4a57c6fe44d733ebe22ac5bf4c18e56d hashMerkleRoot=0cca0a75f4dbeb22cfb8d625a8fd5bf5644ae8b403598bdaaa1095b2a860765f nTime=Wed May 24 14:44:52 2023 nBits=207fffff nNonce=00000002), nonce=0, shortids_length=5, shortids=[215827416537220, 271830461757115, 254576430693737, 118474923560500, 145899820988280], prefilled_txn_length=1, prefilledtxn=[PrefilledTransaction(i... (msg truncated)
2023-05-24T12:44:18.054000Z TestFramework.p2p (DEBUG): Send message to 127.0.0.1:12377: msg_ping(nonce=0000000a)
2023-05-24T12:44:18.065000Z TestFramework.p2p (DEBUG): Received message from 127.0.0.1:12377: msg_sendcmpct(announce=True, version=2)
2023-05-24T12:44:18.088000Z TestFramework.p2p (DEBUG): Closed connection to: 127.0.0.1:12377
2023-05-24T12:44:18.088000Z TestFramework.p2p (DEBUG): Closed connection to: 127.0.0.1:12377
2023-05-24T12:44:18.105000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/home/sjors/dev/bitcoin/test/functional/test_framework/test_framework.py", line 132, in main
    self.run_test()
  File "test/functional/p2p_compactblocks.py", line 864, in run_test
    self.test_compactblock_reconstruction_multiple_peers(self.segwit_node, self.additional_segwit_node)
  File "test/functional/p2p_compactblocks.py", line 773, in test_compactblock_reconstruction_multiple_peers
    delivery_peer.send_and_ping(msg_cmpctblock(cmpct_block.to_p2p()))
  File "/home/sjors/dev/bitcoin/test/functional/test_framework/p2p.py", line 553, in send_and_ping
    self.sync_with_ping(timeout=timeout)
  File "/home/sjors/dev/bitcoin/test/functional/test_framework/p2p.py", line 570, in sync_with_ping
    self.wait_until(test_function, timeout=timeout)
  File "/home/sjors/dev/bitcoin/test/functional/test_framework/p2p.py", line 463, in wait_until
    wait_until_helper(test_function, timeout=timeout, lock=p2p_lock, timeout_factor=self.timeout_factor)
  File "/home/sjors/dev/bitcoin/test/functional/test_framework/util.py", line 266, in wait_until_helper
    if predicate():
  File "/home/sjors/dev/bitcoin/test/functional/test_framework/p2p.py", line 460, in test_function
    assert self.is_connected
AssertionError
2023-05-24T12:44:18.106000Z TestFramework (DEBUG): Closing down network thread
2023-05-24T12:44:18.156000Z TestFramework (INFO): Stopping nodes
2023-05-24T12:44:18.157000Z TestFramework.node0 (DEBUG): Stopping node
```