CFilters reject and disconnect peers with a valid block hash #29655

issue djkazic openend this issue on March 14, 2024
  1. djkazic commented at 11:09 pm on March 14, 2024: none

    Is there an existing issue for this?

    • I have searched the existing issues

    Current behaviour

    For quite some time now, I’ve noticed that neutrino clients connected to my Bitcoin Core instance would have issues connecting after a while. Today, I turned on debug logging for [net] and discovered these messages (see log section). Peers were being disconnected! But strangely, it seems like even though these peers are requesting valid block hashes, Bitcoin Core is rejecting the serving of CFilters to them. No other disconnect messages for CFilters have been observed. I checked validity two ways: by checking against bitcoin-cli getblock as well as using a block explorer (mempool.space).

    Expected behaviour

    If a BIP-157 client requests a valid block hash as set forth by BlockRequestAllowed, it should receive a response from Bitcoin Core.

    Steps to reproduce

    1. Setup Bitcoin Core node with peerbloomfilters=1 and peerblockfilters=1, ensure port 8333 is open. Also set debug=net for debug level for networking logs.
    2. Connect neutrino peer to Bitcoin Core node and wait.
    3. Eventually, you will see the debug network message above.

    Relevant log output

      02024-03-14T16:25:48Z [net] received: getcfheaders (37 bytes) peer=35
      12024-03-14T16:25:48Z [net] peer 35 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
      22024-03-14T16:25:48Z [net] received: verack (0 bytes) peer=71
      3--
      42024-03-14T16:25:48Z [net] received: getcfheaders (37 bytes) peer=12
      52024-03-14T16:25:48Z [net] peer 12 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
      62024-03-14T16:25:49Z [net] received: getdata (37 bytes) peer=37
      7--
      82024-03-14T16:25:49Z [net] received: getcfheaders (37 bytes) peer=13
      92024-03-14T16:25:49Z [net] peer 13 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     102024-03-14T16:25:49Z [net] disconnecting peer=13
     11--
     122024-03-14T16:25:58Z [net] received: getcfilters (37 bytes) peer=75
     132024-03-14T16:25:58Z [net] peer 75 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     142024-03-14T16:25:58Z [net] received: getdata (73 bytes) peer=54
     15--
     162024-03-14T16:25:58Z [net] received: getcfilters (37 bytes) peer=72
     172024-03-14T16:25:58Z [net] peer 72 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     182024-03-14T16:25:58Z [net] received: tx (372 bytes) peer=11
     19--
     202024-03-14T16:26:14Z [net] received: getcfheaders (37 bytes) peer=50
     212024-03-14T16:26:14Z [net] peer 50 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     222024-03-14T16:26:14Z [net] sending inv (37 bytes) peer=54
     23--
     242024-03-14T16:26:14Z [net] received: getcfheaders (37 bytes) peer=1
     252024-03-14T16:26:14Z [net] peer 1 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     262024-03-14T16:26:14Z [net] received: getcfheaders (37 bytes) peer=71
     272024-03-14T16:26:14Z [net] peer 71 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     282024-03-14T16:26:14Z [net] received: getcfheaders (37 bytes) peer=6
     292024-03-14T16:26:14Z [net] peer 6 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     302024-03-14T16:26:14Z [net] received: getcfheaders (37 bytes) peer=3
     312024-03-14T16:26:14Z [net] peer 3 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     322024-03-14T16:26:14Z [net] received: tx (327 bytes) peer=25
     33--
     342024-03-14T16:26:15Z [net] Cleared nodestate for peer=71
     352024-03-14T16:26:15Z [net] peer 26 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     362024-03-14T16:26:15Z [net] sending inv (109 bytes) peer=54
     37--
     382024-03-14T16:26:15Z [net] received: getcfheaders (37 bytes) peer=9
     392024-03-14T16:26:15Z [net] peer 9 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     402024-03-14T16:26:15Z [net] received: tx (345 bytes) peer=46
     41--
     422024-03-14T16:26:15Z [net] received: getcfheaders (37 bytes) peer=67
     432024-03-14T16:26:15Z [net] peer 67 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     442024-03-14T16:26:15Z [net] received: getdata (37 bytes) peer=37
     45--
     462024-03-14T16:26:24Z [net] received: getcfilters (37 bytes) peer=84
     472024-03-14T16:26:24Z [net] peer 84 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     482024-03-14T16:26:24Z [net] received: getdata (37 bytes) peer=37
     49--
     502024-03-14T16:26:24Z [net] received: getcfilters (37 bytes) peer=87
     512024-03-14T16:26:24Z [net] peer 87 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     522024-03-14T16:26:24Z [net] sending inv (577 bytes) peer=57
     53--
     542024-03-14T16:26:25Z [net] received: getcfilters (37 bytes) peer=85
     552024-03-14T16:26:25Z [net] peer 85 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     562024-03-14T16:26:25Z [net] Requesting tx c4d0491f6f1d12c2c2f7d3fef9501150b7a4e7f6346dd68308c41050567d5c64 peer=81
     57--
     582024-03-14T16:26:26Z [net] received: getcfilters (37 bytes) peer=90
     592024-03-14T16:26:26Z [net] peer 90 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     602024-03-14T16:26:26Z [net] sending inv (109 bytes) peer=68
     61--
     622024-03-14T16:26:53Z [net] received: getcfheaders (37 bytes) peer=98
     632024-03-14T16:26:53Z [net] peer 98 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     642024-03-14T16:26:53Z [net] received: ping (8 bytes) peer=28
     65--
     662024-03-14T16:29:23Z [net] received: getcfheaders (37 bytes) peer=126
     672024-03-14T16:29:23Z [net] peer 126 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     682024-03-14T16:29:23Z [net] disconnecting peer=126
     69--
     702024-03-14T16:29:51Z [net] received: getcfilters (37 bytes) peer=128
     712024-03-14T16:29:51Z [net] peer 128 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     722024-03-14T16:29:51Z [net] sending inv (541 bytes) peer=120
     73--
     742024-03-14T16:30:44Z [net] received: getcfcheckpt (33 bytes) peer=139
     752024-03-14T16:30:44Z [net] peer 139 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     762024-03-14T16:30:44Z [net] disconnecting peer=139
     77--
     782024-03-14T16:30:56Z [net] received: getcfheaders (37 bytes) peer=146
     792024-03-14T16:30:56Z [net] peer 146 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     802024-03-14T16:30:56Z [net] disconnecting peer=146
     81--
     822024-03-14T16:31:11Z [net] received: getcfheaders (37 bytes) peer=151
     832024-03-14T16:31:11Z [net] peer 151 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     842024-03-14T16:31:11Z [net] disconnecting peer=151
     85--
     862024-03-14T16:31:21Z [net] received: getcfilters (37 bytes) peer=154
     872024-03-14T16:31:21Z [net] peer 154 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     882024-03-14T16:31:21Z [net] disconnecting peer=154
     89--
     902024-03-14T16:31:39Z [net] received: getcfheaders (37 bytes) peer=153
     912024-03-14T16:31:39Z [net] peer 153 requested invalid block hash: 0000000000000000000132006d75c39161b70fd058da1b740ab02c3f1df4470d
     922024-03-14T16:31:39Z [net] disconnecting peer=153
     93--
     942024-03-14T16:40:31Z [net] received: getcfheaders (37 bytes) peer=74
     952024-03-14T16:40:31Z [net] peer 74 requested invalid block hash: 000000000000000000017ff36e3f004964cdaea7d5e397965673ec5ef9ce9337
     962024-03-14T16:40:31Z [net] disconnecting peer=74
     97--
     982024-03-14T16:40:31Z [net] received: getcfheaders (37 bytes) peer=184
     992024-03-14T16:40:31Z [net] peer 184 requested invalid block hash: 000000000000000000017ff36e3f004964cdaea7d5e397965673ec5ef9ce9337
    1002024-03-14T16:40:31Z [net] disconnecting peer=184
    101--
    1022024-03-14T16:40:31Z [net] received: getcfheaders (37 bytes) peer=73
    1032024-03-14T16:40:31Z [net] peer 73 requested invalid block hash: 000000000000000000017ff36e3f004964cdaea7d5e397965673ec5ef9ce9337
    1042024-03-14T16:40:31Z [net] disconnecting peer=73
    105--
    1062024-03-14T16:40:31Z [net] received: getcfheaders (37 bytes) peer=202
    1072024-03-14T16:40:31Z [net] peer 202 requested invalid block hash: 000000000000000000017ff36e3f004964cdaea7d5e397965673ec5ef9ce9337
    1082024-03-14T16:40:31Z [net] disconnecting peer=202
    109--
    1102024-03-14T16:40:32Z [net] received: getcfheaders (37 bytes) peer=78
    1112024-03-14T16:40:32Z [net] peer 78 requested invalid block hash: 000000000000000000017ff36e3f004964cdaea7d5e397965673ec5ef9ce9337
    1122024-03-14T16:40:32Z [net] received: getheaders (69 bytes) peer=222
    113--
    1142024-03-14T16:40:32Z [net] received: getcfheaders (37 bytes) peer=229
    1152024-03-14T16:40:32Z [net] peer 229 requested invalid block hash: 000000000000000000017ff36e3f004964cdaea7d5e397965673ec5ef9ce9337
    1162024-03-14T16:40:32Z [net] socket closed for peer=192
    117--
    1182024-03-14T16:40:32Z [net] received: getcfheaders (37 bytes) peer=77
    1192024-03-14T16:40:32Z [net] peer 77 requested invalid block hash: 000000000000000000017ff36e3f004964cdaea7d5e397965673ec5ef9ce9337
    1202024-03-14T16:40:32Z [net] disconnecting peer=77
    121--
    1222024-03-14T16:46:29Z [net] received: getcfheaders (37 bytes) peer=259
    1232024-03-14T16:46:29Z [net] peer 259 requested invalid block hash: 00000000000000000001a680cb297921d300dadaab79df9876303b6c0bd9dd69
    1242024-03-14T16:46:29Z [net] disconnecting peer=259
    125--
    1262024-03-14T16:46:29Z [net] received: getcfheaders (37 bytes) peer=241
    1272024-03-14T16:46:29Z [net] peer 241 requested invalid block hash: 00000000000000000001a680cb297921d300dadaab79df9876303b6c0bd9dd69
    1282024-03-14T16:46:29Z [net] sending inv (37 bytes) peer=265
    129--
    1302024-03-14T17:01:49Z [net] received: getcfheaders (37 bytes) peer=400
    1312024-03-14T17:01:49Z [net] peer 400 requested invalid block hash: 0000000000000000000026ebf8f613a1ce69849f12e2c5f8fd9867c2402e60fc
    1322024-03-14T17:01:49Z [net] disconnecting peer=400
    133--
    1342024-03-14T17:01:49Z [net] received: getcfheaders (37 bytes) peer=303
    1352024-03-14T17:01:49Z [net] peer 303 requested invalid block hash: 0000000000000000000026ebf8f613a1ce69849f12e2c5f8fd9867c2402e60fc
    1362024-03-14T17:01:50Z [net] disconnecting peer=303
    137--
    1382024-03-14T17:01:50Z [net] received: getcfheaders (37 bytes) peer=337
    1392024-03-14T17:01:50Z [net] peer 337 requested invalid block hash: 0000000000000000000026ebf8f613a1ce69849f12e2c5f8fd9867c2402e60fc
    1402024-03-14T17:01:50Z [net] disconnecting peer=337
    141--
    1422024-03-14T17:01:50Z [net] received: getcfheaders (37 bytes) peer=391
    1432024-03-14T17:01:50Z [net] peer 391 requested invalid block hash: 0000000000000000000026ebf8f613a1ce69849f12e2c5f8fd9867c2402e60fc
    1442024-03-14T17:01:50Z [net] disconnecting peer=391
    145--
    1462024-03-14T18:02:26Z [net] received: getcfheaders (37 bytes) peer=828
    1472024-03-14T18:02:26Z [net] peer 828 requested invalid block hash: 000000000000000000032b3666aa4da769d272e90a3b95819433ef1ad8cf0f91
    1482024-03-14T18:02:26Z [net] disconnecting peer=828
    149--
    1502024-03-14T18:02:26Z [net] received: getcfheaders (37 bytes) peer=500
    1512024-03-14T18:02:26Z [net] peer 500 requested invalid block hash: 000000000000000000032b3666aa4da769d272e90a3b95819433ef1ad8cf0f91
    1522024-03-14T18:02:26Z [net] disconnecting peer=500
    153--
    1542024-03-14T18:02:27Z [net] received: getcfheaders (37 bytes) peer=426
    1552024-03-14T18:02:27Z [net] peer 426 requested invalid block hash: 000000000000000000032b3666aa4da769d272e90a3b95819433ef1ad8cf0f91
    1562024-03-14T18:02:27Z [net] disconnecting peer=426
    1572024-03-14T18:02:27Z [net] received: getcfheaders (37 bytes) peer=606
    1582024-03-14T18:02:27Z [net] peer 606 requested invalid block hash: 000000000000000000032b3666aa4da769d272e90a3b95819433ef1ad8cf0f91
    1592024-03-14T18:02:27Z [net] disconnecting peer=606
    160--
    1612024-03-14T18:02:27Z [net] received: getcfheaders (37 bytes) peer=429
    1622024-03-14T18:02:27Z [net] peer 429 requested invalid block hash: 000000000000000000032b3666aa4da769d272e90a3b95819433ef1ad8cf0f91
    1632024-03-14T18:02:27Z [net] disconnecting peer=429
    164--
    1652024-03-14T18:02:27Z [net] received: getcfheaders (37 bytes) peer=425
    1662024-03-14T18:02:27Z [net] peer 425 requested invalid block hash: 000000000000000000032b3666aa4da769d272e90a3b95819433ef1ad8cf0f91
    1672024-03-14T18:02:27Z [net] disconnecting peer=425
    168--
    1692024-03-14T18:26:18Z [net] received: getcfheaders (37 bytes) peer=905
    1702024-03-14T18:26:18Z [net] peer 905 requested invalid block hash: 000000000000000000003b869494f4d6e7de0436d5ecd1b9e897728cdf5ca940
    1712024-03-14T18:26:18Z [net] disconnecting peer=905
    172--
    1732024-03-14T18:26:18Z [net] received: getcfheaders (37 bytes) peer=1003
    1742024-03-14T18:26:18Z [net] peer 1003 requested invalid block hash: 000000000000000000003b869494f4d6e7de0436d5ecd1b9e897728cdf5ca940
    1752024-03-14T18:26:18Z [net] disconnecting peer=1003
    176--
    1772024-03-14T19:08:54Z [net] received: getcfheaders (37 bytes) peer=1363
    1782024-03-14T19:08:54Z [net] peer 1363 requested invalid block hash: 000000000000000000014e6470d64f5f9e9c370325adaa8628841feb07a62ad0
    1792024-03-14T19:08:54Z [net] disconnecting peer=1363
    180--
    1812024-03-14T19:16:00Z [net] received: getcfheaders (37 bytes) peer=1244
    1822024-03-14T19:16:00Z [net] peer 1244 requested invalid block hash: 0000000000000000000262970ea32768668aba73aba631b9a17871fbe988b6c5
    1832024-03-14T19:16:00Z [net] disconnecting peer=1244
    184--
    1852024-03-14T19:47:31Z [net] received: getcfheaders (37 bytes) peer=942
    1862024-03-14T19:47:31Z [net] peer 942 requested invalid block hash: 0000000000000000000197ca35169bbd71bacab0258d773398720a23d0fb4a58
    1872024-03-14T19:47:31Z [net] disconnecting peer=942
    188--
    1892024-03-14T19:47:31Z [net] received: getcfheaders (37 bytes) peer=1066
    1902024-03-14T19:47:31Z [net] peer 1066 requested invalid block hash: 0000000000000000000197ca35169bbd71bacab0258d773398720a23d0fb4a58
    1912024-03-14T19:47:31Z [net] disconnecting peer=1066
    192--
    1932024-03-14T19:47:31Z [net] received: getcfheaders (37 bytes) peer=907
    1942024-03-14T19:47:31Z [net] peer 907 requested invalid block hash: 0000000000000000000197ca35169bbd71bacab0258d773398720a23d0fb4a58
    1952024-03-14T19:47:31Z [net] disconnecting peer=907
    196--
    1972024-03-14T19:47:31Z [net] received: getcfheaders (37 bytes) peer=906
    1982024-03-14T19:47:31Z [net] peer 906 requested invalid block hash: 0000000000000000000197ca35169bbd71bacab0258d773398720a23d0fb4a58
    1992024-03-14T19:47:31Z [net] sending inv (181 bytes) peer=114
    200--
    2012024-03-14T19:51:17Z [net] received: getcfheaders (37 bytes) peer=1822
    2022024-03-14T19:51:17Z [net] peer 1822 requested invalid block hash: 00000000000000000000c855dc4e0cc69918aed13ed048d38018b63e7b9b071c
    2032024-03-14T19:51:17Z [net] disconnecting peer=1822
    204--
    2052024-03-14T19:51:17Z [net] received: getcfheaders (37 bytes) peer=1798
    2062024-03-14T19:51:17Z [net] peer 1798 requested invalid block hash: 00000000000000000000c855dc4e0cc69918aed13ed048d38018b63e7b9b071c
    2072024-03-14T19:51:17Z [net] disconnecting peer=1798
    208--
    2092024-03-14T19:51:58Z [net] received: getcfheaders (37 bytes) peer=1836
    2102024-03-14T19:51:58Z [net] peer 1836 requested invalid block hash: 0000000000000000000170d2609f1b73735872a2242789f2190d846f585bddda
    2112024-03-14T19:51:58Z [net] disconnecting peer=1836
    212--
    2132024-03-14T20:03:34Z [net] received: getcfheaders (37 bytes) peer=1841
    2142024-03-14T20:03:34Z [net] peer 1841 requested invalid block hash: 0000000000000000000219dfc58b29fbf268e0d2c3b0bbf164e34527e3c03c3b
    2152024-03-14T20:03:34Z [net] sending inv (253 bytes) peer=25
    216--
    2172024-03-14T20:03:34Z [net] received: getcfheaders (37 bytes) peer=1875
    2182024-03-14T20:03:34Z [net] peer 1875 requested invalid block hash: 0000000000000000000219dfc58b29fbf268e0d2c3b0bbf164e34527e3c03c3b
    2192024-03-14T20:03:34Z [net] disconnecting peer=1875
    220--
    2212024-03-14T20:11:27Z [net] received: getcfheaders (37 bytes) peer=1837
    2222024-03-14T20:11:27Z [net] peer 1837 requested invalid block hash: 00000000000000000000292964b4b00d1d414583bd18d1ebea7a8041d4409c6d
    2232024-03-14T20:11:27Z [net] disconnecting peer=1837
    224--
    2252024-03-14T21:06:43Z [net] received: getcfheaders (37 bytes) peer=2002
    2262024-03-14T21:06:43Z [net] peer 2002 requested invalid block hash: 00000000000000000001b224ba634525a3263cda1f8cac13209f7c52b800a275
    2272024-03-14T21:06:43Z [net] disconnecting peer=2002
    228--
    2292024-03-14T22:51:15Z [net] received: getcfheaders (37 bytes) peer=1842
    2302024-03-14T22:51:15Z [net] peer 1842 requested invalid block hash: 0000000000000000000069998432cdfe3f87dda9bcd1d33c239fa775fbdfaed4
    2312024-03-14T22:51:15Z [net] disconnecting peer=1842
    

    How did you obtain Bitcoin Core

    Pre-built binaries

    What version of Bitcoin Core are you using?

    v26.0.0

    Operating system and version

    Ubuntu 20.04 LTS

    Machine specifications

    No response

  2. mzumsande commented at 0:03 am on March 15, 2024: contributor
    Comparing the timestamps to those when my node received the respective blocks, it looks to me like these filters are requested immediately after the block was newly found in the network, but at a time when the block hash wasn’t validated and connected yet at your node. Is it possible that the disconnected clients didn’t adhere to this part from BIP157, where they are expected to wait for a headers message before sending the request? StopHash MUST be known to belong to a block accepted by the receiving peer. This is the case if the peer had previously sent a headers or inv message with that block or any descendents. A node that receives getcfilters with an unknown StopHash SHOULD NOT respond.
  3. maflcko commented at 7:14 am on March 15, 2024: member
    IIRC the filters are built in a background thread, which is not waited on, so this may happen even if the remote knows that the block was connected already.
  4. djkazic commented at 12:18 pm on March 15, 2024: none

    OK sounds like this is normal behavior. I’ll take a look at the neutrino side of things.

    Thanks for taking a look @maflcko and @mzumsande!

  5. mzumsande commented at 2:41 pm on March 15, 2024: contributor

    IIRC the filters are built in a background thread, which is not waited on, so this may happen even if the remote knows that the block was connected already.

    Yes, I think so too. Though in that case (if we had connected the tip but not constructed the filter yet) there should be a different error message (“Failed to find block filter in index”) and we wouldn’t disconnect but ignore the request, so it likely didn’t happen here.

    OK sounds like this is normal behavior.

    I would agree that it’s normal to not answer the request (if we really haven’t connected and advertised the block - would be good to double-check that in the log) - but maybe it could still be better to just not answer if the requested blockfilter is 1 above the current tip instead of disconnecting.

  6. bitcoin deleted a comment on Mar 19, 2024
  7. willcl-ark added the label P2P on Mar 20, 2024

github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2024-12-11 03:12 UTC

This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me