Skip to content

Add cross-client execution metrics and slow block logging#9834

Draft
macfarla wants to merge 67 commits into
besu-eth:mainfrom
macfarla:feature/execution-metrics-standardization-rebased
Draft

Add cross-client execution metrics and slow block logging#9834
macfarla wants to merge 67 commits into
besu-eth:mainfrom
macfarla:feature/execution-metrics-standardization-rebased

Conversation

@macfarla
Copy link
Copy Markdown
Contributor

PR description

Builds on #9660 from @CPerezz

Summary

Implement standardized JSON format for slow block logging to enable cross-client performance analysis and protocol research.

This change is part of the Cross-Client Execution Metrics initiative proposed by Gary Rong and CPerezz.

Motivation

Standardized execution metrics are critical for:

  • Cross-client performance comparison
  • Network health monitoring
  • Data-driven protocol research

Real-world example: The EIP-7907 analysis used execution metrics to measure code read latency, per-call overhead scaling, and block execution breakdown. Without standardized metrics across clients, such analysis cannot be validated cross-client.

References

JSON Format

{
  "level": "warn",
  "msg": "Slow block",
  "block": { "number": ..., "hash": ..., "gas_used": ..., "tx_count": ... },
  "timing": { "execution_ms": ..., "total_ms": ... },
  "throughput": { "mgas_per_sec": ... },
  "state_reads": { "accounts": ..., "storage_slots": ..., "code": ..., "code_bytes": ... },
  "state_writes": { "accounts": ..., "storage_slots": ... },
  "cache": {
    "account": { "hits": ..., "misses": ..., "hit_rate": ... },
    "storage": { ... },
    "code": { ... }
  },
  "evm": { "sload": ..., "sstore": ..., "calls": ..., "creates": ... }
}

Thanks for sending a pull request! Have you done the following?

  • Checked out our contribution guidelines?
  • Considered documentation and added the doc-change-required label to this PR if updates are required.
  • Considered the changelog and included an update if required.
  • For database changes (e.g. KeyValueSegmentIdentifier) considered compatibility and performed forwards and backwards compatibility tests

Locally, you can run these tests to catch failures early:

  • spotless: ./gradlew spotlessApply
  • unit tests: ./gradlew build
  • acceptance tests: ./gradlew acceptanceTest
  • integration tests: ./gradlew integrationTest
  • reference tests: ./gradlew ethereum:referenceTests:referenceTests
  • hive tests: Engine or other RPCs modified?

macfarla and others added 14 commits February 17, 2026 10:28
Implements standardized execution metrics collection for block processing
performance monitoring, following the cross-client execution metrics specification.

Key features:
- SlowBlockTracer: logs detailed JSON metrics for blocks exceeding a configurable
  threshold (--slow-block-threshold CLI flag or -Dbesu.execution.slowBlockThresholdMs)
- StateMetricsCollector: instance-based metrics collection threaded through the
  world state object graph, replacing ThreadLocal-based approaches
- ExecutionStats: tracks timing breakdowns, state access counts, cache performance,
  and EVM operation counts (SLOAD, SSTORE, CALL, CREATE)
- BlockAwareTracerAggregator: composable tracer pattern for combining multiple
  block-aware operation tracers
- ExecutionMetricsTracer: EVM-level tracer for opcode counting
- Parallel execution support with metrics aggregation across background threads

Co-authored-by: CPerezz <c@cperezz.dev>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
@macfarla macfarla marked this pull request as ready for review February 18, 2026 05:46
Copilot AI review requested due to automatic review settings February 18, 2026 05:46
Copy link
Copy Markdown
Contributor

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR implements standardized JSON-format slow block logging to enable cross-client performance analysis and protocol research. It introduces a comprehensive execution metrics system that collects detailed statistics about block execution including timing, state access patterns, cache performance, and EVM operation counts following the cross-client execution metrics specification.

Changes:

  • Added ExecutionStats/ExecutionStatsTracer classes to collect block execution metrics across the EVM and state layers
  • Introduced SlowBlockTracer for logging slow blocks in standardized JSON format with 38 metric fields
  • Extended MetricsConfiguration with executionMetricsEnabled flag and slow block threshold configuration

Reviewed changes

Copilot reviewed 43 out of 43 changed files in this pull request and generated 3 comments.

Show a summary per file
File Description
metrics/core/src/main/java/org/hyperledger/besu/metrics/prometheus/MetricsConfiguration.java Added executionMetricsEnabled field to metrics configuration
evm/src/main/java/org/hyperledger/besu/evm/tracing/ExecutionMetricsTracer.java New EVM-level tracer for collecting operation counts (SLOAD/SSTORE/CALL/CREATE)
ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/ExecutionStats.java Core metrics collection class implementing StateMetricsCollector interface
ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/SlowBlockTracer.java Block-aware tracer that logs slow blocks in standardized JSON format
ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelizedConcurrentTransactionProcessor.java Extended to support metrics collection during parallel transaction execution
ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/AbstractBlockProcessor.java Integrated SlowBlockTracer into block processing pipeline
ethereum/core/src/main/java/org/hyperledger/besu/ethereum/ProtocolContext.java Added slowBlockThresholdMs configuration
app/src/main/java/org/hyperledger/besu/cli/options/MetricsOptions.java Added CLI options for execution metrics and slow block threshold
acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/SlowBlockMetricsValidationTest.java Comprehensive acceptance test validating all 38 JSON metric fields
Comments suppressed due to low confidence (2)

ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/accumulator/PathBasedWorldStateUpdateAccumulator.java:1

  • The change from parallelStream() to stream() removes parallelism from account updates. This could impact performance for blocks with many account modifications. Consider documenting why this change was necessary (likely for metrics collection ordering) or re-evaluate if sequential processing is required here.
    ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/ExecutionStatsIntegrationTest.java:1
  • This TODO indicates incomplete implementation of code write metrics. Consider creating a tracking issue for this follow-up work and referencing it in the comment for better traceability.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment on lines +528 to +529
// Persist before traceEndBlock so that state root calculation (trie cache lookups,
// state_hash_ms timing) occurs while ExecutionStatsHolder is still set on this thread.
Copy link

Copilot AI Feb 18, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The reordering of worldState.persist() before blockTracer.traceEndBlock() changes the execution flow significantly. While the comment explains the reasoning for metrics timing, this could have subtle effects on tracer behavior. Ensure all block tracers are compatible with receiving traceEndBlock after state persistence completes.

Copilot uses AI. Check for mistakes.
Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Since SlowBlockTracer is now standalone and only reads from ExecutionStatsHolder at traceEndBlock, this ordering is actually correct — it needs persist to have run so
state_hash_ms timing is captured.

@macfarla
Copy link
Copy Markdown
Contributor Author

example output for hoodi block https://hoodi.etherscan.io/block/2259313

{"@timestamp":"2026-02-18T10:34:15,936","level":"WARN","thread":"vert.x-worker-thread-0","class":"SlowBlock","message":"{"level":"warn","msg":"Slow block","block":{"number":2259313,"hash":"0x96629cd754416caa4a4976f9d5b740929a005d7b294940a935a2f748d924277e","gas_used":59712075,"tx_count":55},"timing":{"execution_ms":543.260524,"state_read_ms":5.470963,"state_hash_ms":2.01084,"commit_ms":1.238452,"total_ms":546.509816},"throughput":{"mgas_per_sec":109.91},"state_reads":{"accounts":141,"storage_slots":214,"code":68,"code_bytes":456956},"state_writes":{"accounts":208,"storage_slots":83,"code":0,"code_bytes":0,"eip7702_delegations_set":0,"eip7702_delegations_cleared":0},"cache":{"account":{"hits":1,"misses":0,"hit_rate":100.0},"storage":{"hits":1,"misses":0,"hit_rate":100.0},"code":{"hits":68,"misses":0,"hit_rate":100.0}},"unique":{"accounts":0,"storage_slots":0,"contracts":0},"evm":{"sload":298,"sstore":70,"calls":131,"creates":1}}","throwable":""}

compared with debug_traceBockByNumber

dev-elc-bu-nb-hoodi-sally-9660-tracing-5-rebased-snap:~$ python3 ~/compare-opcodes.py --rpc http://127.0.0.1:8545 --block 2259313
Tracing block 2259313 via http://127.0.0.1:8545 ...
  Block exists: 55 transactions, gas used: 59,712,075
  RPC: debug_traceBlockByNumber ["0x227971", {}]
  55 transactions traced

=== All opcodes (descending) ===
  PUSH1                 3,876,716
  PUSH2                 2,585,111
  JUMPDEST              1,293,189
  JUMPI                 1,292,877
  POP                   1,292,204
  JUMP                  1,292,141
  ADD                   1,292,006
  LT                    1,291,003
  GAS                   1,290,758
  DUP1                      1,907
  SWAP1                     1,796
  DUP2                      1,723
  MSTORE                    1,215
  PUSH4                     1,013
  DUP3                        967
  SWAP2                       943
  EQ                          861
  MLOAD                       798
  SUB                         795
  ISZERO                      755
  AND                         735
  PUSH0                       672
  DUP4                        629
  SHL                         526
  GT                          434
  SWAP3                       427
  DUP5                        318
  CALLDATASIZE                316
  SLOAD                       298
  PUSH32                      291
  CALLDATALOAD                240
  SWAP4                       226
  DUP6                        178
  RETURNDATASIZE              170
  SHR                         146
  OR                          143
  DUP7                        142
  NOT                         136
  KECCAK256                   135
  SLT                         132
  RETURN                      124
  SWAP5                       110
  MUL                         109
  CALLVALUE                   103
  PUSH8                        85
  PUSH20                       80
  DUP8                         78
  PUSH3                        76
  SWAP6                        70
  SSTORE                       70
  CALLER                       66
  STATICCALL                   65
  STOP                         63
  CALLDATACOPY                 59
  DIV                          57
  RETURNDATACOPY               48
  DELEGATECALL                 45
  DUP9                         37
  PUSH6                        31
  LOG1                         28
  DUP11                        27
  DUP10                        25
  EXP                          25
  SWAP7                        24
  CODESIZE                     24
  EXTCODESIZE                  23
  TIMESTAMP                    21
  CALL                         21
  CODECOPY                     18
  SWAP8                        12
  DUP12                         9
  DUP14                         9
  SWAP10                        8
  PUSH21                        8
  PUSH16                        8
  DUP13                         7
  ADDRESS                       7
  NUMBER                        6
  LOG3                          6
  SWAP9                         5
  MULMOD                        5
  SGT                           4
  PUSH5                         4
  MOD                           4
  LOG4                          4
  PUSH10                        4
  SWAP12                        4
  LOG2                          3
  SWAP11                        3
  TSTORE                        2
  CHAINID                       2
  PUSH19                        2
  BLOCKHASH                     2
  SWAP15                        2
  PUSH9                         2
  BALANCE                       2
  TLOAD                         1
  BLOBHASH                      1
  MCOPY                         1
  PUSH12                        1
  PUSH13                        1
  PUSH25                        1
  CREATE                        1
  ORIGIN                        1
  DUP15                         1
  SWAP14                        1
  SWAP16                        1
  DUP16                         1
  SWAP13                        1
  PUSH17                        1
  PUSH14                        1
  SELFBALANCE                   1

=== Mapped to SlowBlockTracer categories ===
  metric        debug_trace
  ------------ ------------
  sload                 298
  sstore                 70
  calls                 131
  creates                 1

macfarla and others added 3 commits February 20, 2026 16:13
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
…sage

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
@ahamlat
Copy link
Copy Markdown
Contributor

ahamlat commented Mar 17, 2026

+1 on OperationTracer[], Collections.unmodifiableList introduces another overhead on top of existing ones for ArrayList :

  • ArrayList vs raw array already has overhead: iterator allocation on every for-each loop, rangeCheck / bounds checks on get(index), object indirection through elementData[], etc.
  • Collections.unmodifiableList then adds yet another layer on top of that: the delegating wrapper iterator with its extra virtual calls on every hasNext()/next().

Maybe have a fast path execution with 1 and 2 tracers to avoid megamorphic calls, so have only monomorphic or bimorphic calls.
For the first path, instead of using OperationTracer[], we can imagine something like

private final OperationTracer first;
private final OperationTracer second;
public void tracePreExecution(final MessageFrame frame) {
    first.tracePreExecution(frame);
    second.tracePreExecution(frame);
}

@siladu
Copy link
Copy Markdown
Contributor

siladu commented Mar 17, 2026

Maybe have a fast path execution with 1 and 2 tracers to avoid megamorphic calls, so have only monomorphic or bimorphic calls.

I have a slight preference for delegation pattern since we already use that elsewhere in the codebase and easy to mix and match with other Tracers.
Though SlowBlockTracer + EvmExecutionMetricsTracer are quite coupled already so a maybe it's fine to compose them more directly like you say.
Need to account for any plugin tracers that might be present too.

@siladu
Copy link
Copy Markdown
Contributor

siladu commented Mar 17, 2026

Still reviewing, but couple of comments before I forget:

  • Need to update default to disabled
  • Think we should add a line to BesuConfigOverview when it's enabled

Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
@macfarla macfarla self-assigned this Apr 23, 2026
macfarla and others added 5 commits April 23, 2026 17:13
Resolved conflicts between the execution metrics / slow block tracing
feature (PR besu-eth#9834) and the following upstream changes:

- BesuPluginServiceRegistrar extracted from BesuCommand (service
  registration now centralised); registerRuntimeServices() extended
  with slowBlockThresholdMs so BlockSimulatorServiceImpl receives it.
- TracerAggregator removed from evm module; replaced with a new
  CompositeOperationTracer in ethereum/core that delegates every
  OperationTracer method to a fixed list of child tracers and adds a
  hasTracer() utility used by the parallel-tracer tests.
- PreprocessingFunction.run() extended with both BlockProcessingContext
  (our addition) and Optional<BlockHeader> maybeParentHeader (upstream
  addition); all implementations and call sites updated.
- PathBasedWorldState.persist() API changed to use computeRoot() with a
  state-root supplier; our timing-metrics hooks retained.
- BlockSimulator gas-limit check added alongside our EVMExecutionMetrics
  tracer composition (using CompositeOperationTracer.of).
- parallelStream() → stream() in PathBasedWorldStateUpdateAccumulator to
  eliminate a data race on the accountWrites/storageWrites int fields.
- BalConcurrentTransactionProcessor wired with the same workerStats
  ExecutionStats pattern as ParallelizedConcurrentTransactionProcessor.
- Test suites updated: maybeParentHeader propagated to all runAsyncBlock
  call sites; blockHeader mocks extended with getStateRoot()/getBlockHash()
  stubs required after the getWorldState() API change; testApplyResult…
  test fixed to simulate traceBeforeRewardTransaction so that the
  miningBeneficiaryReward is non-zero and setPostBalance is exercised.

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
…teCallSimulationResult

Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
@macfarla
Copy link
Copy Markdown
Contributor Author

verified mainnet output matches eg for block https://etherscan.io/block/24975451

{"@timestamp":"2026-04-28T02:04:49,466","level":"WARN","thread":"vert.x-worker-thread-0","class":"SlowBlock","message":"{"level":"warn","msg":"Slow block","block":{"number":24975451,"hash":"0xb43f7f12c475f97fb606cbc104cfa1901c306571cb78fa1bbff2b7d8224a7221","gas_used":49514450,"tx_count":1025},"timing":{"execution_ms":706.055852,"state_read_ms":485.346352,"state_hash_ms":31.156424,"commit_ms":3.128383,"total_ms":740.340659},"throughput":{"mgas_per_sec":70.13},"state_reads":{"accounts":890,"storage_slots":1317,"code":504,"code_bytes":3958838},"state_writes":{"accounts":3076,"storage_slots":1730,"code":0,"code_bytes":0,"eip7702_delegations_set":0,"eip7702_delegations_cleared":0},"cache":{"account":{"hits":3991,"misses":890,"hit_rate":81.77},"storage":{"hits":5475,"misses":1317,"hit_rate":80.61},"code":{"hits":504,"misses":0,"hit_rate":100.0}},"unique":{"accounts":802,"storage_slots":2273,"contracts":591},"evm":{"sload":6970,"sstore":3258,"calls":2609,"creates":2}}","throwable":""}

@macfarla
Copy link
Copy Markdown
Contributor Author

execution engine times with feature enabled/disabled vs control 26.4.0 - enabled is slightly higher,
Screenshot 2026-04-28 at 1 01 19 pm
Screenshot 2026-04-28 at 1 01 29 pm

slightly clearer picture with 1 of each
Screenshot 2026-04-28 at 1 03 26 pm

Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
@macfarla macfarla marked this pull request as ready for review April 28, 2026 03:51
@macfarla macfarla removed their assignment Apr 28, 2026
macfarla added 4 commits May 1, 2026 12:12
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
Signed-off-by: Sally MacFarlane <macfarla.github@gmail.com>
@macfarla macfarla marked this pull request as draft May 7, 2026 03:26
@siladu siladu self-assigned this May 25, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

6 participants