Logs of "Mempool in non-optimal ordering after block/additions(s)"

b10c · May 12, 2026, 12:33pm

While chatting with @instagibbs, he mentioned we should not be seeing any Mempool in non-optimal ordering after X logs on a node with mempool logging turned on.

github.com/bitcoin/bitcoin

src/txmempool.cpp

10ca73c02


      
                  // First splice this entry into mapTx.
                  auto node_handle = changeset->m_to_add.extract(tx_entry);
                  auto result = mapTx.insert(std::move(node_handle));
          
                  Assume(result.inserted);
                  txiter it = result.position;
          
                  addNewTransaction(it);
              }
              if (!m_txgraph->DoWork(/*max_cost=*/POST_CHANGE_COST)) {
                  LogDebug(BCLog::MEMPOOL, "Mempool in non-optimal ordering after addition(s).");
              }
          }
          
          void CTxMemPool::addNewTransaction(CTxMemPool::txiter newit)
          {
              const CTxMemPoolEntry& entry = *newit;
          
              // Update cachedInnerUsage to include contained transaction's usage.
              // (When we update the entry for in-mempool parents, memory usage will be
              // further updated.)

github.com/bitcoin/bitcoin

src/txmempool.cpp

10ca73c02


      
              auto all_to_remove = m_txgraph->GetDescendantsUnion(to_remove, TxGraph::Level::MAIN);
          
              for (auto ref : all_to_remove) {
                  auto it = mapTx.iterator_to(static_cast<const CTxMemPoolEntry&>(*ref));
                  removeUnchecked(it, MemPoolRemovalReason::REORG);
              }
              for (indexed_transaction_set::const_iterator it = mapTx.begin(); it != mapTx.end(); it++) {
                  assert(TestLockPointValidity(chain, it->GetLockPoints()));
              }
              if (!m_txgraph->DoWork(/*max_cost=*/POST_CHANGE_COST)) {
                  LogDebug(BCLog::MEMPOOL, "Mempool in non-optimal ordering after reorg.");
              }
          }
          
          void CTxMemPool::removeConflicts(const CTransaction &tx)
          {
              // Remove transactions which depend on inputs of tx, recursively
              AssertLockHeld(cs);
              for (const CTxIn &txin : tx.vin) {
                  auto it = mapNextTx.find(txin.prevout);
                  if (it != mapNextTx.end()) {

Turns out, while grepping for it, there appear to be a few of these log messages in my logs:

debug.log-20260502-alice.gz:2026-05-02T10:21:57.209033Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260502-alice.gz:2026-05-02T10:21:57.494597Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-alice.gz:2026-05-02T10:21:57.543092Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-dave.gz:2026-05-02T10:21:57.170824Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260502-dave.gz:2026-05-02T10:21:57.428782Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-dave.gz:2026-05-02T10:21:57.481277Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-greg.gz:2026-05-02T10:21:58.480026Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260502-greg.gz:2026-05-02T10:21:59.101458Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-greg.gz:2026-05-02T10:21:59.246079Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-kane.gz:2026-05-02T10:21:57.370745Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260502-kane.gz:2026-05-02T10:21:58.372083Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-kane.gz:2026-05-02T10:21:58.387310Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-luke.gz:2026-05-02T10:22:00.051254Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260502-luke.gz:2026-05-02T10:22:01.221771Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-luke.gz:2026-05-02T10:22:01.869515Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-mike.gz:2026-05-02T10:21:58.392768Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260502-mike.gz:2026-05-02T10:21:58.591779Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-mike.gz:2026-05-02T10:21:58.620257Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-owen.gz:2026-05-02T10:21:56.400585Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260502-owen.gz:2026-05-02T10:21:56.740554Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260502-owen.gz:2026-05-02T10:21:56.927533Z [msghand] [mempool] Mempool in non-optimal ordering after addition(s).
debug.log-20260503-alice.gz:2026-05-03T11:07:02.853936Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-alice.gz:2026-05-03T22:40:04.199623Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-dave.gz:2026-05-03T11:07:03.200111Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-dave.gz:2026-05-03T22:40:04.808721Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-greg.gz:2026-05-03T11:07:03.733736Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-greg.gz:2026-05-03T22:40:07.687305Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-kane.gz:2026-05-03T11:07:02.255613Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-kane.gz:2026-05-03T22:40:03.207174Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-luke.gz:2026-05-03T11:07:07.459751Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-luke.gz:2026-05-03T22:40:11.845625Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-mike.gz:2026-05-03T11:07:04.036649Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-mike.gz:2026-05-03T22:40:05.604810Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-owen.gz:2026-05-03T11:07:02.204334Z [msghand] [mempool] Mempool in non-optimal ordering after block.
debug.log-20260503-owen.gz:2026-05-03T22:40:03.341977Z [msghand] [mempool] Mempool in non-optimal ordering after block.

b10c · May 12, 2026, 12:34pm

I’m now running GitHub - instagibbs/bitcoin at nonoptimal-cluster-dump · GitHub at bench: simulate real RBF tail-nip on hard clusters · instagibbs/bitcoin@b36ab29 · GitHub on one of the demo.peer.observer nodes to have some more data to debug this.

instagibbs · May 12, 2026, 12:37pm

Copying my comments from IRC:

14:42 <instagibbs> sipa b10c I think what's happening is pretty straight forward: mempool is full of \~25 count linear chain clusters, all roughly the same cfr. a block comes in, skims off a bunch of the cluster prefixes (1 or two tx each), leaving most of hte clusters still with almost a couple dozen. looks like most recent block I measured touched almost 40 such
14:42 <instagibbs> clusters, and it exhausts the DoWork budget with \~11 clusters left over.
14:44 <instagibbs> obviously it makes good progress each incantation of DoWork

So basically I think this could happen even in typical operation. I think seeing how often it happens and how “bad” it is is also helpful for future DoWork re-budgeting efforts that may happen.

b10c · May 17, 2026, 10:35pm

I’ve uploaded a few cluster_dump_1778*.json files to BNOC data-share into the 2026-05-non-optimal-mempool-dumps folder.