log: avoid collecting GetSerializeSize data when compact block logging is disabled #33738

pull l0rinc wants to merge 3 commits into bitcoin:master from l0rinc:l0rinc/debug-log-serialization changing 10 files +31 −25
  1. l0rinc commented at 10:57 pm on October 29, 2025: contributor

    Context

    The new accounting options introduced in #32582 can be quite heavy, and not needed when debug logging is disabled.

    Problem

    PartiallyDownloadedBlock::FillBlock() and PeerManagerImpl::SendBlockTransactions() accumulate transaction sizes for debug logging by calling GetTotalSize() in loops, which invokes expensive GetSerializeSize() serializations. The header hash is also only calculated for the debug log.

    Fixes

    Guard the size calculations with LogAcceptCategory() checks so serialization only occurs when compact block debug logging is enabled.

    Also modernized the surrounding code a bit since the change is quite trivial.

    Reproducer

    You can test the change by starting your up-to-date bitcoind node with -debug=cmpctblock and observing the compact block lines such as:

    [cmpctblock] Successfully reconstructed block 00000000000000000001061eaa6c0fe79258e7f79606e67ac495765cb121a520 with 1 txn prefilled, 3122 txn from mempool (incl at least 3 from extra pool) and 641 txn (352126 bytes) requested

     0diff --git a/src/blockencodings.cpp b/src/blockencodings.cpp
     1index 58620c93cc..f16eb38fa5 100644
     2--- a/src/blockencodings.cpp
     3+++ b/src/blockencodings.cpp
     4@@ -186,6 +186,7 @@ bool PartiallyDownloadedBlock::IsTxAvailable(size_t index) const
     5 
     6 ReadStatus PartiallyDownloadedBlock::FillBlock(CBlock& block, const std::vector<CTransactionRef>& vtx_missing, bool segwit_active)
     7 {
     8+    LogInfo("PartiallyDownloadedBlock::FillBlock called");
     9     if (header.IsNull()) return READ_STATUS_INVALID;
    10 
    11     block = header;
    12@@ -218,6 +219,7 @@ ReadStatus PartiallyDownloadedBlock::FillBlock(CBlock& block, const std::vector<
    13     }
    14 
    15     if (LogAcceptCategory(BCLog::CMPCTBLOCK, BCLog::Level::Debug)) {
    16+        LogInfo("debug log enabled");
    17         const uint256 hash{block.GetHash()}; // avoid cleared header
    18         uint32_t tx_missing_size{0};
    19         for (const auto& tx : vtx_missing) tx_missing_size += tx->ComputeTotalSize(); // avoid cleared txn_available
    20diff --git a/src/net_processing.cpp b/src/net_processing.cpp
    21index 5600c8d389..c081825f77 100644
    22--- a/src/net_processing.cpp
    23+++ b/src/net_processing.cpp
    24@@ -2470,6 +2470,7 @@ uint32_t PeerManagerImpl::GetFetchFlags(const Peer& peer) const
    25 
    26 void PeerManagerImpl::SendBlockTransactions(CNode& pfrom, Peer& peer, const CBlock& block, const BlockTransactionsRequest& req)
    27 {
    28+    LogInfo("PeerManagerImpl::SendBlockTransactions called");
    29     BlockTransactions resp(req);
    30     for (size_t i = 0; i < req.indexes.size(); i++) {
    31         if (req.indexes[i] >= block.vtx.size()) {
    32@@ -2480,6 +2481,7 @@ void PeerManagerImpl::SendBlockTransactions(CNode& pfrom, Peer& peer, const CBlo
    33     }
    34 
    35     if (LogAcceptCategory(BCLog::CMPCTBLOCK, BCLog::Level::Debug)) {
    36+        LogInfo("debug log enabled");
    37         uint32_t tx_requested_size{0};
    38         for (const auto i : req.indexes) tx_requested_size += block.vtx[i]->ComputeTotalSize();
    39         LogDebug(BCLog::CMPCTBLOCK, "Peer %d sent us a GETBLOCKTXN for block %s, sending a BLOCKTXN with %u txns. (%u bytes)\n", pfrom.GetId(), block.GetHash().ToString(), resp.txn.size(), tx_requested_size);
    
  2. DrahtBot added the label Utils/log/libs on Oct 29, 2025
  3. DrahtBot commented at 10:57 pm on October 29, 2025: contributor

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

    Code Coverage & Benchmarks

    For details see: https://corecheck.dev/bitcoin/bitcoin/pulls/33738.

    Reviews

    See the guideline for information on the review process.

    Type Reviewers
    ACK danielabrozzoni, davidgumberg
    Concept ACK TheCharlatan, 0xB10C

    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:

    • #32606 (p2p: Drop unsolicited CMPCTBLOCK from non-HB peer by davidgumberg)

    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.

  4. davidgumberg commented at 1:24 am on October 30, 2025: contributor
    Thanks for catching this, the PR seems correct to me, why is it in draft?
  5. TheCharlatan commented at 6:43 am on October 30, 2025: contributor
    Concept ACK
  6. in src/net_processing.cpp:2486 in 17856343f8
    2483+        if (LogAcceptCategory(BCLog::CMPCTBLOCK, BCLog::Level::Debug)) {
    2484+            tx_requested_size += resp.txn[i]->GetTotalSize();
    2485+        }
    2486     }
    2487 
    2488     LogDebug(BCLog::CMPCTBLOCK, "Peer %d sent us a GETBLOCKTXN for block %s, sending a BLOCKTXN with %u txns. (%u bytes)\n", pfrom.GetId(), block.GetHash().ToString(), resp.txn.size(), tx_requested_size);
    


    maflcko commented at 6:43 am on October 30, 2025:

    in theory this seems racy, when the logging is toggled in another thread, but this is probably good enough to ignore.

    Though, on a different note, I wonder if there are other places that could benefit from CTransaction caching. Two full hashes are cached, so caching the size should be cheap in both time and space?


    l0rinc commented at 6:48 am on October 30, 2025:

    the hash is actually eagerly calculated as well - which should also be hidden behind a similar condition, was hoping someone will bring it up :)


    there aren’t any benchmarks for this but a ton of tests failed for the throw check above, so at least it has coverage.


    davidgumberg commented at 0:28 am on October 31, 2025:

    wonder if there are other places that could benefit from CTransaction caching. Two full hashes are cached, so caching the size should be cheap in both time and space?

    I don’t think we should be caching the sizes, since there aren’t really any performance critical users of GetTotalSize(), it’s invoked by these cmpctblock logs, many RPC’s when they do pretty-printing of transactions, and the qt interface’s transaction view, but there are critical paths where CTransaction()’s are constructed.


    the hash is actually eagerly calculated as well

    As far as I can tell, CTransaction’s hashes are computed and cached on construction: https://github.com/bitcoin/bitcoin/blob/6f359695c36c13af832b0b1021dcb3a234f6f219/src/primitives/transaction.cpp#L95-L96 https://github.com/bitcoin/bitcoin/blob/6f359695c36c13af832b0b1021dcb3a234f6f219/src/primitives/transaction.h#L343-L344

    Are you suggesting that the hashes should be computed lazily when CTransaction::GetHash() is first invoked?


    maflcko commented at 6:49 am on October 31, 2025:

    I don’t think we should be caching the sizes,

    Good point. I haven’t looked at the other places where it is used. I guess one could consider renaming GetTotalSize to ComputeTotalSize, to hopefully avoid similar issues of this kind in the future?


    l0rinc commented at 3:14 pm on October 31, 2025:

    As far as I can tell, CTransaction’s hashes are computed and cached on construction

    No, I mean uint256 hash = header.GetHash() is only needed for the debug log - let me try separating all calculations that are only needed for debugging. Given that we’re clearing header and txn_available I understand why the split wasn’t done before. But we can still use block for the hash and vtx_missing for the missing, so I think it should be possible to split the two. That’s a more invasive change but it would separate the performance critical calculations from the debugging data. https://github.com/bitcoin/bitcoin/blob/a0c254c13a3ef21e257cca3493446c632b636b15/src/primitives/block.cpp#L11-L14

    Are you suggesting that the hashes should be computed lazily when CTransaction::GetHash() is first invoked?

    I did investigate that in https://github.com/l0rinc/bitcoin/pull/21, but haven’t finished the investigation since the initial numbers weren’t convincing enough.

    I guess one could consider renaming GetTotalSize to ComputeTotalSize

    Thanks, pushed that in a separate commit (before the rest to showcase why we’re avoiding the call in the first place). It’s small enough that I didn’t bother with a scripted diff.

  7. maflcko commented at 6:43 am on October 30, 2025: member
    is there a benchmark that detects this?
  8. l0rinc marked this as ready for review on Oct 30, 2025
  9. DrahtBot requested review from TheCharlatan on Oct 31, 2025
  10. 0xB10C commented at 1:45 pm on October 31, 2025: contributor
    Concept ACK
  11. refactor: rename `CTransaction::GetTotalSize` to signal that it's not cached
    Transaction hashes are cached, it may not be intuitive that their sizes are actually recalculated every time.
    This is done before the other refactors to clarify why we want to avoid calling this method;
    
    Co-authored-by: maflcko <6399679+maflcko@users.noreply.github.com>
    ec20bdcc16
  12. l0rinc force-pushed on Oct 31, 2025
  13. log,net: avoid `ComputeTotalSize` when logging is disabled
    `PeerManagerImpl::SendBlockTransactions()` previously summed transaction sizes for debug logs by calling `ComputeTotalSize()` inside tight loops, triggering serialization even when logging was off.
    
    Guard the size accumulation with `LogAcceptCategory` so serialization (used only for logging) runs only when compact block debug logging is enabled.
    
    No behavior change when logging is enabled (except for reduced work): the reported counts, hashes, and byte totals remain the same.
    We have already performed the bounds check before, so we can iterate `req.indexes` directly later.
    Separating debug-only work from the critical path reduces risk and favors the performance-critical non-debug case.
    This also narrows the racy scope of when logging is toggled from another thread.
    4e8bba381e
  14. log,blocks: avoid `ComputeTotalSize` and `GetHash()` work when logging is disabled
    Besides the transaction size calculations, `PartiallyDownloadedBlock::FillBlock()` also calculated the header hash that's only needed when debug logging is enabled.
    Since multiple arguments are invalidated after the first iteration (needed for efficient moving), we can't redo the exact same loop, but we can iterate the `missing` arg directly and use the block header (which we've copied at the beginning) for the header hash instead.
    10e0e96e70
  15. l0rinc force-pushed on Oct 31, 2025
  16. luke-jr referenced this in commit 065af0f17c on Nov 5, 2025
  17. danielabrozzoni approved
  18. danielabrozzoni commented at 9:12 am on November 8, 2025: member

    Code Review ACK 10e0e96e703a40b298b87e9943f85d5189b9e3dc

    Code looks good to me, I ran the tests locally, but I didn’t perform any additional testing beyond that.

  19. DrahtBot requested review from davidgumberg on Nov 8, 2025
  20. DrahtBot requested review from 0xB10C on Nov 8, 2025
  21. in src/blockencodings.cpp:229 in 10e0e96e70
    236+        LogDebug(BCLog::CMPCTBLOCK, "Successfully reconstructed block %s with %u txn prefilled, %u txn from mempool (incl at least %u from extra pool) and %u txn (%u bytes) requested\n", hash.ToString(), prefilled_count, mempool_count, extra_count, vtx_missing.size(), tx_missing_size);
    237+        if (vtx_missing.size() < 5) {
    238+            for (const auto& tx : vtx_missing) {
    239+                LogDebug(BCLog::CMPCTBLOCK, "Reconstructed block %s required tx %s\n", hash.ToString(), tx->GetHash().ToString());
    240+            }
    241         }
    


    vasild commented at 5:09 pm on November 20, 2025:

    Would it be useful to print the first 5, even if there are more? E.g.

    0Reconstructed block B required tx 111
    1Reconstructed block B required tx 222
    2Reconstructed block B required tx 333
    3Reconstructed block B required tx 444
    4Reconstructed block B required tx 555 and others
    

    l0rinc commented at 6:19 pm on November 20, 2025:
    Good idea. Should we do it in a follow-up instead?

    davidgumberg commented at 6:25 pm on November 20, 2025:

    I don’t think it’s very helpful to print 5, when I want to know the tx’es causing compact block reconstruction to fail I remove this if statement so that all missing tx’es are printed, and I have a hard time imagining a use case for only wanting the txid’s if it’s less than 5 or only wanting the first 5.

    I think we should print all of the missing transactions every time, but can definitely be discussed in a separate issue/pr.

  22. in src/blockencodings.cpp:203 in 10e0e96e70
    200+            if (vtx_missing.size() <= tx_missing_offset) {
    201                 return READ_STATUS_INVALID;
    202+            }
    203             block.vtx[i] = vtx_missing[tx_missing_offset++];
    204-            tx_missing_size += block.vtx[i]->GetTotalSize();
    205-        } else
    


    vasild commented at 5:18 pm on November 20, 2025:

    I am missing some high level context here, but is this guaranteed to iterate over all members of vtx_missing[]?

    I ask because down there we do iterate the full vtx_missing[] to derive tx_missing_size.


    l0rinc commented at 6:20 pm on November 20, 2025:
    I have tried explaining it in the commit message, can you please point out where more context is necessarry?

    davidgumberg commented at 6:52 pm on November 20, 2025:

    Is this guaranteed to iterate over all members of vtx_missing[]?

    Yes, because of the check below that:

    https://github.com/bitcoin/bitcoin/blob/6b2d17b13220ea69c33b8cab41fe059ff758874c/src/blockencodings.cpp#L211-L212

    We increment tx_missing_offset every time we take a transaction from vtx_missing, so the check enforces that we followed the if branch / took from vtx_missing just as many times as there are members in vtx_missing.

  23. in src/net_processing.cpp:2484 in 4e8bba381e outdated
    2482     }
    2483 
    2484-    LogDebug(BCLog::CMPCTBLOCK, "Peer %d sent us a GETBLOCKTXN for block %s, sending a BLOCKTXN with %u txns. (%u bytes)\n", pfrom.GetId(), block.GetHash().ToString(), resp.txn.size(), tx_requested_size);
    2485+    if (LogAcceptCategory(BCLog::CMPCTBLOCK, BCLog::Level::Debug)) {
    2486+        uint32_t tx_requested_size{0};
    2487+        for (const auto i : req.indexes) tx_requested_size += block.vtx[i]->ComputeTotalSize();
    


    davidgumberg commented at 7:12 pm on November 20, 2025:

    nit:

    0        for (const auto &tx : resp.txn) tx_requested_size += tx->ComputeTotalSize();
    
  24. DrahtBot requested review from davidgumberg on Nov 20, 2025
  25. davidgumberg commented at 10:02 pm on November 20, 2025: contributor

    crACK 10e0e96e703a40b298b8

    Lightly tested running on mainnet, logs for receiving look good:

    02025-11-20T21:56:39.778340Z [cmpctblock] Successfully reconstructed block 000000000000000000004152f92a1ec0a2f2e4356264001b11361f35247f641d with 1 txn prefilled, 3940 txn from mempool (incl at least 6 from extra pool) and 141 txn (64021 bytes) requested
    

    Haven’t received a GETBLOCKTXN request yet.


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: 2025-11-21 21:13 UTC

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