go-ethereum icon indicating copy to clipboard operation
go-ethereum copied to clipboard

Fix log indexer noise after debug_setHead operations

Open ForrestKim42 opened this issue 6 months ago • 2 comments

Summary

This PR resolves Issue #31929 by reducing log noise generated by the log indexer after debug_setHead operations.

Problem Description

When debug_setHead is called to rewind the blockchain, blocks are removed from the database. However, the log indexer's ChainView objects may still hold references to these deleted blocks. When extendNonCanonical() attempts to access these missing headers, it results in:

  1. Repeated ERROR logs: Header not found number=X hash=0x...
  2. Log noise that can mask other important errors
  3. User confusion about whether this indicates a real problem

Root Cause Analysis

The issue occurs because:

  • debug_setHead removes blocks from the blockchain database
  • Log indexer's ChainView may still reference deleted block hashes
  • extendNonCanonical() in core/filtermaps/chain_view.go tries to fetch these missing headers
  • The existing return false logic properly handles the error, but logs at ERROR level

Solution

This is a logging improvement only - no functional logic changes:

Changes Made

  1. Log level: Changed from ERROR to DEBUG
  2. Log message: Enhanced with descriptive context about chain view extension
  3. Comments: Added explanation for when this situation occurs
  4. Behavior: Maintains existing error handling (return false was already present)

Code Changes

// Before
log.Error("Header not found", "number", number, "hash", hash)
return false

// After  
// Header not found - this can happen after debug_setHead operations
// where blocks have been deleted. Return false to indicate the chain view
// is no longer valid rather than logging repeated errors.
log.Debug("Header not found during chain view extension", "number", number, "hash", hash)
return false

Testing

Automated Tests

  • ✅ All existing filtermaps tests pass: go test ./core/filtermaps -v
  • ✅ No regressions in related functionality

Manual Verification

  1. Before fix: Started geth in dev mode, generated blocks, called debug_setHead(3)5 repeated ERROR logs
  2. After fix: Same scenario → 4 DEBUG logs, no ERROR noise

Test Environment

# Setup test environment
rm -rf ./dev-test-data
./build/bin/geth --dev --datadir ./dev-test-data --http --http.api debug,eth,net,web3 --verbosity 4

# Generate test blocks and trigger issue
curl -X POST -H "Content-Type: application/json" --data '{"jsonrpc":"2.0","method":"debug_setHead","params":["0x3"],"id":1}' http://localhost:8545

Related Issues

  • Fixes #31929

Additional Context

This issue was reported as spurious error messages appearing after debug_setHead operations. The investigation revealed that while the error handling was functionally correct, the ERROR log level was inappropriate for this expected scenario in development/debugging workflows.

The fix maintains full compatibility while significantly improving the debugging experience for developers using debug_setHead.

ForrestKim42 avatar May 29 '25 18:05 ForrestKim42

Sorry. i was misunderstand the problem

ForrestKim42 avatar May 29 '25 18:05 ForrestKim42

OH. I did understand well

ForrestKim42 avatar May 29 '25 18:05 ForrestKim42