Repository: bitcoin/bitcoin (language: cpp)

Issue:
CPU DoS on mainnet in debug mode
I've been seeing 100% cpu usage on one of my bitcoind nodes recently, with transactions taking >60s to be accepted into the mempool. Digging into it, the problem seems to be `BOOST_MULTI_INDEX_ENABLE_SAFE_MODE`  which was introduced in #24395. That results in iterator destruction taking O(n) time (in the number of other active iterators on the same multi-index) in the worst case, rather than O(1) time, due to keeping the iterators in a [singly linked list](https://www.boost.org/doc/libs/1_82_0/boost/multi_index/detail/safe_mode.hpp):

```
 * Iterators are chained in a single attached list, whose header is
 * kept by the container. More elaborate data structures would yield better
 * performance, but I decided to keep complexity to a minimum since
 * speed is not an issue here.
```

Speed does become an issue here though, as we keep an iterator around for every mempool entry (in `vTxHashes`).

This isn't always a problem: presumably in the normal case new iterators are added to the head of the list then removed while they're still roughly at the head of the list, giving O(1) timing; but somehow having a full mempool (and hence TrimToSize actually doing things) triggers worst case behaviour?


Discussion / hints:
I experienced this as well.
Been seeing this on my 24.0.1 public nodes as well, it's not 100% CPU usage as such, but a single CPU core is spinning at 100%. One 24.0.1 node with listen=0 did not seem affected.

I noticed that after a node restart, the CPU usage went back to normal (and is still normal after a day) even though the mempool was loaded from disk - though it might be because it's no longer entirely full due to mempoolminfee.

PS: These nodes do **not** run in debug mode.
Just to confirm, yours was in debug mode as well? Otherwise it'd be concerning.

-------- Original Message --------
On May 7, 2023, 8:39 PM, ArmchairCryptologist wrote:

> Been seeing this on my 24.0.1 public nodes as well, it's not 100% CPU usage as such, but a single CPU core is spinning at 100%. One 24.0.1 node with listen=0 did not seem affected.
>
> I noticed that after a node restart, the CPU usage went back to normal (and is still normal after a day) even though the mempool was loaded from disk - though it might be because it's not entirely full.
>
> —
> Reply to this email directly, [view it on GitHub](https://github.com/bitcoin/bitcoin/issues/27586#issuecomment-1537513884), or [unsubscribe](https://github.com/notifications/unsubscribe-auth/AFLK3F7KEP44Z6OFB25VRUDXE7T6FANCNFSM6AAAAAAXXYXUTA).
> You are receiving this because you commented.Message ID: ***@***.***>
> Just to confirm, yours was in debug mode as well? Otherwise it'd be concerning.

My nodes are NOT in debug mode, no. I run four public nodes (24.0.1) with different server hosts, and all four of them were spinning a CPU core at 100% and experiencing slowness with block/transaction handling when I checked them yesterday, two to the point where they started occasionally dropping connectivity to my private nodes. Like I mentioned, one 24.0.1 node which does not accept incoming connections (but is connected to untrusted nodes) did not have this issue. The other private nodes still run 23.0.0 and also do not have any issues, though these only connect through my own public nodes so they aren't directly exposed to untrusted nodes.
Of the four nodes, the one that was restarted on May 6th is now back to spinning 100% of a CPU core (60% average CPU usage on a two-core VM the last hour) while the three that were restarted yesterday are also seeing high CPU usage but not 100% all the time (between 30% and 38% average CPU usage on a two-core VM), so it's building back up relatively quickly. I also verified that the mempool is not fully committed (usage is at 251217552).

There were around 15 peers with bytessent_per_msg.inv over 100000 without any received ones, but even after doing setban on them and verifying that they have been disconnected, the CPU usage did not drop noticeably if at all. This is probably because the node has 180 connected peers, and 140+ of those have both bytessent_per_msg.inv and bytesrecv_per_msg.inv over 100000, so disconnecting 15 of them for not sending any probably doesn't do much..

Based on what you say about it being a different bug I assume that it is not an issue introduced with 24.0, but I reverted one of the nodes to 23.0 just to verify.
> Just to confirm, yours was in debug mode as well? Otherwise it'd be concerning.

What is debug mode? A binary compiled with `--enable-debug` option or `debug=1` saved in bitcoin.conf?

> What is debug mode? A binary compiled with `--enable-debug` option or `debug=1` saved in bitcoin.conf?
> 
> 

Compiled with `--enable-debug`
Same issue with 24.0.1 node today and went back to normal after daemon reload. My node do NOT run in debug mode too.
I have the same problem. `bitcoind` started using 100% cpu (single thread) on my servers. I used the binary from https://bitcoincore.org/bin/bitcoin-core-24.0.1/bitcoin-24.0.1-x86_64-linux-gnu.tar.gz

<img src="https://img.poiuty.com/a/3c/c68204e690ae2d605cfd60e03eee0f3c.jpg">

Built bitcoind from source (v24.0.1.tar.gz). Works fine for an hour now.
```
./configure --without-gui --disable-zmq --disable-wallet
```

<img src="https://img.poiuty.com/a/7b/5234d849fcf5248c4a1adaf5011bc57b.jpg">
> Same issue with 24.0.1 node today and went back to normal after daemon reload. My node do NOT run in debug mode too.

Same here since yesterday, using the 24.0.1 binaries NOT running in debug mode. (Binaries from https://bitcoincore.org/bin/bitcoin-core-24.0.1/bitcoin-24.0.1-x86_64-linux-gnu.tar.gz). I didn't restart the node, but used the setban approach as pointed out here https://github.com/bitcoin/bitcoin/issues/27586#issuecomment-1537784340

Since then, the single core load has decreased to 45% without restart and made the node cli and RPC calls responsive again, regardless of mempool allocation peaking at 300MB. So this has brought relief to some extent.

Using this command to identify those peers: `bitcoin-cli getpeerinfo | jq -r '.[] | if (.bytessent_per_msg.inv > 100000 and .bytesrecv_per_msg.inv == null) then .addr else empty end'`

The above command on my listening node (running a mess of commits on top of master from ~March) returns localhost (probably my mempool instance) plus 10 other peers. Five of those are universities (e.g. [DNS Bitcoin Monitoring](https://www.dsn.kastel.kit.edu/bitcoin/data.html), 3 Digital Ocean. Some of them are bitcoinj wallets, i.e. you wouldn't expect them to relay anything to us (except perhaps if they make a transaction).

CPU use looks normal to me, it's not compiled with --enable-debug. Last restart was 3 days ago. I also have `peerbloomfilters=0` (default since v0.19).


Just to confirm, after a day or so I'm seeing the same kind of CPU load increasing over time with the node I downgraded to 23.0.0, so this other issue probably was not introduced with 24.0.1.

Reducing maxconnections to a low-ish number (100 or less) seems to at least significantly delay the problem, though I can't say yet whether it'll mitigate it entirely. 150-200 is definitely causing issues on a 4 GHz Xeon.

> I didn't restart the node, but used the setban approach as pointed out here https://github.com/bitcoin/bitcoin/issues/27586#issuecomment-1537784340

That comment was actually a reply to a comment by @ajtowns who pointed that out as a possible mitigation to a potential issue he identified, but said comment seems to have been removed (too much information?), so it probably seems somewhat out-of-context.
@ArmchairCryptologist do you have `peerbloomfilters` on?
> @ArmchairCryptologist do you have peerbloomfilters on?

Nope. The nodes are pretty much running with the default settings except for maxconnections. But like I mentioned earlier, I'm only seeing this on well-connected public nodes, so if you get <100 incoming connections you might not be having this issue.
This is true for 2 (two) full nodes that run with `pruning` off, `peerbloomfilters` off, `maxmempool` set to 2048 and `maxconnections` set to 500, where both have an average between 170 and 225 active peers.  They are also **NOT** in debug mode, but still affected by abnormally high CPU usage and RAM consumption.

Both use fairly reasonable CPUs and are at 100% CPU usage and a lot of RAM (like 8GB only bitcoind). For reference:

  "connections": 222,
  "connections_in": 212,
  "connections_out": 10,

![bitcoind-res](https://github.com/bitcoin/bitcoin/assets/6549887/c0c43907-ca26-4af7-bedc-4058f0660370)

> This is true for 2 (two) full nodes that run with pruning off, peerbloomfilters off, maxmempool set to 2048 and maxconnections set to 500, where both have an average between 170 and 225 active peers.

This particular case seems like you have configured bitcoind to do more than your cpu can handle during higher-traffic times. Consider reducing maxconnections for now. And perhaps shrink maxmempool - may I ask why you are using 2048?
For the reporters using [htop](https://htop.dev/) to analyze CPU usage (which is the case for at least @poiuty @gits7r, according to the posted screenshots): could you go to the display settings (reachable via key F2) and activate "tree view" and the global option "show custom thread names"? This would show the CPU usage per thread, which could be interesting for further investigation, e.g.:

![image](https://github.com/bitcoin/bitcoin/assets/91535/3b20748f-86db-4f4c-a185-496135d3b5ec)

(FWIW I'm running a listening pruned node on some quite lame dual-core virtual server, have rarely seen more than 10-15% CPU usage the last few days; will tinker around with higher maxmempool/maxconnections settings to see if I can reproduce the issue reported above).
I think #27610 should improve the non-debug cpu usage in b-msghand. Both commits should cleanly cherry-pick for on top of v24.x; and the first commit (the "CompareDepthAndScore" one) should cleanly cherry-pick for v23.x.
> Using this command to identify those peers: `bitcoin-cli getpeerinfo | jq -r '.[] | if (.bytessent_per_msg.inv > 100000 and .bytesrecv_per_msg.inv == null) then .addr else empty end'`

Someone posted https://news.ycombinator.com/item?id=35824998 linking to a DoS script https://github.com/visualbasic6/drain/blob/c8373b55d83832f95fb0a77aca56436adeffb58d/drain-btc.py a day before this issue. It's possible someone may be using the script targeting public nodes. 

Check your `bytessent_per_msg.headers` for anomalous hits. I'm seeing `bytessent_per_msg.headers=2542689711` and 100% CPU util on `b-msghand` thread when testing the DoS script for 10s with single thread on my localhost node.
> It's possible someone may be using the script targeting public nodes.

FWIW, I was not seeing any ridiculous bytessent_per_msg.inv numbers on any of my nodes. In fact the highest counts on all of my public nodes is my private nodes, but not by much.

A notable change happened yesterday (May 9th) around 14:25 UTC where the CPU load on all the public nodes dropped drastically at the same time, and they all look normal at present. The high-fee BRC-20 token spam we were seeing also appear to have quieted down a bit, so it seems likely that the issues were simply related to that. Unless it starts back up it might be hard to diagnose this further without artificially generating a similar traffic pattern.

Incidentally, the command originally provided by @ajtowns which lists the peer addresses with the inv numbers was:

`bitcoin-cli getpeerinfo | jq -j '.[] | (.bytessent_per_msg.inv, " ", .bytesrecv_per_msg.inv, " ", .addr, "\n")' | grep ' null ' | sort -n`

(Remove the `| grep ' null '` part to show nodes that are also sending invs.)

Edit: I misread your post, I see you are referring to the headers field. I'm not seeing any anomalous hits at present, and it doesn't seem consistent with the behavior I was seeing with gradual increase of CPU usage over time, but I'll check it to rule it out if the problem reappears.
Using: `bitcoin-cli getpeerinfo | jq -j '.[] | (.bytessent_per_msg.headers, " ", .addr, "\n")' | sort -n | grep -v 127.0.0.1`

My highest `bytessent_per_msg.headers` 35 KB (for non localhost), i.e. a _lot_ less than the 2.5 GB @ayeowch is seeing. CPU still calm. The node has 114 inbound connections (and 10 out).

I guess that means none of my peers have asked me for the full 64 MB headers chain during this session.
@ayeowch running that particular script against a modest Intel i5-8400 with 6 cores, either from another computer on the LAN or from the machine itself, I don't see any noticeable CPU difference (compared to all the other stuff its running). Even when downloading 10GB of headers in a few minutes, which is probably a faster download rate than you experienced given the total (though you tally disconnected peers too I suppose).
FWIW I am also seeing some sustained high CPU usage on a listening (non debug mode) 24.0.1 node from the `b-msghand` thread:

![htop ~_001](https://github.com/bitcoin/bitcoin/assets/6606587/d80b439c-ba93-4659-8cfc-b6be7981b1c6)


I am used to seeing this thread at ~1% on this machine:

![htop ~_002](https://github.com/bitcoin/bitcoin/assets/6606587/8f31aa77-98ea-4aac-9ed9-ba6a466de9cd)


I also have a number of these "hungry" peers:

```fish
bitcoin in ~ took 53s ➜ bitcoin-cli getpeerinfo | jq -j '.[] | (.bytessent_per_msg.inv, " ", .bytesrecv_per_msg.inv, " ", .addr, "\n")' | grep ' null ' | sort -n
2501 null xx.xx.xx.xx:xxxx
6379589 null xx.xx.xx.xx:xxxx
19839661 null xx.xx.xx.xx:xxxx
24468696 null xx.xx.xx.xx:xxxx
38336458 null xx.xx.xx.xx:xxxx
62889263 null xx.xx.xx.xx:xxxx
79513965 null xx.xx.xx.xx:xxxx
80910412 null xx.xx.xx.xx:xxxx
80972609 null xx.xx.xx.xx:xxxx
82147824 null xx.xx.xx.xx:xxxx
343710563 null xx.xx.xx.xx:xxxx
484505648 null xx.xx.xx.xx:xxxx
484552023 null xx.xx.xx.xx:xxxx
484575864 null xx.xx.xx.xx:xxxx
```

This hardware usually deals with `bitcoind` pretty easily and has been running with maxconnections for a while:

```fish
bitcoin in ~ ➜ bitcoin-cli getnettotals
{
  "totalbytesrecv": 49382137900,
  "totalbytessent": 1290284641863,
  "timemillis": 1683631908883,
  "uploadtarget": {
    "timeframe": 86400,
    "target": 0,
    "target_reached": false,
    "serve_historical_blocks": true,
    "bytes_left_in_cycle": 0,
    "time_left_in_cycle": 0
  }
}
```

I will cherry-pick https://github.com/bitcoin/bitcoin/pull/27610 on top of 24.0.1 and see how it fares.
@ayeowch, I ran the script on several vps. Generated a lot of traffic and CPU load increased.
But, the time `bitcoind` was using 100% CPU (single thread) I didn't see much network traffic.

<img src="https://img.poiuty.com/a/ae/f9a79fffd2136c3cfba61a103c3575ae.jpg">

<img src="https://img.poiuty.com/a/d6/9ab34f93219d8f00e91e283c2c750ed6.jpg">

<img src="https://img.poiuty.com/a/58/40789731a81d2332a97a7305fb54af58.jpg">
> > Using this command to identify those peers: `bitcoin-cli getpeerinfo | jq -r '.[] | if (.bytessent_per_msg.inv > 100000 and .bytesrecv_per_msg.inv == null) then .addr else empty end'`
> 
> Someone posted https://news.ycombinator.com/item?id=35824998 linking to a DoS script https://github.com/visualbasic6/drain/blob/c8373b55d83832f95fb0a77aca56436adeffb58d/drain-btc.py a day before this issue. It's possible someone may be using the script targeting public nodes.
> 
> Check your `bytessent_per_msg.headers` for anomalous hits. I'm seeing `bytessent_per_msg.headers=2542689711` and 100% CPU util on `b-msghand` thread when testing the DoS script for 10s with single thread on my localhost node.

@ayeowch I haven't tested this, but can't you mitigate the damage done by the script by setting `-maxuploadtarget` ? 
I presume this is still an issue? If yes, what about filing a new one, given that this issue is about `--enable-debug` (not `-debug`), and most comments here may be about a recently fixed issue #https://github.com/bitcoin/bitcoin/issues/27623 and not about `--enable-debug` performance?
I'm also seeing the same issue.. The load average suddenly increased from 0.25 to 1+. From the graph its clear it started on the 6th of May:

![load-pinpoint=1683143407,1683834607](https://github.com/bitcoin/bitcoin/assets/5763256/55401b14-3d6c-45f4-b8d3-3983405cc5ae)

> I presume this is still an issue?

I haven't seen any notable issues since the BRC-20 spam died down a few days ago, one node with 412 incoming connections is currently sitting at ~16% average CPU usage.

> I'm also seeing the same issue.. The load average suddenly increased from 0.25 to 1+.

You probably need to restart the node to clear it up after it's started spinning, a few days ago I had one node still spinning even after dropping to <80 connections due to timeouts/disconnects.

> You probably need to restart the node to clear it up after it's started spinning

You were right.. restarting it dropped CPU usage from 100 percent to about 3 percent immediately. I hope it will stay this way as rc3 (which should fix it) still hasn't been released.
Maybe we can move the boost option into a new `--enable-slow-debug` option, and just enable that for fuzzing and perhaps one of the CI tasks?

```diff
diff --git a/configure.ac b/configure.ac
index cbbf8d6172..fbf7a72e7b 100644
--- a/configure.ac
+++ b/configure.ac
@@ -306,6 +306,13 @@ AC_ARG_ENABLE([debug],
     [enable_debug=$enableval],
     [enable_debug=no])
 
+dnl Enable slow debug
+AC_ARG_ENABLE([slow-debug],
+    [AS_HELP_STRING([--enable-slow-debug],
+                    [use compiler flags and macros suited for debugging that may cause slowdown (default is no)])],
+    [enable_slow_debug=$enableval],
+    [enable_slow_debug=no])
+
 dnl Enable different -fsanitize options
 AC_ARG_WITH([sanitizers],
     [AS_HELP_STRING([--with-sanitizers],
@@ -1482,7 +1489,7 @@ if test "$use_boost" = "yes"; then
   AX_CHECK_PREPROC_FLAG([-DBOOST_NO_CXX98_FUNCTION_BASE], [BOOST_CPPFLAGS="$BOOST_CPPFLAGS -DBOOST_NO_CXX98_FUNCTION_BASE"], [], [$CXXFLAG_WERROR],
                         [AC_LANG_PROGRAM([[#include <boost/config.hpp>]])])
 
-  if test "$enable_debug" = "yes" || test "$enable_fuzz" = "yes"; then
+  if (test "$enable_debug" = "yes" && test "$enable_slow_debug" = "yes") || test "$enable_fuzz" = "yes"; then
     BOOST_CPPFLAGS="$BOOST_CPPFLAGS -DBOOST_MULTI_INDEX_ENABLE_SAFE_MODE"
   fi
```
See also https://github.com/bitcoin/bitcoin/pull/27300#pullrequestreview-1352821536

Fix patch:
diff --git a/configure.ac b/configure.ac
index fc692c4f6aa25..8015813ec7ed7 100644
--- a/configure.ac
+++ b/configure.ac
@@ -1491,10 +1491,6 @@ if test "$use_boost" = "yes"; then
   AX_CHECK_PREPROC_FLAG([-DBOOST_NO_CXX98_FUNCTION_BASE], [BOOST_CPPFLAGS="$BOOST_CPPFLAGS -DBOOST_NO_CXX98_FUNCTION_BASE"], [], [$CXXFLAG_WERROR],
                         [AC_LANG_PROGRAM([[#include <boost/config.hpp>]])])
 
-  if test "$enable_debug" = "yes" || test "$enable_fuzz" = "yes"; then
-    BOOST_CPPFLAGS="$BOOST_CPPFLAGS -DBOOST_MULTI_INDEX_ENABLE_SAFE_MODE"
-  fi
-
   if test "$suppress_external_warnings" != "no"; then
     BOOST_CPPFLAGS=SUPPRESS_WARNINGS($BOOST_CPPFLAGS)
   fi


Test patch:
diff --git a/ci/test/00_setup_env_i686_multiprocess.sh b/ci/test/00_setup_env_i686_multiprocess.sh
index 9e3ea0d383905..8ab4d54d31877 100755
--- a/ci/test/00_setup_env_i686_multiprocess.sh
+++ b/ci/test/00_setup_env_i686_multiprocess.sh
@@ -12,6 +12,7 @@ export CI_IMAGE_NAME_TAG=ubuntu:20.04
 export PACKAGES="cmake python3 llvm clang g++-multilib"
 export DEP_OPTS="DEBUG=1 MULTIPROCESS=1"
 export GOAL="install"
-export BITCOIN_CONFIG="--enable-debug CC='clang -m32' CXX='clang++ -m32' LDFLAGS='--rtlib=compiler-rt -lgcc_s'"
+export BITCOIN_CONFIG="--enable-debug CC='clang -m32' CXX='clang++ -m32' \
+LDFLAGS='--rtlib=compiler-rt -lgcc_s' CPPFLAGS='-DBOOST_MULTI_INDEX_ENABLE_SAFE_MODE'"
 export TEST_RUNNER_ENV="BITCOIND=bitcoin-node"
 export TEST_RUNNER_EXTRA="--nosandbox"
diff --git a/ci/test/00_setup_env_native_fuzz_with_msan.sh b/ci/test/00_setup_env_native_fuzz_with_msan.sh
index 35a0de8034e66..dd694f818c876 100755
--- a/ci/test/00_setup_env_native_fuzz_with_msan.sh
+++ b/ci/test/00_setup_env_native_fuzz_with_msan.sh
@@ -17,7 +17,7 @@ export PACKAGES="clang-16 llvm-16 libclang-rt-16-dev cmake"
 # BDB generates false-positives and will be removed in future
 export DEP_OPTS="NO_BDB=1 NO_QT=1 CC='clang' CXX='clang++' CFLAGS='${MSAN_FLAGS}' CXXFLAGS='${MSAN_AND_LIBCXX_FLAGS}'"
 export GOAL="install"
-export BITCOIN_CONFIG="--enable-fuzz --with-sanitizers=fuzzer,memory --disable-hardening --with-asm=no CC=clang CXX=clang++ CFLAGS='${MSAN_FLAGS}' CXXFLAGS='${MSAN_AND_LIBCXX_FLAGS}'"
+export BITCOIN_CONFIG="--enable-fuzz --with-sanitizers=fuzzer,memory --disable-hardening --with-asm=no CC=clang CXX=clang++ CFLAGS='${MSAN_FLAGS}' CPPFLAGS='-DBOOST_MULTI_INDEX_ENABLE_SAFE_MODE' CXXFLAGS='${MSAN_AND_LIBCXX_FLAGS}'"
 export USE_MEMORY_SANITIZER="true"
 export RUN_UNIT_TESTS="false"
 export RUN_FUNCTIONAL_TESTS="false"
diff --git a/ci/test/00_setup_env_native_qt5.sh b/ci/test/00_setup_env_native_qt5.sh
index bb10a2a2de8f8..3a1d7808f1523 100755
--- a/ci/test/00_setup_env_native_qt5.sh
+++ b/ci/test/00_setup_env_native_qt5.sh
@@ -17,5 +17,5 @@ export RUN_UNIT_TESTS="false"
 export GOAL="install"
 export NO_WERROR=1  # -Werror=maybe-uninitialized
 export DOWNLOAD_PREVIOUS_RELEASES="true"
-export BITCOIN_CONFIG="--enable-zmq --with-libs=no --with-gui=qt5 --enable-reduce-exports \
---enable-debug CFLAGS=\"-g0 -O2 -funsigned-char\" CXXFLAGS=\"-g0 -O2 -funsigned-char\""
+export BITCOIN_CONFIG="--enable-zmq --with-libs=no --with-gui=qt5 --enable-reduce-exports --enable-debug \
+CFLAGS=\"-g0 -O2 -funsigned-char\" CPPFLAGS='-DBOOST_MULTI_INDEX_ENABLE_SAFE_MODE' CXXFLAGS=\"-g0 -O2 -funsigned-char\""