Failed loading mempool when restarting bitcoind #29193

issue dev7ba openend this issue on January 6, 2024
  1. dev7ba commented at 10:04 am on January 6, 2024: none

    Is there an existing issue for this?

    • I have searched the existing issues

    Current behaviour

    After a clean shutdown, bitcoind failed to load the majority of mempool transactions from mempool.dat. I keep a node up for months for webpage mempoolexplorer.com with options: maxmempool=2000 mempoolfullrbf=1 mempoolexpiry=999999 to maximize the number of txs in my mempool. The node is currently loading and saving mempool txs when shutdown ok (but with only a small number of them instead of a fully synchronized mempool). So I think It could be related to the currently mempool size spike. (larger than ever according jochen-hoenicke )

    Expected behaviour

    The expected behavior is to save/load all the transactions again no matter the size of the mempool

    Steps to reproduce

    It’s a issue difficult to reproduce, because I have no access to a node syncronized with “the full mempool” since mine failed.

    In order to reproduce the issue you must have access to a big mempool and try to start/stop bitcoind and monitor mempool.dat. (Mine is currenty erased and only with a few transactions)

    Not sure if the problem was writing the txs into mempool.dat or reading them.

    Maybe this utility I created can help copying a live mempool from one node to another:

    https://github.com/dev7ba/mempoolcp

    Relevant log output

    I did not copy the debug.log line (currently erased) but it was something like this:

    Imported mempool transactions from disk: (small number here) succeeded, (big number here) failed, 0 expired, 0 already there, 0 waiting for initial broadcast

    How did you obtain Bitcoin Core

    Pre-built binaries

    What version of Bitcoin Core are you using?

    v24.0.0

    Operating system and version

    Ubuntu 20.04.6 LTS

    Machine specifications

    Intel(R) Core(TM) i5-6260U CPU @ 1.80GHz 16GB RAM

  2. dev7ba renamed this:
    Failed load mempool when restarting bitcoind
    Failed loading mempool when restarting bitcoind
    on Jan 6, 2024
  3. glozow commented at 10:32 am on January 6, 2024: member

    Hard to guess without logs (which would tell us why transactions failed). How much time elapsed between saving the mempool.dat and loading it? Mempool transactions that had confirmed during that time would be marked as “failed.”

    And to clarify, are you restarting with the same config? What are mempoolexpiry and maxmempool now? (Is it possible you have less space or expired old transactions?)

    Not sure if the problem was writing the txs into mempool.dat or reading them.

    Must be loading given the “X failed” log line.

    v24.0.0

    Maybe try upgrading to a newer version?

  4. dev7ba commented at 10:46 am on January 6, 2024: none

    How much time elapsed between saving the mempool.dat and loading it?

    Only a few minutes.

    And to clarify, are you restarting with the same config? What are mempoolexpiry and maxmempool now?

    I restarted with the same config. Checked I have enough disk space.

    Must be loading given the “X failed” log line.

    Yes, I see.

    Maybe try upgrading to a newer version?

    I can’t test it anyway, I’m trying to contact people with a “full mempool”, And asking them to restart the node and see what happens.

  5. maflcko added the label Mempool on Jan 6, 2024
  6. maflcko added the label Data corruption on Jan 6, 2024
  7. maflcko removed the label Data corruption on Jan 6, 2024
  8. deyw-bit commented at 10:14 am on January 11, 2024: none

    I can confirm a similar issue in a node running Bitcoin Core 25.1, as detailed below:

    Config options:

    • maxmempool=2000
    • mempoolexpiry=720
    • mempoolfullrbf=1

    Prior to the node’s restart, the mempool size was approximately 1.14 GB, which filled up over roughly 18 hours of uptime since the last node restart.

    After initiating the shutdown, the node restarted immediately. According to the logs, the mempool was dumped (“Dumped mempool: 1.0479s to copy, 10.5051s to dump”). However, there are no subsequent details indicating that the mempool data was reloaded post-restart.

    Three minutes following the restart, the mempool size was merely 1MB. Ten minutes later, it increased to 18MB and continued to grow gradually, accumulating unconfirmed transactions. After one hour of uptime, the mempool size reached 110MB, with approximately 18,000 pending transactions.

    How did you obtain Bitcoin Core Pre-built binaries: (https://bitcoincore.org/bin/bitcoin-core-25.1/bitcoin-25.1-x86_64-linux-gnu.tar.gz)

    What version of Bitcoin Core are you using? v25.1

    Operating system and version Debian GNU/Linux 12 (bookworm)

    Machine specifications Synology NAS (node running in Docker)

    debug.log (for the one hour starting with the node shutdown) - showing only lines with string ‘Shutdown|mempool|Bitcoin Core version v’:

    2024-01-11T08:55:47Z Shutdown: In progress… 2024-01-11T08:55:57Z Dumped mempool: 0.643629s to copy, 8.92166s to dump 2024-01-11T08:56:11Z Shutdown: done

    RESTART

    2024-01-11T08:56:21Z Bitcoin Core version v25.1.0 (release build) 2024-01-11T08:56:21Z Config file arg: maxmempool=“2000” 2024-01-11T08:56:21Z Config file arg: mempoolexpiry=“720” 2024-01-11T08:56:21Z Config file arg: mempoolfullrbf=“1” 2024-01-11T08:56:23Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space)

  9. maflcko commented at 10:20 am on January 11, 2024: member

    Ten minutes later, it increased to 18MB and continued to grow gradually

    Loading the mempool takes time after a startup. You can monitor whether it is complete over the getmempoolinfo RPC (loaded field). Once it is loaded, the loading result will be printed to the debug log.

  10. deyw-bit commented at 10:25 am on January 11, 2024: none
    Okay, will keep monitoring it, right now (90 minutes after restart), bitcoin-cli getmempoolinfo returns “loaded”: false
  11. dev7ba commented at 12:37 pm on January 11, 2024: none
    In retrospect, I believe what happened is that upon noticing the mempool wasn’t loading, I gracefully shut down the node, causing mempool.dat to be overwritten with the limited contents of the mempool. It might also be advisable not to overwrite the old mempool.dat if it hasn’t finished loading completely.
  12. deyw-bit commented at 1:05 pm on January 11, 2024: none

    Upon examining the entire debug.log, which includes log entries from the past few months - it occasionally took up to nine hours to fully load the mempool on my node.

    It’s plausible that the mempool.dat could potentially be overwritten by the limited contents of the mempool if a shutdown is initiated before the loading of the mempool is completed.

    grep -E 'Shutdown|mempool|Bitcoin Core version v' /volume1/docker/bitcoin/debug.log

    2023-10-23T11:24:47Z Bitcoin Core version v25.0.0 (release build) 2023-10-23T11:24:47Z Config file arg: mempoolfullrbf=“1” 2023-10-23T11:24:48Z * Using 335.0 MiB for in-memory UTXO set (plus up to 286.1 MiB of unused mempool space) 2023-10-23T13:26:39Z Imported mempool transactions from disk: 1131 succeeded, 1655 failed, 0 expired, 0 already there, 0 waiting for initial broadcast 2023-10-23T13:50:54Z Shutdown: In progress… 2023-10-23T13:50:57Z Dumped mempool: 0.0389276s to copy, 1.94065s to dump 2023-10-23T13:51:02Z Shutdown: done 2023-10-23T13:51:09Z Bitcoin Core version v25.0.0 (release build) 2023-10-23T13:51:09Z Config file arg: maxmempool=“2000” 2023-10-23T13:51:09Z Config file arg: mempoolexpiry=“720” 2023-10-23T13:51:09Z Config file arg: mempoolfullrbf=“1” 2023-10-23T13:51:11Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space) 2023-10-23T15:32:53Z Imported mempool transactions from disk: 3139 succeeded, 305 failed, 0 expired, 1 already there, 0 waiting for initial broadcast 2023-11-06T17:51:37Z Shutdown: In progress… 2023-11-06T17:51:46Z Dumped mempool: 0.867882s to copy, 7.10853s to dump 2023-11-06T17:56:22Z Bitcoin Core version v25.1.0 (release build) 2023-11-06T17:56:24Z Config file arg: maxmempool=“2000” 2023-11-06T17:56:24Z Config file arg: mempoolexpiry=“720” 2023-11-06T17:56:24Z Config file arg: mempoolfullrbf=“1” 2023-11-06T17:56:25Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space) 2023-11-06T18:03:58Z Shutdown: In progress… 2023-11-06T18:03:59Z Shutdown: done 2023-11-06T18:04:15Z Bitcoin Core version v25.1.0 (release build) 2023-11-06T18:04:15Z Config file arg: maxmempool=“2000” 2023-11-06T18:04:15Z Config file arg: mempoolexpiry=“720” 2023-11-06T18:04:15Z Config file arg: mempoolfullrbf=“1” 2023-11-06T18:04:16Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space) 2023-11-06T18:07:56Z Shutdown: In progress… 2023-11-06T18:07:57Z Shutdown: done 2023-11-06T18:08:04Z Bitcoin Core version v25.1.0 (release build) 2023-11-06T18:08:04Z Config file arg: maxmempool=“2000” 2023-11-06T18:08:04Z Config file arg: mempoolexpiry=“720” 2023-11-06T18:08:04Z Config file arg: mempoolfullrbf=“1” 2023-11-06T18:08:05Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space) 2023-11-06T18:08:05Z Shutdown requested. Exiting. 2023-11-06T18:08:05Z Shutdown: In progress… 2023-11-06T18:08:05Z Shutdown: done 2023-11-06T18:10:26Z Bitcoin Core version v25.1.0 (release build) 2023-11-06T18:10:26Z Config file arg: maxmempool=“2000” 2023-11-06T18:10:26Z Config file arg: mempoolexpiry=“720” 2023-11-06T18:10:26Z Config file arg: mempoolfullrbf=“1” 2023-11-06T18:10:27Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space) 2023-11-06T23:22:15Z Imported mempool transactions from disk: 144452 succeeded, 7354 failed, 0 expired, 369 already there, 0 waiting for initial broadcast 2023-12-06T15:31:53Z Shutdown: In progress… 2023-12-06T15:32:06Z Dumped mempool: 1.15567s to copy, 10.5175s to dump 2023-12-06T15:32:26Z Shutdown: done 2023-12-06T15:32:35Z Bitcoin Core version v25.1.0 (release build) 2023-12-06T15:32:45Z Config file arg: maxmempool=“2000” 2023-12-06T15:32:45Z Config file arg: mempoolexpiry=“720” 2023-12-06T15:32:45Z Config file arg: mempoolfullrbf=“1” 2023-12-06T15:32:46Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space) 2023-12-06T15:35:10Z Shutdown requested. Exiting. 2023-12-06T15:35:10Z Shutdown: In progress… 2023-12-06T15:35:11Z Shutdown: done 2023-12-06T15:46:49Z Bitcoin Core version v25.1.0 (release build) 2023-12-06T15:46:49Z Config file arg: maxmempool=“2000” 2023-12-06T15:46:49Z Config file arg: mempoolexpiry=“720” 2023-12-06T15:46:49Z Config file arg: mempoolfullrbf=“1” 2023-12-06T15:46:50Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space) 2023-12-06T15:49:07Z Shutdown: In progress… 2023-12-06T15:49:44Z Shutdown: done 2023-12-06T15:49:49Z Bitcoin Core version v25.1.0 (release build) 2023-12-06T15:49:49Z Config file arg: maxmempool=“2000” 2023-12-06T15:49:49Z Config file arg: mempoolexpiry=“720” 2023-12-06T15:49:49Z Config file arg: mempoolfullrbf=“1” 2023-12-06T15:49:50Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space) 2023-12-06T15:51:21Z Bitcoin Core version v25.1.0 (release build) 2023-12-06T15:51:21Z Config file arg: maxmempool=“2000” 2023-12-06T15:51:21Z Config file arg: mempoolexpiry=“720” 2023-12-06T15:51:21Z Config file arg: mempoolfullrbf=“1” 2023-12-06T15:51:22Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space) 2023-12-06T15:53:42Z Shutdown: In progress… 2023-12-06T15:55:04Z Bitcoin Core version v25.1.0 (release build) 2023-12-06T15:55:04Z Config file arg: maxmempool=“2000” 2023-12-06T15:55:04Z Config file arg: mempoolexpiry=“720” 2023-12-06T15:55:04Z Config file arg: mempoolfullrbf=“1” 2023-12-06T15:55:05Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space) 2023-12-06T23:49:10Z Imported mempool transactions from disk: 176381 succeeded, 23591 failed, 91 expired, 2853 already there, 0 waiting for initial broadcast 2024-01-09T15:29:21Z Shutdown: In progress… 2024-01-09T15:29:34Z Dumped mempool: 1.0479s to copy, 10.5051s to dump 2024-01-09T15:29:54Z Shutdown: done 2024-01-09T15:30:03Z Bitcoin Core version v25.1.0 (release build) 2024-01-09T15:30:11Z Config file arg: maxmempool=“2000” 2024-01-09T15:30:11Z Config file arg: mempoolexpiry=“720” 2024-01-09T15:30:11Z Config file arg: mempoolfullrbf=“1” 2024-01-09T15:30:12Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space) 2024-01-10T01:47:06Z Imported mempool transactions from disk: 155031 succeeded, 6745 failed, 4 expired, 1946 already there, 0 waiting for initial broadcast 2024-01-11T08:55:47Z Shutdown: In progress… 2024-01-11T08:55:57Z Dumped mempool: 0.643629s to copy, 8.92166s to dump 2024-01-11T08:56:11Z Shutdown: done 2024-01-11T08:56:21Z Bitcoin Core version v25.1.0 (release build) 2024-01-11T08:56:21Z Config file arg: maxmempool=“2000” 2024-01-11T08:56:21Z Config file arg: mempoolexpiry=“720” 2024-01-11T08:56:21Z Config file arg: mempoolfullrbf=“1” 2024-01-11T08:56:23Z * Using 335.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space) 2024-01-11T20:31:35Z Imported mempool transactions from disk: 146589 succeeded, 5918 failed, 5 expired, 2543 already there, 0 waiting for initial broadcast

  13. glozow commented at 1:21 pm on January 11, 2024: member
    @deyw-bit can you tell us the specs of your machine?
  14. maflcko commented at 1:25 pm on January 11, 2024: member

    I gracefully shut down the node, causing mempool.dat to be overwritten with the limited contents of the mempool.

    There is a check to retain the old mempool in that case. So if you never get along to writing the new mempool, due to repeated restarts, the new transactions will be discarded.

    edit, see code:

    https://github.com/bitcoin/bitcoin/blob/4ae5171d42bd288cbd9a6f307e07b71067b184f5/src/init.cpp#L312

  15. deyw-bit commented at 1:37 pm on January 11, 2024: none

    @deyw-bit can you tell us the specs of your machine?

    I am running the Bitcoin Core v25.1 node in Docker on Synology NAS DS216+II (with 8GB RAM). The node runs in a docker container with OS Debian GNU/Linux 12 (bookworm) with CPU priority set to low and memory limit set to 7 GB.

    The Dockerfile contains following:

    FROM debian:bookworm-slim RUN apt-get update -y && apt-get upgrade -y && apt-get install apt -y RUN apt-get install wget sudo vim gpg curl bash -y RUN wget https://bitcoincore.org/bin/bitcoin-core-25.1/bitcoin-25.1-x86_64-linux-gnu.tar.gz RUN wget https://bitcoincore.org/bin/bitcoin-core-25.1/SHA256SUMS.asc RUN wget https://bitcoincore.org/bin/bitcoin-core-25.1/SHA256SUMS RUN sha256sum –ignore-missing –check SHA256SUMS RUN tar xzvf bitcoin-25.1-x86_64-linux-gnu.tar.gz RUN cd bitcoin-25.1 && ls -al; cp bin/* /bin/; RUN /bin/bitcoind –version

  16. glozow commented at 1:43 pm on January 11, 2024: member
    @deyw-bit How long did IBD take on your machine?
  17. deyw-bit commented at 1:51 pm on January 11, 2024: none

    How long did IBD take on your machine?

    To the best of my recollection, the IBD took approx. 10 days. However, this was a few years ago. I guess last time I triggered IBD was with bitcoin-core-0.21.

  18. fanquake referenced this in commit 05c4c5a434 on Jan 15, 2024
  19. willcl-ark commented at 10:10 am on January 17, 2024: contributor

    Is there anything actionable left here to be done or can we close this out?

    IIUC this mempool was not given enough time to load after restart, but now in addition to getmempoolinfo we have logging from #29227.

    I have increased my maxmempoolsize to see if I can try and re-create the issue, but have only tried loading a 600MB one so far, which was successful and took < 6 minutes:

     0$ grep mempool debug.log
 12024-01-17T09:57:40Z Config file arg: [main] maxmempool="2000"
 22024-01-17T09:57:40Z Config file arg: [main] mempoolfullrbf="1"
 32024-01-17T09:57:41Z * Using 14326.0 MiB for in-memory UTXO set (plus up to 1907.3 MiB of unused mempool space)
 42024-01-17T09:58:04Z Loading 103539 mempool transactions from disk...
 52024-01-17T09:58:11Z Progress loading mempool transactions from disk: 10% (tried 10354, 93185 remaining)
 62024-01-17T09:58:19Z Progress loading mempool transactions from disk: 20% (tried 20708, 82831 remaining)
 72024-01-17T09:58:46Z Progress loading mempool transactions from disk: 30% (tried 31062, 72477 remaining)
 82024-01-17T09:59:02Z Progress loading mempool transactions from disk: 40% (tried 41416, 62123 remaining)
 92024-01-17T10:01:13Z Progress loading mempool transactions from disk: 50% (tried 51770, 51769 remaining)
102024-01-17T10:01:45Z Progress loading mempool transactions from disk: 60% (tried 62124, 41415 remaining)
112024-01-17T10:02:18Z Progress loading mempool transactions from disk: 70% (tried 72478, 31061 remaining)
122024-01-17T10:02:44Z Progress loading mempool transactions from disk: 80% (tried 82832, 20707 remaining)
132024-01-17T10:03:00Z Progress loading mempool transactions from disk: 90% (tried 93186, 10353 remaining)
142024-01-17T10:03:05Z Imported mempool transactions from disk: 102354 succeeded, 1121 failed, 0 expired, 64 already there, 0 waiting for initial broadcast

    Extrapolating1 says that importing a 2GB mempool should take ~< 30 minutes. With low RAM and CPU priority in a container, as described above, I can see this inflating a fair bit.

    Maybe this utility I created can help copying a live mempool from one node to another

    FYI there are savemempool and importmempool RPCs which can dump and load a mempool.dat file too :)

    1. https://m.xkcd.com/605/ ↩︎

  20. glozow commented at 10:35 am on January 17, 2024: member
    +1 @dev7ba there’s not much to go on without logs. Maybe consider updating your software, and open another report with more information if it happens again?
  21. willcl-ark commented at 10:47 am on January 17, 2024: contributor
    OK let’s close for now then. @dev7ba feel free to ping me in here, or open a new issue if this happens again or you have new information.
  22. willcl-ark closed this on Jan 17, 2024


dev7ba glozow deyw-bit maflcko willcl-ark

Labels
Mempool

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-07-05 22:12 UTC
This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me