The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Code Coverage

For detailed information about the code coverage, see the test coverage report.

Reviews

See the guideline for information on the review process.

If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

Conflicts

Reviewers, this pull request conflicts with the following ones:

• #29700 (kernel, refactor: return error status on all fatal errors by ryanofsky)
• #29642 (kernel: Handle fatal errors through return values by TheCharlatan)
• #29641 (scripted-diff: Use LogInfo/LogDebug over LogPrintf/LogPrint by maflcko)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

Why is this needed? A progress log for something that takes less than a second does not sound useful

Why is this needed? A progress log for something that takes less than a second does not sound useful

This is in response to this comment #29227 (review)
the logs I posted in the description are from testnet I can run this on mainnet to get the time it takes on shutdown there

The delay is probably from leveldb, but it would be good to first check

Why is this needed? A progress log for something that takes less than a second does not sound useful

I agree that logging the detailed progress in % is a bit overkill, but IMHO a single line "Dumping xyz mempool transactions to disk..." would still make sense. The "less than a second" data point seems to be closer to best-case, I have one machine here where dumping a full default-sized mempool takes more than 10 seconds.

10 seconds.

Sure, it may take longer than one second, depending on the hardware and its size. However,

• Loading a mempool can take hours, depending on the hardware and its size.
• Loading is done in a background thread, so other stuff is going on and logged at the same time.

Shutdown should be single-threaded, so the debug log should contain the last timestamp, which is enough to derive how long it took to dump the mempool, or whether it is still ongoing. I don't expect anyone to poll the debug log every second to see an update on the progress.

IMHO a single line "Dumping xyz mempool transactions to disk..." would still make sense.

Agree, if there isn't such a log line right now, it could make sense to add it.

logging the detailed progress in % is a bit overkill

+1 to @theStack's comment. Logging the start and end would be sufficient, no need for the 10% increments.

force pushed 33153b0

This removes the 10% increments and now logs a single line with the amount of mempool transactions being written to the disk

utACK 6312513b5074f160971ffec0b093b58b9d3cdaae. Planning to test as well.

I'm seeing an issue during testing. The debug log incorrectly reports 0 MB. Are others able to reproduce my result?

user1@comp1:~/Documents/GitHub/btc29402$ src/bitcoin-cli --rpcwait getmempoolinfo | jq -c '{ transactions: (.size), memory_usage_in_mb: (.usage/1000000) }' | jq; src/bitcoin-cli --rpcwait stop; sleep 10; grep -a Writing ~/.bitcoin/debug.log | tail -2
{
  "transactions": 2529,
  "memory_usage_in_mb": 6.061648
}
Bitcoin Core stopping
2024-02-09T14:11:49Z Writing 2529 mempool transactions to file 0 MB...
2024-02-09T14:11:49Z Writing 0 unbroadcast transactions to file.

I'm seeing an issue during testing. The debug log incorrectly reports 0 MB. Are others able to reproduce my result?

user1@comp1:~/Documents/GitHub/btc29402$ src/bitcoin-cli --rpcwait getmempoolinfo | jq -c '{ transactions: (.size), memory_usage_in_mb: (.usage/1000000) }' | jq; src/bitcoin-cli --rpcwait stop; sleep 10; grep -a Writing ~/.bitcoin/debug.log | tail -2
{
  "transactions": 2529,
  "memory_usage_in_mb": 6.061648
}
Bitcoin Core stopping
2024-02-09T14:11:49Z Writing 2529 mempool transactions to file 0 MB...
2024-02-09T14:11:49Z Writing 0 unbroadcast transactions to file.

It looks like usage from getmempoolinfo is coming from DynamicMemoryUsage in txmempool.cpp
Where I'm calculating sizeof(vinfo) which comes from infoAll in txmempool.cpp. infoAll allocates only mapTx.size()

DynamicMemoryUsage computes like this which includes mapTx.size()

    return memusage::MallocUsage(sizeof(CTxMemPoolEntry) + 15 * sizeof(void*)) * mapTx.size() + memusage::DynamicUsage(mapNextTx) + memusage::DynamicUsage(mapDeltas) + memusage::DynamicUsage(txns_randomized) + cachedInnerUsage;

I think it might make more sense to not have a MB amount on vinfo and print it out for the file size at the end of the creating the mempool file so users are not confused when they see xx amounts in MB and their file actually a different size

it might make more sense to not have a MB amount on vinfo and print it out for the file size at the end of the creating the mempool file so users are not confused when they see xx amounts in MB and their file actually a different size

Approach ACK.

lgtm ACK dbdb7320252fd68415e8b76bad5a2169bd7da241

Seems fine to log when starting to dump the mempool.

ACK 34b6a8dadfb9a279f38fc828d6dff73209928f5d

cr-ACK 4d5b557

Tested from master after merge. lgtm.

2024-03-28T14:37:40Z Writing 21 mempool transactions to file...
2024-03-28T14:37:40Z Writing 0 unbroadcast transactions to file.
2024-03-28T14:37:40Z Dumped mempool: 0.000s to copy, 0.006s to dump, 5795 bytes dumped to file

2024-03-28T14:37:59Z Loading 21 mempool transactions from file...
...
2024-03-28T14:37:59Z Progress loading mempool transactions from file: 14% (tried 3, 18 remaining)
2024-03-28T14:37:59Z msghand thread start
2024-03-28T14:37:59Z init message: Done loading
2024-03-28T14:37:59Z Progress loading mempool transactions from file: 23% (tried 5, 16 remaining)
2024-03-28T14:37:59Z Progress loading mempool transactions from file: 33% (tried 7, 14 remaining)
2024-03-28T14:37:59Z Progress loading mempool transactions from file: 42% (tried 9, 12 remaining)
2024-03-28T14:37:59Z Progress loading mempool transactions from file: 52% (tried 11, 10 remaining)
2024-03-28T14:37:59Z Progress loading mempool transactions from file: 61% (tried 13, 8 remaining)
2024-03-28T14:37:59Z Progress loading mempool transactions from file: 71% (tried 15, 6 remaining)
2024-03-28T14:37:59Z Progress loading mempool transactions from file: 80% (tried 17, 4 remaining)
2024-03-28T14:37:59Z Progress loading mempool transactions from file: 90% (tried 19, 2 remaining)
2024-03-28T14:37:59Z Imported mempool transactions from file: 21 succeeded, 0 failed, 0 expired, 0 already there, 0 waiting for initial broadcast