mempool: add structured logging to orphan management and validation

This commit completes the structured logging coverage for TxMempoolV2 by
instrumenting the orphan management, validation pipeline, and transaction
validator components.

Author: Roasbeef

mempool/orphan.go

@@ -1,6 +1,7 @@
 package mempool
 
 import (
+	"context"
 	"errors"
 	"fmt"
 	"sync"
@@ -160,25 +161,47 @@ func (om *OrphanManager) AddOrphan(tx *btcutil.Tx, tag Tag) error {
 	om.mu.Lock()
 	defer om.mu.Unlock()
 
+	ctx := context.Background()
 	hash := *tx.Hash()
 
 	// Check if already exists.
 	if _, exists := om.metadata[hash]; exists {
+		log.DebugS(ctx, "Orphan already exists",
+			"tx_hash", hash,
+			"tag", tag)
 		return fmt.Errorf("%w: %v", ErrOrphanAlreadyExists, hash)
 	}
 
 	// Check size limit.
 	size := tx.MsgTx().SerializeSize()
 	if size > om.config.MaxOrphanSize {
+		log.WarnS(ctx, "Orphan too large", nil,
+			"tx_hash", hash,
+			"size", size,
+			"max_size", om.config.MaxOrphanSize)
 		return fmt.Errorf("%w: %d bytes (max %d)",
 			ErrOrphanTooLarge, size, om.config.MaxOrphanSize)
 	}
 
+	currentCount := len(om.metadata)
 	// Check count limit.
-	if len(om.metadata) >= om.config.MaxOrphans {
+	if currentCount >= om.config.MaxOrphans {
+		log.WarnS(ctx, "Orphan pool limit reached", nil,
+			"tx_hash", hash,
+			"current_count", currentCount,
+			"max_orphans", om.config.MaxOrphans,
+			"tag", tag)
 		return fmt.Errorf("%w: %d", ErrOrphanLimitReached, om.config.MaxOrphans)
 	}
 
+	// Warn when approaching capacity (potential memory DoS).
+	if currentCount > om.config.MaxOrphans*8/10 {
+		log.InfoS(ctx, "Orphan pool nearing capacity",
+			"current_count", currentCount,
+			"max_orphans", om.config.MaxOrphans,
+			"utilization_pct", currentCount*100/om.config.MaxOrphans)
+	}
+
 	// Add to graph. Use a minimal TxDesc since we don't need fee
 	// information for orphans (they're not mined until promoted).
 	desc := &txgraph.TxDesc{
@@ -206,6 +229,13 @@ func (om *OrphanManager) AddOrphan(tx *btcutil.Tx, tag Tag) error {
 	}
 	om.byTag[tag][hash] = struct{}{}
 
+	log.DebugS(ctx, "Orphan added",
+		"tx_hash", hash,
+		"size", size,
+		"tag", tag,
+		"pool_size", len(om.metadata),
+		"max_orphans", om.config.MaxOrphans)
+
 	return nil
 }
 
@@ -222,8 +252,11 @@ func (om *OrphanManager) RemoveOrphan(hash chainhash.Hash, cascade bool) error {
 // removeOrphanUnsafe removes an orphan without locking. Must be called with
 // lock held.
 func (om *OrphanManager) removeOrphanUnsafe(hash chainhash.Hash, cascade bool) error {
+	ctx := context.Background()
 	_, exists := om.metadata[hash]
 	if !exists {
+		log.DebugS(ctx, "Orphan not found for removal",
+			"tx_hash", hash)
 		return fmt.Errorf("%w: %v", ErrOrphanNotFound, hash)
 	}
 
@@ -238,6 +271,12 @@ func (om *OrphanManager) removeOrphanUnsafe(hash chainhash.Hash, cascade bool) e
 		for descHash := range descendants {
 			toRemove = append(toRemove, descHash)
 		}
+
+		if len(descendants) > 0 {
+			log.DebugS(ctx, "Cascading orphan removal",
+				"tx_hash", hash,
+				"descendant_count", len(descendants))
+		}
 	}
 
 	// Remove metadata and tag index entries for all transactions.
@@ -256,6 +295,12 @@ func (om *OrphanManager) removeOrphanUnsafe(hash chainhash.Hash, cascade bool) e
 	}
 
 	// Remove from graph. Use cascade based on caller's preference.
+	log.DebugS(ctx, "Orphan removed",
+		"tx_hash", hash,
+		"cascade", cascade,
+		"removed_count", len(toRemove),
+		"pool_size", len(om.metadata))
+
 	if cascade {
 		return om.graph.RemoveTransaction(hash)
 	}
@@ -270,6 +315,7 @@ func (om *OrphanManager) RemoveOrphansByTag(tag Tag) int {
 	om.mu.Lock()
 	defer om.mu.Unlock()
 
+	ctx := context.Background()
 	tagSet, exists := om.byTag[tag]
 	if !exists {
 		return 0
@@ -281,6 +327,10 @@ func (om *OrphanManager) RemoveOrphansByTag(tag Tag) int {
 		toRemove = append(toRemove, hash)
 	}
 
+	log.DebugS(ctx, "Removing orphans by tag",
+		"tag", tag,
+		"count", len(toRemove))
+
 	// Remove each orphan.
 	removed := 0
 	for _, hash := range toRemove {
@@ -289,6 +339,13 @@ func (om *OrphanManager) RemoveOrphansByTag(tag Tag) int {
 		}
 	}
 
+	if removed > 0 {
+		log.DebugS(ctx, "Orphans removed by tag",
+			"tag", tag,
+			"removed_count", removed,
+			"pool_size", len(om.metadata))
+	}
+
 	return removed
 }
 
@@ -300,6 +357,7 @@ func (om *OrphanManager) ExpireOrphans() int {
 	om.mu.Lock()
 	defer om.mu.Unlock()
 
+	ctx := context.Background()
 	// Only scan if it's time for the next expiration scan.
 	now := time.Now()
 	if now.Before(om.nextExpireScan) {
@@ -309,6 +367,11 @@ func (om *OrphanManager) ExpireOrphans() int {
 	// Update next scan time.
 	om.nextExpireScan = now.Add(om.config.ExpireScanInterval)
 
+	poolSize := len(om.metadata)
+	log.TraceS(ctx, "Scanning for expired orphans",
+		"pool_size", poolSize,
+		"ttl", om.config.OrphanTTL)
+
 	// Find expired orphans.
 	var expired []chainhash.Hash
 	for hash, meta := range om.metadata {
@@ -325,6 +388,13 @@ func (om *OrphanManager) ExpireOrphans() int {
 		}
 	}
 
+	if removed > 0 {
+		log.DebugS(ctx, "Expired orphans removed",
+			"removed_count", removed,
+			"pool_size", len(om.metadata),
+			"ttl", om.config.OrphanTTL)
+	}
+
 	return removed
 }
 
@@ -376,6 +446,12 @@ func (om *OrphanManager) ProcessOrphans(
 	om.mu.Lock()
 	defer om.mu.Unlock()
 
+	ctx := context.Background()
+	parentHash := parentTx.Hash()
+	log.TraceS(ctx, "Processing orphans for parent",
+		"parent_tx", parentHash,
+		"orphan_pool_size", len(om.metadata))
+
 	// Find orphans that spend from this parent's outputs using the spentBy
 	// index. The parent itself is not in the orphan graph (it's in the main
 	// mempool), but orphans that spend its outputs are indexed by outpoint.
@@ -385,7 +461,6 @@ func (om *OrphanManager) ProcessOrphans(
 
 	// Check each output of the parent to see if it's spent by an orphan.
 	// Iterate through actual outputs of the transaction.
-	parentHash := parentTx.Hash()
 	for txOutIdx := range parentTx.MsgTx().TxOut {
 		outpoint := wire.OutPoint{
 			Hash:  *parentHash,
@@ -414,15 +489,25 @@ func (om *OrphanManager) ProcessOrphans(
 			// If promotion fails, skip this orphan and its descendants.
 			// They'll remain in the orphan pool for potential future
 			// promotion or eventual expiration.
+			log.DebugS(ctx, "Orphan promotion failed",
+				"orphan_tx", node.Tx.Hash(),
+				"parent_tx", parentHash,
+				"reason", err.Error())
 			continue
 		}
 
 		// Promotion succeeded! Remove from orphan manager.
 		if err := om.removeOrphanUnsafe(*node.Tx.Hash(), false); err != nil {
 			// Log error but continue processing other orphans.
+			log.WarnS(ctx, "Failed to remove promoted orphan", err,
+				"orphan_tx", node.Tx.Hash())
 			continue
 		}
 
+		log.DebugS(ctx, "Orphan promoted",
+			"orphan_tx", node.Tx.Hash(),
+			"parent_tx", parentHash)
+
 		promoted = append(promoted, node.Tx)
 
 		// Add this orphan's children to the processing queue.
@@ -434,6 +519,13 @@ func (om *OrphanManager) ProcessOrphans(
 		}
 	}
 
+	if len(promoted) > 0 {
+		log.DebugS(ctx, "Orphan processing complete",
+			"parent_tx", parentHash,
+			"promoted_count", len(promoted),
+			"orphan_pool_size", len(om.metadata))
+	}
+
 	return promoted, nil
 }
 

mempool/tx_validator.go

@@ -5,6 +5,7 @@
 package mempool
 
 import (
+	"context"
 	"time"
 
 	"github.com/btcsuite/btcd/blockchain"
@@ -101,13 +102,20 @@ func (v *StandardTxValidator) ValidateScripts(
 	tx *btcutil.Tx,
 	utxoView *blockchain.UtxoViewpoint,
 ) error {
+	ctx := context.Background()
+	log.TraceS(ctx, "Validating transaction scripts",
+		"tx_hash", tx.Hash(),
+		"input_count", len(tx.MsgTx().TxIn))
 
 	// Use blockchain's script validation with standard verification flags.
 	err := blockchain.ValidateTransactionScripts(
 		tx, utxoView, txscript.StandardVerifyFlags, v.cfg.SigCache,
 		v.cfg.HashCache,
 	)
 	if err != nil {
+		log.DebugS(ctx, "Script validation failed",
+			"tx_hash", tx.Hash(),
+			"reason", err.Error())
 		if cerr, ok := err.(blockchain.RuleError); ok {
 			return chainRuleError(cerr)
 		}

mempool/validation_v2.go

@@ -5,6 +5,7 @@
 package mempool
 
 import (
+	"context"
 	"fmt"
 
 	"github.com/btcsuite/btcd/blockchain"
@@ -102,8 +103,10 @@ func (mp *TxMempoolV2) checkMempoolAcceptance(
 
 	// Exit early if this transaction is missing parents (it's an orphan).
 	if len(missingParents) > 0 {
-		log.Debugf("Tx %v is an orphan with missing parents: %v",
-			txHash, missingParents)
+		ctx := context.Background()
+		log.DebugS(ctx, "Transaction has missing parents",
+			"tx_hash", txHash,
+			"missing_count", len(missingParents))
 
 		return &MempoolAcceptResult{
 			MissingParents: missingParents,