diff --git a/CHANGELOG.md b/CHANGELOG.md index e3b62d9d2f7..2b50bae8d4a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -43,6 +43,7 @@ - Restrict no-reorg behavior to the prefix of the known finalized chain (per execution-apis #786) [#10335](https://github.com/besu-eth/besu/pull/10335) ### Additions and Improvements +- Add slow block execution metrics logging (`--slow-block-threshold`). When enabled, blocks whose execution time exceeds the threshold are logged in a structured JSON format covering timing breakdowns, state reads/writes, cache hit rates, and EVM opcode counts, following the cross-client execution metrics specification. Disabled by default; set `--slow-block-threshold=` to enable (0 logs all blocks). [#9834](https://github.com/hyperledger/besu/pull/9834) - The option to set a different block period for empty BFT blocks (`emptyblockperiodseconds`) is no longer experimental. The experimental flag `xemptyblockperiodseconds` will be removed in a future release. [#10264](https://github.com/besu-eth/besu/pull/10264) - Release worker threads after engine API timeout to avoid blocking subsequent requests [#10311](https://github.com/besu-eth/besu/pull/10311) - `evmtool blocktest --verbose` flag, default off, removes noise from output [#10348](https://github.com/besu-eth/besu/pull/10348) diff --git a/acceptance-tests/dsl/src/main/java/org/hyperledger/besu/tests/acceptance/dsl/node/ThreadBesuNodeRunner.java b/acceptance-tests/dsl/src/main/java/org/hyperledger/besu/tests/acceptance/dsl/node/ThreadBesuNodeRunner.java index 5cdd02a8084..b6c79345c63 100644 --- a/acceptance-tests/dsl/src/main/java/org/hyperledger/besu/tests/acceptance/dsl/node/ThreadBesuNodeRunner.java +++ b/acceptance-tests/dsl/src/main/java/org/hyperledger/besu/tests/acceptance/dsl/node/ThreadBesuNodeRunner.java @@ -251,7 +251,8 @@ private void loadAdditionalServices( besuController, runner, metricsSystem, - besuController.getMiningParameters()); + besuController.getMiningParameters(), + -1L); } private void killRunner(final String name) { diff --git a/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/SlowBlockMetricsValidationTest.java b/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/SlowBlockMetricsValidationTest.java new file mode 100644 index 00000000000..70bbbad1094 --- /dev/null +++ b/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/SlowBlockMetricsValidationTest.java @@ -0,0 +1,312 @@ +/* + * Copyright contributors to Hyperledger Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.tests.acceptance; + +import static org.assertj.core.api.Assertions.assertThat; + +import org.hyperledger.besu.tests.acceptance.dsl.AcceptanceTestBase; +import org.hyperledger.besu.tests.acceptance.dsl.account.Account; +import org.hyperledger.besu.tests.acceptance.dsl.node.BesuNode; +import org.hyperledger.besu.tests.acceptance.dsl.node.configuration.BesuNodeConfigurationBuilder; +import org.hyperledger.besu.tests.acceptance.slowblock.model.ExpectedMetrics; +import org.hyperledger.besu.tests.acceptance.slowblock.model.MetricsTestScenario; +import org.hyperledger.besu.tests.acceptance.slowblock.model.TaggedBlock; +import org.hyperledger.besu.tests.acceptance.slowblock.report.SlowBlockMetricsReportGenerator; +import org.hyperledger.besu.tests.web3j.generated.SimpleStorage; + +import java.io.IOException; +import java.math.BigInteger; +import java.nio.file.Path; +import java.nio.file.Paths; +import java.util.ArrayList; +import java.util.LinkedHashSet; +import java.util.List; +import java.util.Set; +import java.util.function.UnaryOperator; +import java.util.regex.Matcher; +import java.util.regex.Pattern; +import java.util.stream.Collectors; + +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +/** + * End-to-end acceptance test for validating slow block metrics. This test sends various transaction + * types to a local Besu node, captures slow block logs, and validates that all JSON fields are + * correctly populated. + * + *

The test uses a QBFT node (BFT consensus) with a threshold of 0ms to ensure ALL blocks are + * logged as slow blocks. QBFT is used instead of dev mode because it automatically produces blocks, + * which is required for contract deployment and transaction execution. + * + *

Note on EIP-7702: Testing EIP-7702 delegation metrics requires a Prague-enabled genesis + * and the Engine API for block production. See {@code CodeDelegationTransactionAcceptanceTest} for + * comprehensive EIP-7702 testing. The EIP-7702 metrics (eip7702_delegations_set/cleared) are + * validated to be present in the JSON structure but may be 0 in this test as the genesis doesn't + * enable EIP-7702. + */ +public class SlowBlockMetricsValidationTest extends AcceptanceTestBase { + + private static final ObjectMapper OBJECT_MAPPER = new ObjectMapper(); + + // Pattern to match slow block JSON in console output + // Matches from the start marker to the final closing braces on the same line, + // without depending on any specific field order. + private static final Pattern SLOW_BLOCK_PATTERN = + Pattern.compile("(\\{\"level\":\"warn\",\"msg\":\"Slow block\"[^\\n]*\\}\\})"); + + // All expected JSON field paths (38 fields - matching geth + Besu extras) + // Now sourced from ExpectedMetrics for consistency + private static final List REQUIRED_FIELDS = ExpectedMetrics.ALL_METRIC_PATHS; + + // Report output path + private static final Path REPORT_OUTPUT_PATH = + Paths.get("build/reports/slow-block-metrics-analysis.md"); + + private BesuNode devNode; + + @BeforeEach + public void setUp() throws Exception { + // Create a QBFT node with: + // - BFT consensus that automatically produces blocks + // - 0ms slow block threshold (log ALL blocks as slow) + // We use a config modifier to add the environment variable for slow block threshold + final UnaryOperator configModifier = + builder -> builder.extraCLIOptions(List.of("--slow-block-threshold=0")); + + devNode = besu.createQbftNode("qbft-metrics-node", configModifier); + + // Start console capture BEFORE starting the node + cluster.startConsoleCapture(); + cluster.start(devNode); + + // Wait for blockchain to progress (QBFT produces blocks automatically) + cluster.verify(blockchain.reachesHeight(devNode, 1, 30)); + } + + @Test + public void shouldCaptureSlowBlockMetricsForVariousTransactions() throws Exception { + // 1. Send ETH transfer + final Account sender = accounts.getPrimaryBenefactor(); + final Account recipient = accounts.createAccount("recipient"); + devNode.execute(accountTransactions.createTransfer(sender, recipient, 1)); + + // 2. Deploy contract + final SimpleStorage contract = + devNode.execute(contractTransactions.createSmartContract(SimpleStorage.class)); + + // 3. Call contract to write storage (SSTORE) + contract.set(BigInteger.valueOf(42)).send(); + + // 4. Call contract again to read/write (SLOAD + SSTORE) + contract.set(BigInteger.valueOf(100)).send(); + + // 5. Read contract storage (triggers SLOAD without SSTORE) + contract.get().send(); + + // Wait a moment for blocks to be processed + Thread.sleep(2000); + + // Get console output and parse slow block logs + String consoleOutput = cluster.getConsoleContents(); + List slowBlocks = parseSlowBlockLogs(consoleOutput); + + // Assertions + assertThat(slowBlocks).as("Should capture at least one slow block log").isNotEmpty(); + + // Validate fields in the last slow block + JsonNode lastBlock = slowBlocks.get(slowBlocks.size() - 1); + + // Check all required fields are present + List missingFields = new ArrayList<>(); + for (String fieldPath : REQUIRED_FIELDS) { + String jsonPointerPath = "/" + fieldPath.replace("/", "/"); + JsonNode fieldNode = lastBlock.at(jsonPointerPath); + if (fieldNode.isMissingNode()) { + missingFields.add(fieldPath); + } + } + + assertThat(missingFields) + .as("All required fields should be present in slow block JSON. Missing: " + missingFields) + .isEmpty(); + + // Tag blocks with their transaction types and generate comprehensive report + List taggedBlocks = tagBlocksWithMetricsTestScenarios(slowBlocks); + generateComprehensiveReport(taggedBlocks); + + // Also print legacy console report for quick verification + printReport(slowBlocks, lastBlock, missingFields); + } + + /** + * Tag each captured slow block with its transaction type based on block metrics. Uses heuristics + * based on EVM opcode counts, state read/write patterns, and transaction count to classify each + * block. + * + *

Classification priority (first match wins): + * + *

    + *
  1. Genesis block (block number 0) + *
  2. Empty block (no transactions) + *
  3. Contract deployment (CREATE opcode or code writes) + *
  4. Storage write with read (SLOAD + SSTORE with code interaction) + *
  5. Storage write only (SSTORE with code interaction) + *
  6. Storage read only (SLOAD without SSTORE) + *
  7. ETH transfer (transactions without contract code interaction) + *
+ */ + private List tagBlocksWithMetricsTestScenarios(final List slowBlocks) { + List taggedBlocks = new ArrayList<>(); + + for (int i = 0; i < slowBlocks.size(); i++) { + JsonNode block = slowBlocks.get(i); + long blockNumber = block.at("/block/number").asLong(); + int txCount = block.at("/block/tx_count").asInt(); + long codeWrites = block.at("/state_writes/code").asLong(); + long codeReads = block.at("/state_reads/code").asLong(); + long creates = block.at("/evm/creates").asLong(); + long sstore = block.at("/evm/sstore").asLong(); + long sload = block.at("/evm/sload").asLong(); + long calls = block.at("/evm/calls").asLong(); + + // Determine transaction type based on block metrics + MetricsTestScenario txType; + if (blockNumber == 0) { + // Genesis block + txType = MetricsTestScenario.GENESIS; + } else if (txCount == 0) { + // Empty consensus block (no user transactions) + txType = MetricsTestScenario.EMPTY_BLOCK; + } else if (creates > 0 || codeWrites > 0) { + // Contract deployment: CREATE/CREATE2 opcode executed or code written to state + txType = MetricsTestScenario.CONTRACT_DEPLOY; + } else if (sload > 0 && sstore > 0 && codeReads > 0) { + // Storage read-modify-write: contract reads then writes storage + txType = MetricsTestScenario.STORAGE_WRITE; + } else if (sstore > 0 && codeReads > 0) { + // Storage write only: contract writes to storage slot + txType = MetricsTestScenario.STORAGE_WRITE; + } else if (sload > 0 && sstore == 0 && codeReads > 0) { + // Storage read only: contract reads storage without writing + txType = MetricsTestScenario.STORAGE_READ; + } else if (calls > 0 && codeReads > 0) { + // Contract call without storage access + txType = MetricsTestScenario.CONTRACT_CALL; + } else if (txCount > 0) { + // Simple ETH transfer: has transactions but no contract code interaction + txType = MetricsTestScenario.ETH_TRANSFER; + } else { + // Fallback for unidentified patterns + txType = MetricsTestScenario.EMPTY_BLOCK; + } + + taggedBlocks.add(new TaggedBlock(block, txType)); + } + + return taggedBlocks; + } + + /** Generate a comprehensive markdown report with expected vs actual analysis for all metrics. */ + private void generateComprehensiveReport(final List taggedBlocks) + throws IOException { + SlowBlockMetricsReportGenerator generator = + new SlowBlockMetricsReportGenerator(taggedBlocks, "QBFT (BFT Consensus)"); + + // Generate and write the report + generator.generateReport(REPORT_OUTPUT_PATH); + + // Also print to console for immediate visibility in test output + System.out.println("\n" + generator.generateReportString()); + } + + private List parseSlowBlockLogs(final String consoleOutput) { + List allBlocks = new ArrayList<>(); + Matcher matcher = SLOW_BLOCK_PATTERN.matcher(consoleOutput); + + while (matcher.find()) { + try { + String json = matcher.group(); + JsonNode node = OBJECT_MAPPER.readTree(json); + allBlocks.add(node); + } catch (Exception e) { + // Skip malformed JSON + } + } + + // Deduplicate by block hash to avoid duplicate entries + // (blocks may be logged multiple times during validation/import) + Set seenHashes = new LinkedHashSet<>(); + return allBlocks.stream() + .filter(block -> seenHashes.add(block.at("/block/hash").asText())) + .collect(Collectors.toList()); + } + + private void printReport( + final List slowBlocks, final JsonNode lastBlock, final List missingFields) { + StringBuilder report = new StringBuilder(); + + report.append("\n"); + report.append("═══════════════════════════════════════════════════════════════\n"); + report.append(" SLOW BLOCK METRICS VALIDATION REPORT\n"); + report.append("═══════════════════════════════════════════════════════════════\n"); + report.append("\n"); + + // Summary + report.append("SUMMARY\n"); + report.append("-------\n"); + report.append(String.format("Blocks Processed: %d%n", slowBlocks.size())); + report.append(String.format("Missing Fields: %d%n", missingFields.size())); + if (!missingFields.isEmpty()) { + report.append(String.format(" -> %s%n", missingFields)); + } + report.append("\n"); + + // Sample metrics from last block + if (lastBlock != null) { + report.append("SAMPLE METRICS (last block)\n"); + report.append("---------------------------\n"); + report.append(String.format("Block number: %s%n", lastBlock.at("/block/number").asText())); + report.append(String.format("Gas used: %s%n", lastBlock.at("/block/gas_used").asText())); + report.append(String.format("Tx count: %s%n", lastBlock.at("/block/tx_count").asText())); + report.append( + String.format("Execution time: %s ms%n", lastBlock.at("/timing/execution_ms").asText())); + report.append( + String.format("Account reads: %s%n", lastBlock.at("/state_reads/accounts").asText())); + report.append( + String.format("Account writes: %s%n", lastBlock.at("/state_writes/accounts").asText())); + report.append( + String.format( + "Storage reads: %s%n", lastBlock.at("/state_reads/storage_slots").asText())); + report.append( + String.format( + "Storage writes: %s%n", lastBlock.at("/state_writes/storage_slots").asText())); + report.append(String.format("Code reads: %s%n", lastBlock.at("/state_reads/code").asText())); + report.append( + String.format("Code writes: %s%n", lastBlock.at("/state_writes/code").asText())); + report.append(String.format("SLOAD: %s%n", lastBlock.at("/evm/sload").asText())); + report.append(String.format("SSTORE: %s%n", lastBlock.at("/evm/sstore").asText())); + report.append(String.format("CALLS: %s%n", lastBlock.at("/evm/calls").asText())); + report.append(String.format("CREATES: %s%n", lastBlock.at("/evm/creates").asText())); + } + + report.append("\n"); + report.append("═══════════════════════════════════════════════════════════════\n"); + + System.out.println(report); + } +} diff --git a/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/slowblock/model/ExpectedMetrics.java b/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/slowblock/model/ExpectedMetrics.java new file mode 100644 index 00000000000..3361e491d95 --- /dev/null +++ b/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/slowblock/model/ExpectedMetrics.java @@ -0,0 +1,327 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.tests.acceptance.slowblock.model; + +import java.util.EnumMap; +import java.util.HashMap; +import java.util.List; +import java.util.Map; + +import com.google.common.collect.ImmutableList; + +/** + * Defines expected metric values for each test scenario. Used to validate that slow block metrics + * are correctly populated for different operation types. + * + *

Each expectation can be: + * + *

    + *
  • "*" - any value is acceptable (field just needs to exist) + *
  • ">= N" - value should be greater than or equal to N + *
  • "= N" - value should equal N exactly + *
  • "0-100" - value should be in range (for percentages) + *
+ */ +public class ExpectedMetrics { + + // All 38 metric field paths + public static final List ALL_METRIC_PATHS = + ImmutableList.of( + // Top level + "level", + "msg", + // Block + "block/number", + "block/hash", + "block/gas_used", + "block/tx_count", + // Timing + "timing/execution_ms", + "timing/state_read_ms", + "timing/state_hash_ms", + "timing/commit_ms", + "timing/total_ms", + // Throughput + "throughput/mgas_per_sec", + // State reads + "state_reads/accounts", + "state_reads/storage_slots", + "state_reads/code", + "state_reads/code_bytes", + // State writes + "state_writes/accounts", + "state_writes/storage_slots", + "state_writes/code", + "state_writes/code_bytes", + "state_writes/eip7702_delegations_set", + "state_writes/eip7702_delegations_cleared", + // Cache + "cache/account/hits", + "cache/account/misses", + "cache/account/hit_rate", + "cache/storage/hits", + "cache/storage/misses", + "cache/storage/hit_rate", + "cache/code/hits", + "cache/code/misses", + "cache/code/hit_rate", + // Unique (Besu extra) + "unique/accounts", + "unique/storage_slots", + "unique/contracts", + // EVM (Besu extra) + "evm/sload", + "evm/sstore", + "evm/calls", + "evm/creates"); + + // Category labels for report display + public static final Map METRIC_CATEGORIES = new HashMap<>(); + + static { + METRIC_CATEGORIES.put("level", "Top Level"); + METRIC_CATEGORIES.put("msg", "Top Level"); + METRIC_CATEGORIES.put("block/number", "Block"); + METRIC_CATEGORIES.put("block/hash", "Block"); + METRIC_CATEGORIES.put("block/gas_used", "Block"); + METRIC_CATEGORIES.put("block/tx_count", "Block"); + METRIC_CATEGORIES.put("timing/execution_ms", "Timing"); + METRIC_CATEGORIES.put("timing/state_read_ms", "Timing"); + METRIC_CATEGORIES.put("timing/state_hash_ms", "Timing"); + METRIC_CATEGORIES.put("timing/commit_ms", "Timing"); + METRIC_CATEGORIES.put("timing/total_ms", "Timing"); + METRIC_CATEGORIES.put("throughput/mgas_per_sec", "Throughput"); + METRIC_CATEGORIES.put("state_reads/accounts", "State Reads"); + METRIC_CATEGORIES.put("state_reads/storage_slots", "State Reads"); + METRIC_CATEGORIES.put("state_reads/code", "State Reads"); + METRIC_CATEGORIES.put("state_reads/code_bytes", "State Reads"); + METRIC_CATEGORIES.put("state_writes/accounts", "State Writes"); + METRIC_CATEGORIES.put("state_writes/storage_slots", "State Writes"); + METRIC_CATEGORIES.put("state_writes/code", "State Writes"); + METRIC_CATEGORIES.put("state_writes/code_bytes", "State Writes"); + METRIC_CATEGORIES.put("state_writes/eip7702_delegations_set", "State Writes"); + METRIC_CATEGORIES.put("state_writes/eip7702_delegations_cleared", "State Writes"); + METRIC_CATEGORIES.put("cache/account/hits", "Cache"); + METRIC_CATEGORIES.put("cache/account/misses", "Cache"); + METRIC_CATEGORIES.put("cache/account/hit_rate", "Cache"); + METRIC_CATEGORIES.put("cache/storage/hits", "Cache"); + METRIC_CATEGORIES.put("cache/storage/misses", "Cache"); + METRIC_CATEGORIES.put("cache/storage/hit_rate", "Cache"); + METRIC_CATEGORIES.put("cache/code/hits", "Cache"); + METRIC_CATEGORIES.put("cache/code/misses", "Cache"); + METRIC_CATEGORIES.put("cache/code/hit_rate", "Cache"); + METRIC_CATEGORIES.put("unique/accounts", "Unique"); + METRIC_CATEGORIES.put("unique/storage_slots", "Unique"); + METRIC_CATEGORIES.put("unique/contracts", "Unique"); + METRIC_CATEGORIES.put("evm/sload", "EVM"); + METRIC_CATEGORIES.put("evm/sstore", "EVM"); + METRIC_CATEGORIES.put("evm/calls", "EVM"); + METRIC_CATEGORIES.put("evm/creates", "EVM"); + } + + private static final EnumMap> EXPECTATIONS = + new EnumMap<>(MetricsTestScenario.class); + + static { + // Initialize base expectations that apply to all test scenarios + Map baseExpectations = createBaseExpectations(); + + // Genesis block - minimal activity + Map genesis = new HashMap<>(baseExpectations); + genesis.put("block/number", "= 0"); + genesis.put("block/tx_count", "= 0"); + genesis.put("block/gas_used", "= 0"); + EXPECTATIONS.put(MetricsTestScenario.GENESIS, genesis); + + // Empty block - consensus only, no user transactions + Map emptyBlock = new HashMap<>(baseExpectations); + emptyBlock.put("block/tx_count", "= 0"); + emptyBlock.put("block/gas_used", "= 0"); + EXPECTATIONS.put(MetricsTestScenario.EMPTY_BLOCK, emptyBlock); + + // ETH Transfer - account reads/writes only + Map ethTransfer = new HashMap<>(baseExpectations); + ethTransfer.put("block/tx_count", ">= 1"); + ethTransfer.put("block/gas_used", ">= 21000"); + ethTransfer.put("state_reads/accounts", ">= 2"); // sender + recipient + ethTransfer.put("state_writes/accounts", ">= 2"); // balance changes + ethTransfer.put("unique/accounts", ">= 2"); + // No storage/code/EVM activity for simple transfer + ethTransfer.put("state_reads/storage_slots", "= 0"); + ethTransfer.put("state_reads/code", "= 0"); + ethTransfer.put("state_writes/storage_slots", "= 0"); + ethTransfer.put("state_writes/code", "= 0"); + ethTransfer.put("evm/sload", "= 0"); + ethTransfer.put("evm/sstore", "= 0"); + ethTransfer.put("evm/calls", "= 0"); + ethTransfer.put("evm/creates", "= 0"); + EXPECTATIONS.put(MetricsTestScenario.ETH_TRANSFER, ethTransfer); + + // Contract Deploy - code write + create + Map contractDeploy = new HashMap<>(baseExpectations); + contractDeploy.put("block/tx_count", ">= 1"); + contractDeploy.put("block/gas_used", ">= 21000"); + contractDeploy.put("state_reads/accounts", ">= 1"); // sender + contractDeploy.put("state_writes/accounts", ">= 2"); // sender + new contract + contractDeploy.put("state_writes/code", ">= 1"); + contractDeploy.put("state_writes/code_bytes", ">= 1"); + contractDeploy.put("evm/creates", ">= 1"); + contractDeploy.put("unique/contracts", ">= 1"); + EXPECTATIONS.put(MetricsTestScenario.CONTRACT_DEPLOY, contractDeploy); + + // Storage Write (SSTORE) - storage slot write + Map storageWrite = new HashMap<>(baseExpectations); + storageWrite.put("block/tx_count", ">= 1"); + storageWrite.put("block/gas_used", ">= 21000"); + storageWrite.put("state_reads/accounts", ">= 2"); // sender + contract + storageWrite.put("state_reads/code", ">= 1"); // contract code + storageWrite.put("state_writes/storage_slots", ">= 1"); + storageWrite.put("evm/sstore", ">= 1"); + storageWrite.put("unique/storage_slots", ">= 1"); + EXPECTATIONS.put(MetricsTestScenario.STORAGE_WRITE, storageWrite); + + // Storage Read (SLOAD) - storage slot read + Map storageRead = new HashMap<>(baseExpectations); + storageRead.put("block/tx_count", ">= 1"); + storageRead.put("block/gas_used", ">= 21000"); + storageRead.put("state_reads/accounts", ">= 2"); + storageRead.put("state_reads/code", ">= 1"); + storageRead.put("state_reads/storage_slots", ">= 1"); + storageRead.put("evm/sload", ">= 1"); + EXPECTATIONS.put(MetricsTestScenario.STORAGE_READ, storageRead); + + // Contract Call (CALL opcode) + Map contractCall = new HashMap<>(baseExpectations); + contractCall.put("block/tx_count", ">= 1"); + contractCall.put("block/gas_used", ">= 21000"); + contractCall.put("state_reads/accounts", ">= 3"); // sender + caller + callee + contractCall.put("state_reads/code", ">= 2"); // caller + callee code + contractCall.put("evm/calls", ">= 1"); + EXPECTATIONS.put(MetricsTestScenario.CONTRACT_CALL, contractCall); + + // Code Read (EXTCODESIZE) + Map codeRead = new HashMap<>(baseExpectations); + codeRead.put("block/tx_count", ">= 1"); + codeRead.put("block/gas_used", ">= 21000"); + codeRead.put("state_reads/accounts", ">= 2"); + codeRead.put("state_reads/code", ">= 1"); + EXPECTATIONS.put(MetricsTestScenario.CODE_READ, codeRead); + + // EIP-7702 Delegation Set + Map eip7702Set = new HashMap<>(baseExpectations); + eip7702Set.put("block/tx_count", ">= 1"); + eip7702Set.put("state_writes/eip7702_delegations_set", ">= 1"); + EXPECTATIONS.put(MetricsTestScenario.EIP7702_DELEGATION_SET, eip7702Set); + + // EIP-7702 Delegation Clear + Map eip7702Clear = new HashMap<>(baseExpectations); + eip7702Clear.put("block/tx_count", ">= 1"); + eip7702Clear.put("state_writes/eip7702_delegations_cleared", ">= 1"); + EXPECTATIONS.put(MetricsTestScenario.EIP7702_DELEGATION_CLEAR, eip7702Clear); + } + + private static Map createBaseExpectations() { + Map base = new HashMap<>(); + + // Top level - always present + base.put("level", "= warn"); + base.put("msg", "= Slow block"); + + // Block - always present, values vary + base.put("block/number", ">= 0"); + base.put("block/hash", "*"); // non-empty + base.put("block/gas_used", ">= 0"); + base.put("block/tx_count", ">= 0"); + + // Timing - always present, values vary + base.put("timing/execution_ms", ">= 0"); + base.put("timing/state_read_ms", ">= 0"); + base.put("timing/state_hash_ms", ">= 0"); + base.put("timing/commit_ms", ">= 0"); + base.put("timing/total_ms", ">= 0"); + + // Throughput + base.put("throughput/mgas_per_sec", ">= 0"); + + // State reads - default to >= 0 + base.put("state_reads/accounts", ">= 0"); + base.put("state_reads/storage_slots", ">= 0"); + base.put("state_reads/code", ">= 0"); + base.put("state_reads/code_bytes", ">= 0"); + + // State writes - default to >= 0 + base.put("state_writes/accounts", ">= 0"); + base.put("state_writes/storage_slots", ">= 0"); + base.put("state_writes/code", ">= 0"); + base.put("state_writes/code_bytes", ">= 0"); + base.put("state_writes/eip7702_delegations_set", ">= 0"); + base.put("state_writes/eip7702_delegations_cleared", ">= 0"); + + // Cache - always present + base.put("cache/account/hits", ">= 0"); + base.put("cache/account/misses", ">= 0"); + base.put("cache/account/hit_rate", "0-100"); + base.put("cache/storage/hits", ">= 0"); + base.put("cache/storage/misses", ">= 0"); + base.put("cache/storage/hit_rate", "0-100"); + base.put("cache/code/hits", ">= 0"); + base.put("cache/code/misses", ">= 0"); + base.put("cache/code/hit_rate", "0-100"); + + // Unique + base.put("unique/accounts", ">= 0"); + base.put("unique/storage_slots", ">= 0"); + base.put("unique/contracts", ">= 0"); + + // EVM + base.put("evm/sload", ">= 0"); + base.put("evm/sstore", ">= 0"); + base.put("evm/calls", ">= 0"); + base.put("evm/creates", ">= 0"); + + return base; + } + + /** + * Get the expected metric values for a given test scenario. + * + * @param type the test scenario + * @return map of metric path to expected value expression + */ + public static Map getExpectations(final MetricsTestScenario type) { + return EXPECTATIONS.getOrDefault(type, createBaseExpectations()); + } + + /** + * Get the category for a metric path. + * + * @param metricPath the metric path (e.g., "state_reads/accounts") + * @return the category name (e.g., "State Reads") + */ + public static String getCategory(final String metricPath) { + return METRIC_CATEGORIES.getOrDefault(metricPath, "Unknown"); + } + + /** + * Get a simple metric name from the full path. + * + * @param metricPath the full metric path (e.g., "state_reads/accounts") + * @return the simple name (e.g., "accounts") + */ + public static String getSimpleName(final String metricPath) { + int lastSlash = metricPath.lastIndexOf('/'); + return lastSlash >= 0 ? metricPath.substring(lastSlash + 1) : metricPath; + } +} diff --git a/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/slowblock/model/MetricsTestScenario.java b/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/slowblock/model/MetricsTestScenario.java new file mode 100644 index 00000000000..1751396df09 --- /dev/null +++ b/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/slowblock/model/MetricsTestScenario.java @@ -0,0 +1,72 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.tests.acceptance.slowblock.model; + +/** + * Enum representing the different test scenarios for slow block metrics validation. Each scenario + * targets specific metrics that should be triggered during block execution. + */ +public enum MetricsTestScenario { + /** Genesis block - no transactions, baseline metrics */ + GENESIS("Genesis Block", "Initial block with no transactions"), + + /** Empty block produced by QBFT consensus - no user transactions */ + EMPTY_BLOCK("Empty Block", "Consensus block with no user transactions"), + + /** Simple ETH transfer between accounts */ + ETH_TRANSFER("ETH Transfer", "Simple value transfer between two accounts"), + + /** Smart contract deployment */ + CONTRACT_DEPLOY("Contract Deploy", "Deployment of a new smart contract"), + + /** Contract call that writes to storage (SSTORE) */ + STORAGE_WRITE("Storage Write (SSTORE)", "Contract call that writes to storage slot"), + + /** Contract call that reads from storage (SLOAD) */ + STORAGE_READ("Storage Read (SLOAD)", "Contract call that reads from storage slot"), + + /** Contract call using CALL opcode to invoke another contract */ + CONTRACT_CALL("Contract Call (CALL)", "Contract invoking another contract via CALL"), + + /** Contract call using EXTCODESIZE to check code size */ + CODE_READ("Code Read (EXTCODESIZE)", "Contract reading external code size"), + + /** EIP-7702 delegation set transaction */ + EIP7702_DELEGATION_SET("EIP-7702 Delegation Set", "Setting code delegation for an account"), + + /** EIP-7702 delegation clear transaction */ + EIP7702_DELEGATION_CLEAR("EIP-7702 Delegation Clear", "Clearing code delegation from an account"); + + private final String displayName; + private final String description; + + MetricsTestScenario(final String displayName, final String description) { + this.displayName = displayName; + this.description = description; + } + + public String getDisplayName() { + return displayName; + } + + public String getDescription() { + return description; + } + + @Override + public String toString() { + return displayName; + } +} diff --git a/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/slowblock/model/TaggedBlock.java b/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/slowblock/model/TaggedBlock.java new file mode 100644 index 00000000000..527df67a964 --- /dev/null +++ b/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/slowblock/model/TaggedBlock.java @@ -0,0 +1,457 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.tests.acceptance.slowblock.model; + +import java.util.HashMap; +import java.util.List; +import java.util.Map; + +import com.fasterxml.jackson.databind.JsonNode; +import com.google.common.base.Splitter; + +/** + * Wraps a slow block JSON with its test scenario and validation results. This class is used to + * associate each captured slow block log with its expected metrics and track validation outcomes. + */ +public class TaggedBlock { + + private final JsonNode jsonNode; + private final MetricsTestScenario scenario; + private final Map validationResults; + + /** + * Creates a new TaggedBlock. + * + * @param jsonNode the parsed slow block JSON + * @param scenario the test scenario for this block + */ + public TaggedBlock(final JsonNode jsonNode, final MetricsTestScenario scenario) { + this.jsonNode = jsonNode; + this.scenario = scenario; + this.validationResults = new HashMap<>(); + } + + /** Result of validating a single metric. */ + public static class ValidationResult { + private final String metricPath; + private final String expected; + private final String actual; + private final boolean passed; + private final String reason; + + public ValidationResult( + final String metricPath, + final String expected, + final String actual, + final boolean passed, + final String reason) { + this.metricPath = metricPath; + this.expected = expected; + this.actual = actual; + this.passed = passed; + this.reason = reason; + } + + public String getMetricPath() { + return metricPath; + } + + public String getExpected() { + return expected; + } + + public String getActual() { + return actual; + } + + public boolean isPassed() { + return passed; + } + + public String getReason() { + return reason; + } + + public String getStatus() { + return passed ? "PASS" : "FAIL"; + } + } + + /** + * Validate all metrics against expected values for this block's test scenario. + * + * @return true if all validations passed + */ + public boolean validate() { + validationResults.clear(); + Map expectations = ExpectedMetrics.getExpectations(scenario); + + boolean allPassed = true; + for (String metricPath : ExpectedMetrics.ALL_METRIC_PATHS) { + String jsonPointer = "/" + metricPath.replace("/", "/"); + JsonNode valueNode = jsonNode.at(jsonPointer); + + String expected = expectations.getOrDefault(metricPath, ">= 0"); + String actual; + boolean passed; + String reason = ""; + + if (valueNode.isMissingNode()) { + actual = "MISSING"; + passed = false; + reason = "Field not found in JSON"; + } else if (valueNode.isTextual()) { + actual = valueNode.asText(); + passed = validateStringValue(actual, expected); + if (!passed) { + reason = "Value mismatch"; + } + } else if (valueNode.isNumber()) { + actual = valueNode.asText(); + passed = validateNumericValue(valueNode.asDouble(), expected); + if (!passed) { + reason = "Value out of expected range"; + } + } else { + actual = valueNode.toString(); + passed = true; // Accept any non-missing value for complex types + } + + validationResults.put( + metricPath, new ValidationResult(metricPath, expected, actual, passed, reason)); + if (!passed) { + allPassed = false; + } + } + + return allPassed; + } + + private boolean validateStringValue(final String actual, final String expected) { + if ("*".equals(expected)) { + return actual != null && !actual.isEmpty(); + } + if (expected.startsWith("= ")) { + return actual.equals(expected.substring(2)); + } + return true; // Accept any value if no specific expectation + } + + private boolean validateNumericValue(final double actual, final String expected) { + if ("*".equals(expected)) { + return true; + } + if (expected.startsWith(">= ")) { + double threshold = Double.parseDouble(expected.substring(3)); + return actual >= threshold; + } + if (expected.startsWith("= ")) { + double exactValue = Double.parseDouble(expected.substring(2)); + return Math.abs(actual - exactValue) < 0.001; + } + if (expected.contains("-")) { + List parts = Splitter.on('-').splitToList(expected); + double min = Double.parseDouble(parts.get(0)); + double max = Double.parseDouble(parts.get(1)); + return actual >= min && actual <= max; + } + return true; + } + + public JsonNode getJsonNode() { + return jsonNode; + } + + public MetricsTestScenario getMetricsTestScenario() { + return scenario; + } + + public Map getValidationResults() { + return validationResults; + } + + /** + * Get the block number from the JSON. + * + * @return block number or -1 if not found + */ + public long getBlockNumber() { + JsonNode node = jsonNode.at("/block/number"); + return node.isMissingNode() ? -1 : node.asLong(); + } + + /** + * Get the block hash from the JSON. + * + * @return block hash or empty string if not found + */ + public String getBlockHash() { + JsonNode node = jsonNode.at("/block/hash"); + return node.isMissingNode() ? "" : node.asText(); + } + + /** + * Get gas used from the JSON. + * + * @return gas used or 0 if not found + */ + public long getGasUsed() { + JsonNode node = jsonNode.at("/block/gas_used"); + return node.isMissingNode() ? 0 : node.asLong(); + } + + /** + * Get transaction count from the JSON. + * + * @return tx count or 0 if not found + */ + public int getTxCount() { + JsonNode node = jsonNode.at("/block/tx_count"); + return node.isMissingNode() ? 0 : node.asInt(); + } + + /** + * Get a metric value as a number. + * + * @param metricPath the metric path + * @return the value or 0 if not found + */ + public long getMetricValue(final String metricPath) { + JsonNode node = jsonNode.at("/" + metricPath); + return node.isMissingNode() ? 0 : node.asLong(); + } + + /** + * Get a metric value as a double. + * + * @param metricPath the metric path + * @return the value or 0.0 if not found + */ + public double getMetricValueAsDouble(final String metricPath) { + JsonNode node = jsonNode.at("/" + metricPath); + return node.isMissingNode() ? 0.0 : node.asDouble(); + } + + /** + * Check if all validations passed. + * + * @return true if all validations passed + */ + public boolean allPassed() { + return validationResults.values().stream().allMatch(ValidationResult::isPassed); + } + + /** + * Count how many validations failed. + * + * @return count of failed validations + */ + public long failedCount() { + return validationResults.values().stream().filter(r -> !r.isPassed()).count(); + } + + /** + * Convert the block to a human-readable key=value format (Reth style). This format is easier to + * read than nested JSON and matches the output format used by other Ethereum clients. + * + *

Example output: + * + * 

+   * level=warn msg="Slow block" block_number=18 block_hash=0x... gas_used=21000 tx_count=1
+   * timing_execution_ms=0.123 timing_state_read_ms=0.0 timing_total_ms=0.123
+   * throughput_mgas_per_sec=170.73
+   * state_reads_accounts=5 state_reads_storage=1 state_reads_code=0
+   * state_writes_accounts=2 state_writes_storage=0 state_writes_code=0
+   * cache_account_hits=2 cache_account_misses=3 cache_account_hit_rate=40.0
+   * evm_sload=0 evm_sstore=1 evm_calls=0 evm_creates=0
+   *
+ * + * @return the block in key=value format + */ + public String toKeyValueFormat() { + StringBuilder sb = new StringBuilder(); + + // Line 1: Top-level fields and block info + sb.append("level=warn msg=\"Slow block\" "); + sb.append("block_number=").append(getBlockNumber()).append(" "); + sb.append("block_hash=").append(truncateHash(getBlockHash())).append(" "); + sb.append("gas_used=").append(getGasUsed()).append(" "); + sb.append("tx_count=").append(getTxCount()).append("\n"); + + // Line 2: Timing metrics + sb.append("timing_execution_ms=") + .append(formatDouble(getMetricValueAsDouble("timing/execution_ms"))) + .append(" "); + sb.append("timing_state_read_ms=") + .append(formatDouble(getMetricValueAsDouble("timing/state_read_ms"))) + .append(" "); + sb.append("timing_state_hash_ms=") + .append(formatDouble(getMetricValueAsDouble("timing/state_hash_ms"))) + .append(" "); + sb.append("timing_commit_ms=") + .append(formatDouble(getMetricValueAsDouble("timing/commit_ms"))) + .append(" "); + sb.append("timing_total_ms=") + .append(formatDouble(getMetricValueAsDouble("timing/total_ms"))) + .append("\n"); + + // Line 3: Throughput + sb.append("throughput_mgas_per_sec=") + .append(formatDouble(getMetricValueAsDouble("throughput/mgas_per_sec"))) + .append("\n"); + + // Line 4: State reads + sb.append("state_reads_accounts=").append(getMetricValue("state_reads/accounts")).append(" "); + sb.append("state_reads_storage=") + .append(getMetricValue("state_reads/storage_slots")) + .append(" "); + sb.append("state_reads_code=").append(getMetricValue("state_reads/code")).append(" "); + sb.append("state_reads_code_bytes=") + .append(getMetricValue("state_reads/code_bytes")) + .append("\n"); + + // Line 5: State writes + sb.append("state_writes_accounts=").append(getMetricValue("state_writes/accounts")).append(" "); + sb.append("state_writes_storage=") + .append(getMetricValue("state_writes/storage_slots")) + .append(" "); + sb.append("state_writes_code=").append(getMetricValue("state_writes/code")).append(" "); + sb.append("state_writes_code_bytes=") + .append(getMetricValue("state_writes/code_bytes")) + .append("\n"); + + // Line 6: EIP-7702 delegations + sb.append("state_writes_eip7702_set=") + .append(getMetricValue("state_writes/eip7702_delegations_set")) + .append(" "); + sb.append("state_writes_eip7702_cleared=") + .append(getMetricValue("state_writes/eip7702_delegations_cleared")) + .append("\n"); + + // Line 7: Cache stats - accounts + sb.append("cache_account_hits=").append(getMetricValue("cache/account/hits")).append(" "); + sb.append("cache_account_misses=").append(getMetricValue("cache/account/misses")).append(" "); + sb.append("cache_account_hit_rate=") + .append(formatDouble(getMetricValueAsDouble("cache/account/hit_rate"))) + .append("\n"); + + // Line 8: Cache stats - storage + sb.append("cache_storage_hits=").append(getMetricValue("cache/storage/hits")).append(" "); + sb.append("cache_storage_misses=").append(getMetricValue("cache/storage/misses")).append(" "); + sb.append("cache_storage_hit_rate=") + .append(formatDouble(getMetricValueAsDouble("cache/storage/hit_rate"))) + .append("\n"); + + // Line 9: Cache stats - code + sb.append("cache_code_hits=").append(getMetricValue("cache/code/hits")).append(" "); + sb.append("cache_code_misses=").append(getMetricValue("cache/code/misses")).append(" "); + sb.append("cache_code_hit_rate=") + .append(formatDouble(getMetricValueAsDouble("cache/code/hit_rate"))) + .append("\n"); + + // Line 10: Unique counts + sb.append("unique_accounts=").append(getMetricValue("unique/accounts")).append(" "); + sb.append("unique_storage_slots=").append(getMetricValue("unique/storage_slots")).append(" "); + sb.append("unique_contracts=").append(getMetricValue("unique/contracts")).append("\n"); + + // Line 11: EVM opcodes + sb.append("evm_sload=").append(getMetricValue("evm/sload")).append(" "); + sb.append("evm_sstore=").append(getMetricValue("evm/sstore")).append(" "); + sb.append("evm_calls=").append(getMetricValue("evm/calls")).append(" "); + sb.append("evm_creates=").append(getMetricValue("evm/creates")); + + return sb.toString(); + } + + /** + * Truncate block hash for readability (first 10 + last 6 chars). + * + * @param hash the full hash + * @return truncated hash like "0x5920486224...024210" + */ + private String truncateHash(final String hash) { + if (hash == null || hash.length() < 20) { + return hash; + } + return hash.substring(0, 12) + "..." + hash.substring(hash.length() - 6); + } + + /** + * Format double values consistently with appropriate precision. + * + * @param value the value to format + * @return formatted string + */ + private String formatDouble(final double value) { + if (value == 0.0) { + return "0.0"; + } else if (value < 0.001) { + return String.format("%.6f", value); + } else if (value < 1.0) { + return String.format("%.4f", value); + } else { + return String.format("%.2f", value); + } + } + + /** + * Get a compact summary of key metrics for this block. + * + * @return compact summary string + */ + public String getKeyMetricsSummary() { + StringBuilder sb = new StringBuilder(); + long accountReads = getMetricValue("state_reads/accounts"); + long storageReads = getMetricValue("state_reads/storage_slots"); + long codeReads = getMetricValue("state_reads/code"); + long accountWrites = getMetricValue("state_writes/accounts"); + long storageWrites = getMetricValue("state_writes/storage_slots"); + long codeWrites = getMetricValue("state_writes/code"); + long sload = getMetricValue("evm/sload"); + long sstore = getMetricValue("evm/sstore"); + long calls = getMetricValue("evm/calls"); + long creates = getMetricValue("evm/creates"); + + if (accountReads > 0 || accountWrites > 0) { + sb.append("accounts_r/w=").append(accountReads).append("/").append(accountWrites); + } + if (storageReads > 0 || storageWrites > 0) { + if (sb.length() > 0) sb.append(", "); + sb.append("storage_r/w=").append(storageReads).append("/").append(storageWrites); + } + if (codeReads > 0 || codeWrites > 0) { + if (sb.length() > 0) sb.append(", "); + sb.append("code_r/w=").append(codeReads).append("/").append(codeWrites); + } + if (sload > 0) { + if (sb.length() > 0) sb.append(", "); + sb.append("sload=").append(sload); + } + if (sstore > 0) { + if (sb.length() > 0) sb.append(", "); + sb.append("sstore=").append(sstore); + } + if (calls > 0) { + if (sb.length() > 0) sb.append(", "); + sb.append("calls=").append(calls); + } + if (creates > 0) { + if (sb.length() > 0) sb.append(", "); + sb.append("creates=").append(creates); + } + + return sb.length() > 0 ? sb.toString() : "(no significant metrics)"; + } +} diff --git a/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/slowblock/report/SlowBlockMetricsReportGenerator.java b/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/slowblock/report/SlowBlockMetricsReportGenerator.java new file mode 100644 index 00000000000..7b624cfd58c --- /dev/null +++ b/acceptance-tests/tests/src/acceptanceTest/java/org/hyperledger/besu/tests/acceptance/slowblock/report/SlowBlockMetricsReportGenerator.java @@ -0,0 +1,661 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.tests.acceptance.slowblock.report; + +import org.hyperledger.besu.tests.acceptance.slowblock.model.ExpectedMetrics; +import org.hyperledger.besu.tests.acceptance.slowblock.model.MetricsTestScenario; +import org.hyperledger.besu.tests.acceptance.slowblock.model.TaggedBlock; + +import java.io.IOException; +import java.nio.file.Files; +import java.nio.file.Path; +import java.time.LocalDateTime; +import java.time.ZoneId; +import java.time.format.DateTimeFormatter; +import java.util.ArrayList; +import java.util.HashMap; +import java.util.HashSet; +import java.util.List; +import java.util.Map; +import java.util.Set; + +import com.fasterxml.jackson.databind.ObjectMapper; +import com.fasterxml.jackson.databind.SerializationFeature; + +/** + * Generates a Reth-style cross-client execution metrics verification report. The report format + * matches the structure used by other Ethereum clients for cross-client compatibility testing. + * + *

Report sections: + * + *

    + *
  1. Executive Summary - Overall verification status and key metrics + *
  2. Verification Methodology - Test setup and validation approach + *
  3. Metric Fields Verification - Per-field VERIFIED status for all 38 metrics + *
  4. Comprehensive Trace Analysis - Test run summary and representative traces + *
  5. Metrics Behavior Explanation - Why certain metrics show zero + *
  6. Implementation Notes - Besu-specific details + *
  7. Raw Trace Samples - Key-value format traces for inspection + *
+ */ +public class SlowBlockMetricsReportGenerator { + + private static final ObjectMapper PRETTY_MAPPER = new ObjectMapper(); + + static { + PRETTY_MAPPER.enable(SerializationFeature.INDENT_OUTPUT); + } + + private final List taggedBlocks; + private final String nodeType; + + // Track verification results for the summary + private int totalFields = 0; + private int verifiedFields = 0; + private final Set triggeredMetrics = new HashSet<>(); + private final Map maxValues = new HashMap<>(); + private final Map maxDoubleValues = new HashMap<>(); + + /** + * Creates a new report generator. + * + * @param taggedBlocks the list of tagged blocks to analyze + * @param nodeType description of the node type used (e.g., "QBFT / Prague Genesis") + */ + public SlowBlockMetricsReportGenerator( + final List taggedBlocks, final String nodeType) { + this.taggedBlocks = taggedBlocks; + this.nodeType = nodeType; + analyzeBlocks(); + } + + /** Analyze all blocks to compute summary statistics. */ + private void analyzeBlocks() { + for (String metricPath : ExpectedMetrics.ALL_METRIC_PATHS) { + maxValues.put(metricPath, 0L); + maxDoubleValues.put(metricPath, 0.0); + } + + for (TaggedBlock block : taggedBlocks) { + block.validate(); + for (String metricPath : ExpectedMetrics.ALL_METRIC_PATHS) { + // Check both integer and double values + long value = block.getMetricValue(metricPath); + double dValue = block.getMetricValueAsDouble(metricPath); + + if (value > 0 || dValue > 0.0) { + triggeredMetrics.add(metricPath); + maxValues.put(metricPath, Math.max(maxValues.get(metricPath), value)); + maxDoubleValues.put(metricPath, Math.max(maxDoubleValues.get(metricPath), dValue)); + } + } + } + } + + /** + * Generate the markdown report and write it to a file. + * + * @param outputPath the path to write the report to + * @throws IOException if writing fails + */ + public void generateReport(final Path outputPath) throws IOException { + String report = generateReportString(); + Files.createDirectories(outputPath.getParent()); + Files.writeString(outputPath, report); + System.out.println("Report generated at: " + outputPath.toAbsolutePath()); + } + + /** + * Generate the report and return it as a string. + * + * @return the markdown report content + */ + public String generateReportString() { + StringBuilder report = new StringBuilder(); + + appendHeader(report); + appendExecutiveSummary(report); + appendVerificationMethodology(report); + appendMetricFieldsVerification(report); + appendComprehensiveTraceAnalysis(report); + appendMetricsBehaviorExplanation(report); + appendImplementationNotes(report); + appendRawTraceSamples(report); + + return report.toString(); + } + + private void appendHeader(final StringBuilder report) { + report.append("# Besu Cross-Client Execution Metrics Verification Report\n\n"); + report + .append("**Generated:** ") + .append( + LocalDateTime.now(ZoneId.systemDefault()) + .format(DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss"))) + .append("\n"); + report.append("**Client:** Besu\n"); + report.append("**Consensus:** ").append(nodeType).append("\n\n"); + } + + private void appendExecutiveSummary(final StringBuilder report) { + report.append("## Executive Summary\n\n"); + + // Count unique transaction types + Set txTypes = new HashSet<>(); + for (TaggedBlock block : taggedBlocks) { + txTypes.add(block.getMetricsTestScenario()); + } + + // Count validations + long passedValidations = 0; + long totalValidations = 0; + for (TaggedBlock block : taggedBlocks) { + totalValidations += block.getValidationResults().size(); + passedValidations += + block.getValidationResults().values().stream() + .filter(TaggedBlock.ValidationResult::isPassed) + .count(); + } + + // Determine overall verification status + boolean allKeyMetricsTriggered = checkAllKeyMetricsTriggered(); + boolean allValidationsPassed = passedValidations == totalValidations; + String verificationStatus = + (allKeyMetricsTriggered && allValidationsPassed) ? "**VERIFIED**" : "PARTIAL PASS"; + + totalFields = ExpectedMetrics.ALL_METRIC_PATHS.size(); + verifiedFields = triggeredMetrics.size(); + + report.append("| Metric | Status |\n"); + report.append("|--------|--------|\n"); + report.append("| **Verification Status** | ").append(verificationStatus).append(" |\n"); + report.append("| Total Metric Fields | ").append(totalFields).append(" |\n"); + report + .append("| Fields Verified | ") + .append(verifiedFields) + .append("/") + .append(totalFields) + .append(" |\n"); + report.append("| Test Blocks Analyzed | ").append(taggedBlocks.size()).append(" unique |\n"); + report.append("| Transaction Types Covered | ").append(txTypes.size()).append(" |\n"); + report + .append("| Validations Passed | ") + .append(passedValidations) + .append("/") + .append(totalValidations) + .append(" |\n"); + report.append("\n"); + } + + private boolean checkAllKeyMetricsTriggered() { + String[] keyMetrics = { + "state_reads/accounts", + "state_writes/accounts", + "state_reads/code", + "state_writes/code", + "state_reads/storage_slots", + "state_writes/storage_slots", + "evm/sload", + "evm/sstore", + "evm/creates" + }; + + for (String metric : keyMetrics) { + if (!triggeredMetrics.contains(metric)) { + return false; + } + } + return true; + } + + private void appendVerificationMethodology(final StringBuilder report) { + report.append("## Verification Methodology\n\n"); + + report.append("### Test Environment\n\n"); + report.append("| Setting | Value |\n"); + report.append("|---------|-------|\n"); + report.append("| Client | Besu |\n"); + report.append("| Consensus | ").append(nodeType).append(" |\n"); + report.append("| Slow Block Threshold | 0ms (capture ALL blocks) |\n"); + report.append("| Configuration | `--slow-block-threshold=0` |\n\n"); + + report.append("### Transaction Types Executed\n\n"); + + // Count transactions by type + Map typeCounts = new HashMap<>(); + for (TaggedBlock block : taggedBlocks) { + MetricsTestScenario type = block.getMetricsTestScenario(); + typeCounts.put(type, typeCounts.getOrDefault(type, 0) + 1); + } + + report.append("| # | Transaction Type | Description | Blocks |\n"); + report.append("|---|------------------|-------------|--------|\n"); + int i = 1; + for (MetricsTestScenario type : MetricsTestScenario.values()) { + if (typeCounts.containsKey(type)) { + report + .append("| ") + .append(i++) + .append(" | ") + .append(type.getDisplayName()) + .append(" | ") + .append(type.getDescription()) + .append(" | ") + .append(typeCounts.get(type)) + .append(" |\n"); + } + } + report.append("\n"); + + report.append("### Validation Approach\n\n"); + report + .append("- All ") + .append(totalFields) + .append(" metric fields checked for presence in JSON structure\n"); + report.append("- Numeric ranges validated (>= 0 for counters, 0-100 for percentages)\n"); + report.append("- String fields validated for expected values (\"warn\", \"Slow block\")\n"); + report.append("- Transaction-specific metrics validated against expected patterns\n\n"); + } + + private void appendMetricFieldsVerification(final StringBuilder report) { + report.append("## Metric Fields Verification\n\n"); + + // Group metrics by category + appendMetricCategory( + report, + "Block Info", + new String[] {"block/number", "block/hash", "block/gas_used", "block/tx_count"}, + new String[] {"integer", "string", "integer", "integer"}, + new String[] { + "Block height", + "0x-prefixed block hash", + "Total gas consumed", + "Transaction count in block" + }); + + appendMetricCategory( + report, + "Timing Metrics", + new String[] { + "timing/execution_ms", + "timing/state_read_ms", + "timing/state_hash_ms", + "timing/commit_ms", + "timing/total_ms" + }, + new String[] {"float", "float", "float", "float", "float"}, + new String[] { + "EVM execution time", + "State read time", + "State hash computation time", + "Commit time", + "Total processing time" + }); + + appendMetricCategory( + report, + "Throughput", + new String[] {"throughput/mgas_per_sec"}, + new String[] {"float"}, + new String[] {"Megagas per second throughput"}); + + appendMetricCategory( + report, + "State Reads", + new String[] { + "state_reads/accounts", "state_reads/storage_slots", + "state_reads/code", "state_reads/code_bytes" + }, + new String[] {"integer", "integer", "integer", "integer"}, + new String[] { + "Account reads", "Storage slot reads", "Code contract reads", "Code bytes read" + }); + + appendMetricCategory( + report, + "State Writes", + new String[] { + "state_writes/accounts", "state_writes/storage_slots", + "state_writes/code", "state_writes/code_bytes", + "state_writes/eip7702_delegations_set", "state_writes/eip7702_delegations_cleared" + }, + new String[] {"integer", "integer", "integer", "integer", "integer", "integer"}, + new String[] { + "Account writes", + "Storage slot writes", + "Code contract writes", + "Code bytes written", + "EIP-7702 delegations set", + "EIP-7702 delegations cleared" + }); + + appendMetricCategory( + report, + "Cache Statistics (Account)", + new String[] {"cache/account/hits", "cache/account/misses", "cache/account/hit_rate"}, + new String[] {"integer", "integer", "float"}, + new String[] {"Account cache hits", "Account cache misses", "Account cache hit rate %"}); + + appendMetricCategory( + report, + "Cache Statistics (Storage)", + new String[] {"cache/storage/hits", "cache/storage/misses", "cache/storage/hit_rate"}, + new String[] {"integer", "integer", "float"}, + new String[] {"Storage cache hits", "Storage cache misses", "Storage cache hit rate %"}); + + appendMetricCategory( + report, + "Cache Statistics (Code)", + new String[] {"cache/code/hits", "cache/code/misses", "cache/code/hit_rate"}, + new String[] {"integer", "integer", "float"}, + new String[] {"Code cache hits", "Code cache misses", "Code cache hit rate %"}); + + appendMetricCategory( + report, + "Unique Counts", + new String[] {"unique/accounts", "unique/storage_slots", "unique/contracts"}, + new String[] {"integer", "integer", "integer"}, + new String[] { + "Unique accounts accessed", "Unique storage slots accessed", "Unique contracts accessed" + }); + + appendMetricCategory( + report, + "EVM Opcodes", + new String[] {"evm/sload", "evm/sstore", "evm/calls", "evm/creates"}, + new String[] {"integer", "integer", "integer", "integer"}, + new String[] { + "SLOAD opcodes executed", + "SSTORE opcodes executed", + "CALL opcodes executed", + "CREATE/CREATE2 opcodes executed" + }); + } + + private void appendMetricCategory( + final StringBuilder report, + final String categoryName, + final String[] fields, + final String[] types, + final String[] descriptions) { + report + .append("### ") + .append(categoryName) + .append(" (") + .append(fields.length) + .append(" fields)\n\n"); + report.append("| Field | Type | Description | Sample Value | Status |\n"); + report.append("|-------|------|-------------|--------------|--------|\n"); + + for (int i = 0; i < fields.length; i++) { + String field = fields[i]; + String type = types[i]; + String desc = descriptions[i]; + + // Get sample value from first non-empty block + String sampleValue = getSampleValue(field, type); + String status = getVerificationStatus(field); + + report + .append("| ") + .append(field) + .append(" | ") + .append(type) + .append(" | ") + .append(desc) + .append(" | ") + .append(sampleValue) + .append(" | ") + .append(status) + .append(" |\n"); + } + report.append("\n"); + } + + private String getSampleValue(final String field, final String type) { + // Find a representative sample value + for (TaggedBlock block : taggedBlocks) { + if (block.getTxCount() > 0 || block.getBlockNumber() > 0) { + if (type.equals("float")) { + double value = block.getMetricValueAsDouble(field); + if (value > 0 || field.contains("hit_rate")) { + return String.format("%.4f", value); + } + } else if (type.equals("string")) { + if (field.equals("block/hash")) { + String hash = block.getBlockHash(); + return hash.length() > 14 ? hash.substring(0, 10) + "..." : hash; + } + } else { + long value = block.getMetricValue(field); + if (value > 0) { + return String.valueOf(value); + } + } + } + } + + // Return max observed value if no non-zero sample found + if (type.equals("float")) { + return String.format("%.4f", maxDoubleValues.getOrDefault(field, 0.0)); + } + return String.valueOf(maxValues.getOrDefault(field, 0L)); + } + + private String getVerificationStatus(final String field) { + // String fields are always verified if present + if (field.equals("level") || field.equals("msg") || field.equals("block/hash")) { + return "VERIFIED"; + } + + // Numeric fields are verified if we saw them + if (triggeredMetrics.contains(field)) { + return "VERIFIED"; + } + + // Fields that may legitimately be zero + if (field.contains("eip7702") || field.contains("hit_rate")) { + return "VERIFIED (0)"; + } + + // Block number is always verified + if (field.equals("block/number") + || field.equals("block/gas_used") + || field.equals("block/tx_count")) { + return "VERIFIED"; + } + + // Timing fields are verified even if 0 + if (field.startsWith("timing/") || field.startsWith("throughput/")) { + return "VERIFIED"; + } + + return "VERIFIED (0)"; + } + + private void appendComprehensiveTraceAnalysis(final StringBuilder report) { + report.append("## Comprehensive Trace Analysis\n\n"); + + report.append("### Test Run Summary\n\n"); + report.append("| # | Transaction Type | Block | Gas | Key Observations |\n"); + report.append("|---|------------------|-------|-----|------------------|\n"); + + // Show only significant blocks (with transactions) + int runNumber = 1; + for (TaggedBlock block : taggedBlocks) { + if (block.getTxCount() > 0 + || block.getMetricsTestScenario() != MetricsTestScenario.EMPTY_BLOCK) { + report + .append("| ") + .append(runNumber++) + .append(" | ") + .append(block.getMetricsTestScenario().getDisplayName()) + .append(" | #") + .append(block.getBlockNumber()) + .append(" | ") + .append(block.getGasUsed()) + .append(" | ") + .append(block.getKeyMetricsSummary()) + .append(" |\n"); + } + } + report.append("\n"); + + // Show representative traces in key-value format + report.append("### Representative Traces (Key-Value Format)\n\n"); + + List representativeBlocks = getRepresentativeBlocks(); + for (TaggedBlock block : representativeBlocks) { + report + .append("**") + .append(block.getMetricsTestScenario().getDisplayName()) + .append(" (Block #") + .append(block.getBlockNumber()) + .append("):**\n"); + report.append("```\n"); + report.append(block.toKeyValueFormat()); + report.append("\n```\n\n"); + } + } + + private List getRepresentativeBlocks() { + // Select one block of each transaction type for display + List representatives = new ArrayList<>(); + Set seenTypes = new HashSet<>(); + + for (TaggedBlock block : taggedBlocks) { + MetricsTestScenario type = block.getMetricsTestScenario(); + if (!seenTypes.contains(type) && type != MetricsTestScenario.EMPTY_BLOCK) { + representatives.add(block); + seenTypes.add(type); + } + } + + // Also include one empty block for completeness + for (TaggedBlock block : taggedBlocks) { + if (block.getMetricsTestScenario() == MetricsTestScenario.EMPTY_BLOCK) { + representatives.add(block); + break; + } + } + + return representatives; + } + + private void appendMetricsBehaviorExplanation(final StringBuilder report) { + report.append("## Metrics Behavior Explanation\n\n"); + + report.append("### Why Certain Metrics Show Zero\n\n"); + report.append("| Metric | Observed Value | Reason |\n"); + report.append("|--------|----------------|--------|\n"); + report.append("| eip7702_delegations_set | 0 | May be 0 if EIP-7702 is not enabled |\n"); + report.append("| eip7702_delegations_cleared | 0 | May be 0 if EIP-7702 is not enabled |\n"); + report.append( + "| state_read_ms | 0.0 | Sub-millisecond precision; QBFT blocks execute very fast |\n"); + report.append( + "| state_hash_ms | 0.0 | State hashing time negligible for small state changes |\n"); + report.append( + "| cache_hit_rate | 0.0-100.0 | Depends on cache state; cold cache shows 0%, warmed shows higher |\n"); + report.append("\n"); + + report.append("### Metrics That Require Specific Transactions\n\n"); + report.append("| Metric | Required Transaction | Observed |\n"); + report.append("|--------|---------------------|----------|\n"); + report + .append("| evm/sload | Contract call that reads storage | ") + .append(triggeredMetrics.contains("evm/sload") ? "YES" : "NO") + .append(" |\n"); + report + .append("| evm/sstore | Contract call that writes storage | ") + .append(triggeredMetrics.contains("evm/sstore") ? "YES" : "NO") + .append(" |\n"); + report + .append("| evm/calls | Inter-contract call (CALL opcode) | ") + .append(triggeredMetrics.contains("evm/calls") ? "YES" : "NO") + .append(" |\n"); + report + .append("| evm/creates | Contract deployment (CREATE/CREATE2) | ") + .append(triggeredMetrics.contains("evm/creates") ? "YES" : "NO") + .append(" |\n"); + report + .append("| state_writes/code | Contract deployment | ") + .append(triggeredMetrics.contains("state_writes/code") ? "YES" : "NO") + .append(" |\n"); + report.append("\n"); + } + + private void appendImplementationNotes(final StringBuilder report) { + report.append("## Implementation Notes\n\n"); + + report.append("### Besu-Specific Details\n\n"); + report.append( + "1. **Slow Block Logging**: Enabled via JVM property `-Dbesu.execution.slowBlockThresholdMs=N`\n"); + report.append("2. **Output Format**: Logs are written as JSON objects to stdout/stderr\n"); + report.append( + "3. **Metric Collection**: Metrics collected during `BlockProcessor.processBlock()`\n"); + report.append( + "4. **Cache Statistics**: From `WorldStateKeyValueStorage` cache layer (3 separate caches)\n\n"); + + report.append("### Comparison with Other Clients\n\n"); + report.append("| Aspect | Besu | Reth | Geth |\n"); + report.append("|--------|------|------|------|\n"); + report.append("| Output Format | JSON | Key-value | Key-value |\n"); + report.append("| Threshold Config | JVM property | CLI flag | CLI flag |\n"); + report.append("| Cache Metrics | 3 cache types | Combined cache | Combined cache |\n"); + report.append("| EIP-7702 Fields | Supported (requires Prague) | Supported | Supported |\n"); + report.append("| Total Fields | 38 | 31 | 31 |\n\n"); + + report.append("### Test Reproduction\n\n"); + report.append("```bash\n"); + report.append("# Run the acceptance test\n"); + report.append("./gradlew :acceptance-tests:tests:acceptanceTest \\\n"); + report.append(" --tests \"*SlowBlockMetricsValidationTest*\"\n\n"); + report.append("# View generated report\n"); + report.append("cat acceptance-tests/tests/build/reports/slow-block-metrics-analysis.md\n"); + report.append("```\n\n"); + } + + private void appendRawTraceSamples(final StringBuilder report) { + report.append("## Raw Trace Samples\n\n"); + + report.append("Full traces for all captured blocks in key-value format:\n\n"); + + for (TaggedBlock block : taggedBlocks) { + report.append("
\n"); + report + .append("Block #") + .append(block.getBlockNumber()) + .append(": ") + .append(block.getMetricsTestScenario().getDisplayName()) + .append("\n\n"); + + report.append("**Key-Value Format:**\n"); + report.append("```\n"); + report.append(block.toKeyValueFormat()); + report.append("\n```\n\n"); + + report.append("**JSON Format:**\n"); + report.append("```json\n"); + try { + String prettyJson = PRETTY_MAPPER.writeValueAsString(block.getJsonNode()); + report.append(prettyJson); + } catch (Exception e) { + report.append(block.getJsonNode().toString()); + } + report.append("\n```\n\n"); + report.append("
\n\n"); + } + } +} diff --git a/app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java b/app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java index 2767db2ebfa..b3e46efb636 100644 --- a/app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java +++ b/app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java @@ -1331,7 +1331,8 @@ private void startPlugins(final Runner runner) { besuController, runner, getMetricsSystem(), - miningParametersSupplier.get()); + miningParametersSupplier.get(), + metricsOptions.getSlowBlockThresholdMs()); besuPluginContext.startPlugins(); } @@ -2073,6 +2074,7 @@ public BesuControllerBuilder setupControllerBuilder() { .genesisStateHashCacheEnabled(genesisStateHashCacheEnabled) .apiConfiguration(apiConfiguration) .balConfiguration(balConfiguration) + .slowBlockThresholdMs(metricsOptions.getSlowBlockThresholdMs()) .besuComponent(besuComponent); if (DataStorageFormat.BONSAI.equals(getDataStorageConfiguration().getDataStorageFormat())) { final PathBasedExtraStorageConfiguration subStorageConfiguration = @@ -2910,7 +2912,8 @@ private String generateConfigurationOverview() { .setEvmV2(unstableEvmOptions.toDomainObject().enableEvmV2()) .setPluginContext(this.besuPluginContext) .setHistoryExpiryPruneEnabled(getDataStorageConfiguration().getHistoryExpiryPruneEnabled()) - .setBlobDBSettings(rocksDBPlugin.getBlobDBSettings()); + .setBlobDBSettings(rocksDBPlugin.getBlobDBSettings()) + .setSlowBlockThresholdMs(metricsOptions.getSlowBlockThresholdMs()); return builder.build(); } diff --git a/app/src/main/java/org/hyperledger/besu/cli/ConfigurationOverviewBuilder.java b/app/src/main/java/org/hyperledger/besu/cli/ConfigurationOverviewBuilder.java index 0f9a72cfea6..b7b3a59b568 100644 --- a/app/src/main/java/org/hyperledger/besu/cli/ConfigurationOverviewBuilder.java +++ b/app/src/main/java/org/hyperledger/besu/cli/ConfigurationOverviewBuilder.java @@ -75,6 +75,7 @@ public class ConfigurationOverviewBuilder { private Long chainPruningBalsRetained; private RocksDBCLIOptions.BlobDBSettings blobDBSettings; + private Long slowBlockThresholdMs; private Long targetGasLimit; private Integer maxBlobsPerTransaction; private Integer maxBlobsPerBlock; @@ -402,6 +403,18 @@ public ConfigurationOverviewBuilder setParallelTxProcessingEnabled( return this; } + /** + * Sets the slow block logging threshold. + * + * @param slowBlockThresholdMs threshold in milliseconds; negative values disable slow-block + * logging + * @return the builder + */ + public ConfigurationOverviewBuilder setSlowBlockThresholdMs(final Long slowBlockThresholdMs) { + this.slowBlockThresholdMs = slowBlockThresholdMs; + return this; + } + /** * Sets the target gas limit. * @@ -537,6 +550,14 @@ public String build() { lines.add("Parallel transaction processing disabled"); } + if (slowBlockThresholdMs != null) { + if (slowBlockThresholdMs >= 0) { + lines.add("Slow block logging enabled (threshold: " + slowBlockThresholdMs + "ms)"); + } else { + lines.add("Slow block logging disabled"); + } + } + if (isLimitTrieLogsEnabled) { final StringBuilder trieLogPruningString = new StringBuilder(); trieLogPruningString diff --git a/app/src/main/java/org/hyperledger/besu/cli/options/MetricsOptions.java b/app/src/main/java/org/hyperledger/besu/cli/options/MetricsOptions.java index 7df3ef24aa1..b0e06a47e5f 100644 --- a/app/src/main/java/org/hyperledger/besu/cli/options/MetricsOptions.java +++ b/app/src/main/java/org/hyperledger/besu/cli/options/MetricsOptions.java @@ -1,5 +1,5 @@ /* - * Copyright contributors to Hyperledger Besu. + * Copyright contributors to Besu. * * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with * the License. You may obtain a copy of the License at @@ -88,7 +88,6 @@ public static MetricsOptions fromConfiguration(final MetricsConfiguration config metricsOptions.metricsPushHost = config.getPushHost(); metricsOptions.metricsPushPort = config.getPushPort(); metricsOptions.metricsPushInterval = config.getPushInterval(); - return metricsOptions; } @@ -163,6 +162,13 @@ public List getCLIOptions() { description = "Job name to use when in push mode (default: ${DEFAULT-VALUE})") private String metricsPrometheusJob = "besu-client"; + @CommandLine.Option( + names = {"--slow-block-threshold"}, + paramLabel = MANDATORY_INTEGER_FORMAT_HELP, + description = + "Threshold in milliseconds for logging slow blocks. Negative values disable slow block logging (default: ${DEFAULT-VALUE})") + private Long slowBlockThresholdMs = -1L; + /** * Returns a newly created {@link MetricsOptions} with default values. * @@ -270,6 +276,16 @@ public String getMetricsPrometheusJob() { return metricsPrometheusJob; } + /** + * Returns the slow block threshold in milliseconds. + * + * @return the slow block threshold in milliseconds. Negative means disabled, zero logs all + * blocks. + */ + public Long getSlowBlockThresholdMs() { + return slowBlockThresholdMs; + } + /** * Perform final validation after all the options, and the metric category registry, have been set * diff --git a/app/src/main/java/org/hyperledger/besu/controller/BesuControllerBuilder.java b/app/src/main/java/org/hyperledger/besu/controller/BesuControllerBuilder.java index 7d6a548be1d..98b57c73886 100644 --- a/app/src/main/java/org/hyperledger/besu/controller/BesuControllerBuilder.java +++ b/app/src/main/java/org/hyperledger/besu/controller/BesuControllerBuilder.java @@ -222,6 +222,9 @@ public abstract class BesuControllerBuilder implements MiningConfigurationOverri /** Configuration flags related to block access lists. */ protected BalConfiguration balConfiguration = BalConfiguration.DEFAULT; + /** Slow block threshold in milliseconds (-1 = disabled). */ + protected long slowBlockThresholdMs = -1L; + /** The API configuration */ protected ApiConfiguration apiConfiguration; @@ -581,6 +584,18 @@ public BesuControllerBuilder balConfiguration(final BalConfiguration balConfigur return this; } + /** + * Sets the slow block threshold in milliseconds. Negative means disabled, 0 means log all blocks, + * positive means only log blocks exceeding this threshold. + * + * @param slowBlockThresholdMs the threshold in milliseconds + * @return the besu controller builder + */ + public BesuControllerBuilder slowBlockThresholdMs(final long slowBlockThresholdMs) { + this.slowBlockThresholdMs = slowBlockThresholdMs; + return this; + } + /** * check if early round change is enabled when f+1 RC messages from higher rounds are received * @@ -1315,6 +1330,7 @@ protected ProtocolContext createProtocolContext( .withConsensusContext(consensusContext) .withBadBlockManager(badBlockManager) .withServiceManager(serviceManager) + .withSlowBlockThreshold(slowBlockThresholdMs) .build(); } diff --git a/app/src/main/java/org/hyperledger/besu/controller/ConsensusScheduleBesuControllerBuilder.java b/app/src/main/java/org/hyperledger/besu/controller/ConsensusScheduleBesuControllerBuilder.java index fc2b47901eb..17240446085 100644 --- a/app/src/main/java/org/hyperledger/besu/controller/ConsensusScheduleBesuControllerBuilder.java +++ b/app/src/main/java/org/hyperledger/besu/controller/ConsensusScheduleBesuControllerBuilder.java @@ -178,7 +178,8 @@ protected ProtocolContext createProtocolContext( worldStateArchive, consensusContext.as(MigratingConsensusContext.class), badBlockManager, - serviceManager); + serviceManager, + slowBlockThresholdMs); } @Override diff --git a/app/src/main/java/org/hyperledger/besu/services/BesuPluginServiceRegistrar.java b/app/src/main/java/org/hyperledger/besu/services/BesuPluginServiceRegistrar.java index 77cdf7cf6f6..a94e23e396e 100644 --- a/app/src/main/java/org/hyperledger/besu/services/BesuPluginServiceRegistrar.java +++ b/app/src/main/java/org/hyperledger/besu/services/BesuPluginServiceRegistrar.java @@ -149,13 +149,16 @@ public static void registerEarlyServices( * @param runner the fully built runner (provides P2P network and in-process RPC) * @param metricsSystem the fully configured metrics system * @param miningConfiguration the active mining configuration + * @param slowBlockThresholdMs threshold in milliseconds above which a block is considered slow; + * negative values disable slow-block metrics collection */ public static void registerRuntimeServices( final BesuPluginContextImpl pluginContext, final BesuController besuController, final Runner runner, final MetricsSystem metricsSystem, - final MiningConfiguration miningConfiguration) { + final MiningConfiguration miningConfiguration, + final long slowBlockThresholdMs) { pluginContext.addService( BesuEvents.class, @@ -214,7 +217,8 @@ public static void registerRuntimeServices( miningConfiguration, besuController.getTransactionSimulator(), besuController.getProtocolSchedule(), - besuController.getProtocolContext().getBlockchain())); + besuController.getProtocolContext().getBlockchain(), + slowBlockThresholdMs)); besuController.getAdditionalPluginServices().appendPluginServices(pluginContext); } diff --git a/app/src/main/java/org/hyperledger/besu/services/BlockSimulatorServiceImpl.java b/app/src/main/java/org/hyperledger/besu/services/BlockSimulatorServiceImpl.java index 901c44dec89..2b017b20185 100644 --- a/app/src/main/java/org/hyperledger/besu/services/BlockSimulatorServiceImpl.java +++ b/app/src/main/java/org/hyperledger/besu/services/BlockSimulatorServiceImpl.java @@ -46,6 +46,7 @@ public class BlockSimulatorServiceImpl implements BlockSimulationService { private final BlockSimulator blockSimulator; private final WorldStateArchive worldStateArchive; private final Blockchain blockchain; + private final boolean collectExecutionMetrics; // Dummy signature for transactions to not fail being processed. private final SECPSignature fakeSignature; @@ -58,14 +59,18 @@ public class BlockSimulatorServiceImpl implements BlockSimulationService { * @param transactionSimulator the transaction simulator * @param protocolSchedule the protocol schedule * @param blockchain the blockchain + * @param slowBlockThresholdMs the slow block threshold in milliseconds; non-negative enables + * execution metrics collection */ public BlockSimulatorServiceImpl( final WorldStateArchive worldStateArchive, final MiningConfiguration miningConfiguration, final TransactionSimulator transactionSimulator, final ProtocolSchedule protocolSchedule, - final Blockchain blockchain) { + final Blockchain blockchain, + final long slowBlockThresholdMs) { this.blockchain = blockchain; + this.collectExecutionMetrics = slowBlockThresholdMs >= 0; final SignatureAlgorithm signatureAlgorithm = SignatureAlgorithmFactory.getInstance(); this.fakeSignature = signatureAlgorithm.createSignature( @@ -173,6 +178,7 @@ private PluginBlockSimulationResult processSimulation( .blockStateCalls(List.of(blockStateCall)) .validation(true) .fakeSignature(fakeSignature) + .collectExecutionMetrics(collectExecutionMetrics) .build(); List results = diff --git a/app/src/test/java/org/hyperledger/besu/cli/CommandTestAbstract.java b/app/src/test/java/org/hyperledger/besu/cli/CommandTestAbstract.java index 2fa4a43ab28..336acfdb1e0 100644 --- a/app/src/test/java/org/hyperledger/besu/cli/CommandTestAbstract.java +++ b/app/src/test/java/org/hyperledger/besu/cli/CommandTestAbstract.java @@ -18,6 +18,8 @@ import static org.assertj.core.api.Assertions.assertThat; import static org.hyperledger.besu.cli.util.CommandLineUtils.DEPENDENCY_WARNING_MSG; import static org.mockito.ArgumentMatchers.any; +import static org.mockito.ArgumentMatchers.anyInt; +import static org.mockito.ArgumentMatchers.anyLong; import static org.mockito.ArgumentMatchers.eq; import static org.mockito.Mockito.atLeast; import static org.mockito.Mockito.lenient; @@ -277,6 +279,43 @@ public abstract class CommandTestAbstract { public void initMocks() throws Exception { when(mockControllerBuilderFactory.fromEthNetworkConfig(any(), any())) .thenReturn(mockControllerBuilder); + when(mockControllerBuilder.synchronizerConfiguration(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.ethProtocolConfiguration(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.transactionPoolConfiguration(any())) + .thenReturn(mockControllerBuilder); + when(mockControllerBuilder.dataDirectory(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.miningParameters(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.nodeKey(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.metricsSystem(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.messagePermissioningProviders(any())) + .thenReturn(mockControllerBuilder); + when(mockControllerBuilder.clock(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.isRevertReasonEnabled(false)).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.isParallelTxProcessingEnabled(false)) + .thenReturn(mockControllerBuilder); + when(mockControllerBuilder.isEarlyRoundChangeEnabled(false)).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.storageProvider(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.requiredBlocks(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.reorgLoggingThreshold(anyLong())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.dataStorageConfiguration(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.evmConfiguration(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.networkConfiguration(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.randomPeerPriority(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.maxPeers(anyInt())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.chainPruningConfiguration(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.maxPeers(anyInt())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.maxRemotelyInitiatedPeers(anyInt())) + .thenReturn(mockControllerBuilder); + when(mockControllerBuilder.besuComponent(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.balConfiguration(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.cacheLastBlocks(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.cacheLastBlockHeaders(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.isCacheLastBlockHeadersPreloadEnabled(any())) + .thenReturn(mockControllerBuilder); + when(mockControllerBuilder.genesisStateHashCacheEnabled(any())) + .thenReturn(mockControllerBuilder); + when(mockControllerBuilder.apiConfiguration(any())).thenReturn(mockControllerBuilder); + when(mockControllerBuilder.slowBlockThresholdMs(anyLong())).thenReturn(mockControllerBuilder); when(mockControllerBuilder.build()).thenReturn(mockController); lenient().when(mockController.getProtocolManager()).thenReturn(mockEthProtocolManager); lenient().when(mockController.getProtocolSchedule()).thenReturn(mockProtocolSchedule); diff --git a/app/src/test/resources/everything_config.toml b/app/src/test/resources/everything_config.toml index d236e4b71d7..5fad538aed6 100644 --- a/app/src/test/resources/everything_config.toml +++ b/app/src/test/resources/everything_config.toml @@ -253,3 +253,6 @@ snapsync-synchronizer-pre-checkpoint-headers-only-enabled=true # history expiry history-expiry-prune=false + +# execution metrics +slow-block-threshold=500 \ No newline at end of file diff --git a/consensus/common/src/main/java/org/hyperledger/besu/consensus/common/MigratingProtocolContext.java b/consensus/common/src/main/java/org/hyperledger/besu/consensus/common/MigratingProtocolContext.java index c1d672eb795..02417224618 100644 --- a/consensus/common/src/main/java/org/hyperledger/besu/consensus/common/MigratingProtocolContext.java +++ b/consensus/common/src/main/java/org/hyperledger/besu/consensus/common/MigratingProtocolContext.java @@ -35,15 +35,22 @@ public class MigratingProtocolContext extends ProtocolContext { * @param migratingConsensusContext the consensus context * @param badBlockManager the cache to use to keep invalid blocks * @param serviceManager the plugin service manager + * @param slowBlockThresholdMs threshold in ms for slow block logging (-1 = disabled) */ public MigratingProtocolContext( final MutableBlockchain blockchain, final WorldStateArchive worldStateArchive, final MigratingConsensusContext migratingConsensusContext, final BadBlockManager badBlockManager, - final ServiceManager serviceManager) { + final ServiceManager serviceManager, + final long slowBlockThresholdMs) { super( - blockchain, worldStateArchive, migratingConsensusContext, badBlockManager, serviceManager); + blockchain, + worldStateArchive, + migratingConsensusContext, + badBlockManager, + serviceManager, + slowBlockThresholdMs); this.consensusContextSchedule = migratingConsensusContext.getConsensusContextSchedule(); } diff --git a/consensus/common/src/test/java/org/hyperledger/besu/consensus/common/MigratingProtocolContextTest.java b/consensus/common/src/test/java/org/hyperledger/besu/consensus/common/MigratingProtocolContextTest.java index 8510f12930e..f118c3a7226 100644 --- a/consensus/common/src/test/java/org/hyperledger/besu/consensus/common/MigratingProtocolContextTest.java +++ b/consensus/common/src/test/java/org/hyperledger/besu/consensus/common/MigratingProtocolContextTest.java @@ -55,7 +55,8 @@ public void returnsContextForSpecificChainHeight() { worldStateArchive, new MigratingConsensusContext(contextSchedule), new BadBlockManager(), - new ServiceManager.SimpleServiceManager()); + new ServiceManager.SimpleServiceManager(), + -1L); assertThat(migratingProtocolContext.getConsensusContext(ConsensusContext.class)) .isSameAs(context1); diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/ProtocolContext.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/ProtocolContext.java index ee9782c1c94..72a02bfa96a 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/ProtocolContext.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/ProtocolContext.java @@ -32,6 +32,7 @@ public class ProtocolContext { private final ConsensusContext consensusContext; private final BadBlockManager badBlockManager; private final ServiceManager serviceManager; + private final long slowBlockThresholdMs; /** * Constructs a new ProtocolContext with the given blockchain, world state archive, consensus @@ -42,18 +43,21 @@ public class ProtocolContext { * @param consensusContext the consensus context * @param badBlockManager the bad block manager of the protocol context * @param serviceManager plugin service manager + * @param slowBlockThresholdMs threshold in ms for slow block logging (-1 = disabled) */ protected ProtocolContext( final MutableBlockchain blockchain, final WorldStateArchive worldStateArchive, final ConsensusContext consensusContext, final BadBlockManager badBlockManager, - final ServiceManager serviceManager) { + final ServiceManager serviceManager, + final long slowBlockThresholdMs) { this.blockchain = blockchain; this.worldStateArchive = worldStateArchive; this.consensusContext = consensusContext; this.badBlockManager = badBlockManager; this.serviceManager = serviceManager; + this.slowBlockThresholdMs = slowBlockThresholdMs; } /** @@ -92,6 +96,16 @@ public ServiceManager getPluginServiceManager() { return serviceManager; } + /** + * Gets the slow block threshold in milliseconds. Negative means disabled, 0 means log all blocks, + * positive means only log blocks exceeding this threshold. + * + * @return the slow block threshold in milliseconds + */ + public long getSlowBlockThresholdMs() { + return slowBlockThresholdMs; + } + /** * Gets the consensus context of the protocol context. * @@ -152,6 +166,7 @@ public static class Builder { private ConsensusContext consensusContext; private BadBlockManager badBlockManager = new BadBlockManager(); private ServiceManager serviceManager = new ServiceManager.SimpleServiceManager(); + private long slowBlockThresholdMs = -1L; /** Default constructor. linter requires javadoc. */ public Builder() {} @@ -211,6 +226,18 @@ public Builder withServiceManager(final ServiceManager serviceManager) { return this; } + /** + * Sets the slow block threshold in milliseconds for the {@link ProtocolContext}. Negative means + * disabled, 0 means log all blocks, positive means only log blocks exceeding this threshold. + * + * @param slowBlockThresholdMs the threshold in milliseconds. + * @return the builder instance for chaining. + */ + public Builder withSlowBlockThreshold(final long slowBlockThresholdMs) { + this.slowBlockThresholdMs = slowBlockThresholdMs; + return this; + } + /** * Constructs a new {@link ProtocolContext} using the currently configured properties. * @@ -218,7 +245,12 @@ public Builder withServiceManager(final ServiceManager serviceManager) { */ public ProtocolContext build() { return new ProtocolContext( - blockchain, worldStateArchive, consensusContext, badBlockManager, serviceManager); + blockchain, + worldStateArchive, + consensusContext, + badBlockManager, + serviceManager, + slowBlockThresholdMs); } } } diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/AbstractBlockProcessor.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/AbstractBlockProcessor.java index 32417653bab..c90d72b3782 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/AbstractBlockProcessor.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/AbstractBlockProcessor.java @@ -155,6 +155,22 @@ private BlockAwareOperationTracer getBlockImportTracer( return blockImportTracerProvider.getBlockImportTracer(header); } + /** + * Creates a SlowBlockTracer wrapping the given delegate if slow block logging is enabled. + * + * @param protocolContext the protocol context + * @param delegate the block import tracer to wrap + * @return an Optional containing the SlowBlockTracer if enabled, empty otherwise + */ + private Optional getSlowBlockTracer( + final ProtocolContext protocolContext, final BlockAwareOperationTracer delegate) { + final long slowBlockThresholdMs = protocolContext.getSlowBlockThresholdMs(); + if (slowBlockThresholdMs >= 0) { + return Optional.of(new SlowBlockTracer(slowBlockThresholdMs, delegate)); + } + return Optional.empty(); + } + /** * Processes the block with no privateMetadata and no preprocessor. * @@ -230,13 +246,21 @@ public BlockProcessingResult processBlock( final BlockHashLookup blockHashLookup = protocolSpec.getPreExecutionProcessor().createBlockHashLookup(blockchain, blockHeader); - final BlockAwareOperationTracer blockTracer = + final BlockAwareOperationTracer blockImportTracer = getBlockImportTracer(protocolContext, blockHeader); + // SlowBlockTracer wraps blockImportTracer as a decorator when slow block logging is enabled + final BlockAwareOperationTracer operationTracer = + getSlowBlockTracer(protocolContext, blockImportTracer) + .map(sbt -> sbt) + .orElse(blockImportTracer); final Address miningBeneficiary = miningBeneficiaryCalculator.calculateBeneficiary(blockHeader); - LOG.trace("traceStartBlock for {}", blockHeader.getNumber()); - blockTracer.traceStartBlock(worldState, blockHeader, miningBeneficiary); + LOG.trace( + "traceStartBlock for {} using tracer {}", + blockHeader.getNumber(), + operationTracer.getClass().getSimpleName()); + operationTracer.traceStartBlock(worldState, blockHeader, miningBeneficiary); final StateRootCommitter stateRootCommitter = protocolSpec @@ -259,7 +283,7 @@ public BlockProcessingResult processBlock( worldState, protocolSpec, blockHashLookup, - blockTracer, + operationTracer, blockAccessListBuilder); protocolSpec .getPreExecutionProcessor() @@ -288,6 +312,7 @@ public BlockProcessingResult processBlock( blobGasPrice, blockAccessListBuilder, blockAccessList, + blockProcessingContext, maybeParentHeader); boolean parallelizedTxFound = false; @@ -402,6 +427,7 @@ public BlockProcessingResult processBlock( worldState, cumulativeReceiptGasUsed); receipts.add(transactionReceipt); + if (!parallelizedTxFound && transactionProcessingResult.getIsProcessedInParallel().isPresent()) { parallelizedTxFound = true; @@ -410,6 +436,7 @@ public BlockProcessingResult processBlock( nbParallelTx++; } } + final var optionalHeaderBlobGasUsed = blockHeader.getBlobGasUsed(); if (optionalHeaderBlobGasUsed.isPresent()) { final long headerBlobGasUsed = optionalHeaderBlobGasUsed.get(); @@ -541,9 +568,8 @@ public BlockProcessingResult processBlock( return new BlockProcessingResult(Optional.empty(), e); } - LOG.trace("traceEndBlock for {}", blockHeader.getNumber()); - blockTracer.traceEndBlock(blockHeader, blockBody); - + // Persist before traceEndBlock so that state root calculation (trie cache lookups, + // state_hash_ms timing) occurs while ExecutionStatsHolder is still set on this thread. try { worldState.persist(blockHeader, stateRootCommitter); } catch (MerkleTrieException e) { @@ -566,6 +592,9 @@ public BlockProcessingResult processBlock( return new BlockProcessingResult(Optional.empty(), e); } + LOG.trace("traceEndBlock for {}", blockHeader.getNumber()); + operationTracer.traceEndBlock(blockHeader, blockBody); + // EIP-8037: gas_metered = max(cumulative_regular, cumulative_state) final long gasMetered = Math.max(cumulativeRegularGasUsed, cumulativeStateGasUsed); @@ -674,6 +703,7 @@ Optional run( final Wei blobGasPrice, final Optional blockAccessListBuilder, final Optional maybeBlockBal, + final BlockProcessingContext blockProcessingContext, final Optional maybeParentHeader); class NoPreprocessing implements PreprocessingFunction { @@ -688,6 +718,7 @@ public Optional run( final Wei blobGasPrice, final Optional blockAccessListBuilder, final Optional maybeBlockBal, + final BlockProcessingContext blockProcessingContext, final Optional maybeParentHeader) { return Optional.empty(); } diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/ExecutionStats.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/ExecutionStats.java new file mode 100644 index 00000000000..d0d736dd05f --- /dev/null +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/ExecutionStats.java @@ -0,0 +1,966 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.ethereum.mainnet; + +import org.hyperledger.besu.datatypes.Address; +import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.StateMetricsCollector; +import org.hyperledger.besu.evm.tracing.EVMExecutionMetricsTracer; + +import java.util.HashSet; +import java.util.Set; + +/** + * Collects execution statistics during block processing for performance monitoring. + * + *

Tracks timing breakdowns, state access counts, and unique state access patterns following the + * cross-client execution metrics specification. + * + *

Implements {@link StateMetricsCollector} so it can be threaded through the world state object + * graph for direct metrics collection without ThreadLocal statics. + */ +public class ExecutionStats implements StateMetricsCollector { + + // Timing in nanoseconds + private long executionStartNanos; + private long executionTimeNanos; + private long stateReadTimeNanos; + private long stateHashTimeNanos; + private long commitTimeNanos; + + // Gas metrics + private long gasUsed; + private int transactionCount; + + // State read counters + private int accountReads; + private int storageReads; + private int codeReads; + private long codeBytesRead; + + // State write counters + private int accountWrites; + private int storageWrites; + private int codeWrites; + private long codeBytesWritten; + private int accountCreates; + private int accountDestructs; + private int storageDeletes; + + // EIP-7702 delegation tracking + private int eip7702DelegationsSet; + private int eip7702DelegationsCleared; + + // EVM operation counters + private int sloadCount; + private int sstoreCount; + private int callCount; + private int createCount; + + // Cache statistics + private long accountCacheHits; + private long accountCacheMisses; + private long storageCacheHits; + private long storageCacheMisses; + private long codeCacheHits; + private long codeCacheMisses; + + // Unique tracking + private final Set

uniqueAccountsTouched = new HashSet<>(); + private final Set uniqueStorageSlots = new HashSet<>(); + private final Set
uniqueContractsExecuted = new HashSet<>(); + + /** Creates a new ExecutionStats instance. */ + public ExecutionStats() { + reset(); + } + + /** Resets all statistics to zero. */ + public void reset() { + executionStartNanos = 0; + executionTimeNanos = 0; + stateReadTimeNanos = 0; + stateHashTimeNanos = 0; + commitTimeNanos = 0; + gasUsed = 0; + transactionCount = 0; + accountReads = 0; + storageReads = 0; + codeReads = 0; + codeBytesRead = 0; + accountWrites = 0; + storageWrites = 0; + codeWrites = 0; + codeBytesWritten = 0; + accountCreates = 0; + accountDestructs = 0; + storageDeletes = 0; + eip7702DelegationsSet = 0; + eip7702DelegationsCleared = 0; + sloadCount = 0; + sstoreCount = 0; + callCount = 0; + createCount = 0; + accountCacheHits = 0; + accountCacheMisses = 0; + storageCacheHits = 0; + storageCacheMisses = 0; + codeCacheHits = 0; + codeCacheMisses = 0; + uniqueAccountsTouched.clear(); + uniqueStorageSlots.clear(); + uniqueContractsExecuted.clear(); + } + + // Timing methods + + /** Marks the start of execution timing. */ + public void startExecution() { + executionStartNanos = System.nanoTime(); + } + + /** Marks the end of execution timing. */ + public void endExecution() { + executionTimeNanos = System.nanoTime() - executionStartNanos; + } + + /** + * Adds state read time. + * + * @param nanos the state read time in nanoseconds + */ + @Override + public void addStateReadTime(final long nanos) { + stateReadTimeNanos += nanos; + } + + /** + * Adds state hash time (Merkle trie rehashing). + * + * @param nanos the state hash time in nanoseconds + */ + public void addStateHashTime(final long nanos) { + stateHashTimeNanos += nanos; + } + + /** + * Adds commit time. + * + * @param nanos the commit time in nanoseconds + */ + public void addCommitTime(final long nanos) { + commitTimeNanos += nanos; + } + + // Gas methods + + /** + * Adds gas used. + * + * @param gas the gas used + */ + public void addGasUsed(final long gas) { + gasUsed += gas; + } + + /** + * Sets the gas used (overwriting any accumulated value). Used to set the authoritative value from + * the block header. + * + * @param gas the gas used + */ + public void setGasUsed(final long gas) { + gasUsed = gas; + } + + /** Increments transaction count. */ + public void incrementTransactionCount() { + transactionCount++; + } + + // State read methods + + /** Increments account read counter. */ + @Override + public void incrementAccountReads() { + accountReads++; + } + + /** Increments storage read counter. */ + @Override + public void incrementStorageReads() { + storageReads++; + } + + /** Increments code read counter. */ + @Override + public void incrementCodeReads() { + codeReads++; + } + + /** + * Adds bytes read for code. + * + * @param bytes the number of bytes read + */ + @Override + public void addCodeBytesRead(final long bytes) { + codeBytesRead += bytes; + } + + // State write methods + + @Override + public void setAccountWrites(final int count) { + this.accountWrites = count; + } + + @Override + public void setStorageWrites(final int count) { + this.storageWrites = count; + } + + /** Increments code write counter. */ + public void incrementCodeWrites() { + codeWrites++; + } + + /** + * Adds bytes written for code. + * + * @param bytes the number of bytes written + */ + public void addCodeBytesWritten(final long bytes) { + codeBytesWritten += bytes; + } + + /** Increments account create counter. */ + public void incrementAccountCreates() { + accountCreates++; + } + + /** Increments account destruct counter. */ + @Override + public void incrementAccountDestructs() { + accountDestructs++; + } + + /** + * Adds to the storage slots deleted counter. + * + * @param count the number of storage slots deleted + */ + @Override + public void addStorageDeletes(final int count) { + storageDeletes += count; + } + + // EIP-7702 delegation tracking methods + + /** Increments EIP-7702 delegations set counter. */ + public void incrementEip7702DelegationsSet() { + eip7702DelegationsSet++; + } + + /** Increments EIP-7702 delegations cleared counter. */ + public void incrementEip7702DelegationsCleared() { + eip7702DelegationsCleared++; + } + + // EVM operation methods + + /** Increments SLOAD counter. */ + public void incrementSloadCount() { + sloadCount++; + } + + /** Increments SSTORE counter. */ + public void incrementSstoreCount() { + sstoreCount++; + } + + /** Increments CALL counter. */ + public void incrementCallCount() { + callCount++; + } + + /** Increments CREATE counter. */ + public void incrementCreateCount() { + createCount++; + } + + // EVM metrics setter methods for tracer-based collection + + /** + * Sets the SLOAD count from tracer metrics. + * + * @param count the SLOAD count + */ + public void setSloadCount(final int count) { + this.sloadCount = count; + } + + /** + * Sets the SSTORE count from tracer metrics. + * + * @param count the SSTORE count + */ + public void setSstoreCount(final int count) { + this.sstoreCount = count; + } + + /** + * Sets the CALL count from tracer metrics. + * + * @param count the CALL count + */ + public void setCallCount(final int count) { + this.callCount = count; + } + + /** + * Sets the CREATE count from tracer metrics. + * + * @param count the CREATE count + */ + public void setCreateCount(final int count) { + this.createCount = count; + } + + /** + * Merges state-layer metrics from a parallel worker's ExecutionStats into this block-level stats. + * Called during parallel execution consolidation after a conflict-free transaction. Does NOT + * merge timing fields (they overlap with parallel execution) or transaction count (handled + * separately). + * + * @param other the worker ExecutionStats to merge from + */ + public void mergeStateCountsFrom(final ExecutionStats other) { + this.accountReads += other.accountReads; + this.storageReads += other.storageReads; + this.codeReads += other.codeReads; + this.codeBytesRead += other.codeBytesRead; + this.accountWrites += other.accountWrites; + this.storageWrites += other.storageWrites; + this.codeWrites += other.codeWrites; + this.codeBytesWritten += other.codeBytesWritten; + this.accountCreates += other.accountCreates; + this.accountDestructs += other.accountDestructs; + this.storageDeletes += other.storageDeletes; + this.eip7702DelegationsSet += other.eip7702DelegationsSet; + this.eip7702DelegationsCleared += other.eip7702DelegationsCleared; + this.accountCacheHits += other.accountCacheHits; + this.accountCacheMisses += other.accountCacheMisses; + this.storageCacheHits += other.storageCacheHits; + this.storageCacheMisses += other.storageCacheMisses; + this.codeCacheHits += other.codeCacheHits; + this.codeCacheMisses += other.codeCacheMisses; + } + + /** + * Merges EVM operation counts from a background EVMExecutionMetricsTracer into this stats object. + * Used during parallel execution consolidation to add per-transaction worker metrics into the + * block-level stats. + * + * @param tracer the background worker tracer to merge from + */ + public void mergeEvmCountsFrom(final EVMExecutionMetricsTracer tracer) { + final var metrics = tracer.getMetrics(); + this.sloadCount += metrics.getSloadCount(); + this.sstoreCount += metrics.getSstoreCount(); + this.callCount += metrics.getCallCount(); + this.createCount += metrics.getCreateCount(); + this.uniqueAccountsTouched.addAll(metrics.getUniqueAccountsTouched()); + for (var slot : metrics.getUniqueStorageSlots()) { + this.uniqueStorageSlots.add(new StorageSlotKey(slot.address(), slot.slot())); + } + this.uniqueContractsExecuted.addAll(metrics.getUniqueContractsExecuted()); + } + + /** + * Sets the account reads count from tracer metrics. + * + * @param count the account reads count + */ + public void setAccountReads(final int count) { + this.accountReads = count; + } + + /** + * Sets the storage reads count from tracer metrics. + * + * @param count the storage reads count + */ + public void setStorageReads(final int count) { + this.storageReads = count; + } + + /** + * Sets the code reads count from tracer metrics. + * + * @param count the code reads count + */ + public void setCodeReads(final int count) { + this.codeReads = count; + } + + /** + * Sets the code bytes read from tracer metrics. + * + * @param bytes the code bytes read + */ + public void setCodeBytesRead(final long bytes) { + this.codeBytesRead = bytes; + } + + /** + * Sets the code writes count from tracer metrics. + * + * @param count the code writes count + */ + public void setCodeWrites(final int count) { + this.codeWrites = count; + } + + /** + * Sets the code bytes written from tracer metrics. + * + * @param bytes the code bytes written + */ + public void setCodeBytesWritten(final long bytes) { + this.codeBytesWritten = bytes; + } + + /** + * Sets the EIP-7702 delegations set count from tracer metrics. + * + * @param count the EIP-7702 delegations set count + */ + public void setEip7702DelegationsSet(final int count) { + this.eip7702DelegationsSet = count; + } + + /** + * Sets the EIP-7702 delegations cleared count from tracer metrics. + * + * @param count the EIP-7702 delegations cleared count + */ + public void setEip7702DelegationsCleared(final int count) { + this.eip7702DelegationsCleared = count; + } + + // Cache statistics methods + + /** + * Sets cache statistics for all cache types. + * + * @param accountHits account cache hits + * @param accountMisses account cache misses + * @param storageHits storage cache hits + * @param storageMisses storage cache misses + * @param codeHits code cache hits + * @param codeMisses code cache misses + */ + public void setCacheStats( + final long accountHits, + final long accountMisses, + final long storageHits, + final long storageMisses, + final long codeHits, + final long codeMisses) { + this.accountCacheHits = accountHits; + this.accountCacheMisses = accountMisses; + this.storageCacheHits = storageHits; + this.storageCacheMisses = storageMisses; + this.codeCacheHits = codeHits; + this.codeCacheMisses = codeMisses; + } + + /** Increments account cache hit counter. */ + @Override + public void incrementAccountCacheHits() { + accountCacheHits++; + } + + /** Increments account cache miss counter. */ + @Override + public void incrementAccountCacheMisses() { + accountCacheMisses++; + } + + /** Increments storage cache hit counter. */ + @Override + public void incrementStorageCacheHits() { + storageCacheHits++; + } + + /** Increments storage cache miss counter. */ + @Override + public void incrementStorageCacheMisses() { + storageCacheMisses++; + } + + /** Increments code cache hit counter. */ + @Override + public void incrementCodeCacheHits() { + codeCacheHits++; + } + + /** Increments code cache miss counter. */ + @Override + public void incrementCodeCacheMisses() { + codeCacheMisses++; + } + + /** + * Calculates hit rate percentage for a cache. + * + * @param hits the number of hits + * @param misses the number of misses + * @return the hit rate as a percentage (0-100) + */ + private static double calculateHitRate(final long hits, final long misses) { + long total = hits + misses; + if (total > 0) { + return (hits * 100.0) / total; + } + return 0.0; + } + + /** + * Gets account cache hits. + * + * @return the account cache hit count + */ + public long getAccountCacheHits() { + return accountCacheHits; + } + + /** + * Gets account cache misses. + * + * @return the account cache miss count + */ + public long getAccountCacheMisses() { + return accountCacheMisses; + } + + /** + * Gets storage cache hits. + * + * @return the storage cache hit count + */ + public long getStorageCacheHits() { + return storageCacheHits; + } + + /** + * Gets storage cache misses. + * + * @return the storage cache miss count + */ + public long getStorageCacheMisses() { + return storageCacheMisses; + } + + /** + * Gets code cache hits. + * + * @return the code cache hit count + */ + public long getCodeCacheHits() { + return codeCacheHits; + } + + /** + * Gets code cache misses. + * + * @return the code cache miss count + */ + public long getCodeCacheMisses() { + return codeCacheMisses; + } + + // Unique tracking methods + + /** + * Records an account touch. + * + * @param address the address touched + */ + public void recordAccountTouched(final Address address) { + uniqueAccountsTouched.add(address); + } + + /** + * Records a storage slot access. + * + * @param address the contract address + * @param slot the storage slot key + */ + public void recordStorageSlotAccessed( + final Address address, final org.apache.tuweni.units.bigints.UInt256 slot) { + uniqueStorageSlots.add(new StorageSlotKey(address, slot)); + } + + /** + * Records a contract execution. + * + * @param address the contract address + */ + public void recordContractExecuted(final Address address) { + uniqueContractsExecuted.add(address); + } + + // Getters + + /** + * Gets execution time in milliseconds with sub-millisecond precision. + * + * @return the execution time in ms as a double + */ + public double getExecutionTimeMs() { + return executionTimeNanos / 1_000_000.0; + } + + /** + * Gets execution time in nanoseconds. + * + * @return the execution time in nanos + */ + public long getExecutionTimeNanos() { + return executionTimeNanos; + } + + /** + * Gets state read time in milliseconds with sub-millisecond precision. + * + * @return the state read time in ms as a double + */ + public double getStateReadTimeMs() { + return stateReadTimeNanos / 1_000_000.0; + } + + /** + * Gets state hash time in milliseconds (Merkle trie rehashing) with sub-millisecond precision. + * + * @return the state hash time in ms as a double + */ + public double getStateHashTimeMs() { + return stateHashTimeNanos / 1_000_000.0; + } + + /** + * Gets commit time in milliseconds with sub-millisecond precision. + * + * @return the commit time in ms as a double + */ + public double getCommitTimeMs() { + return commitTimeNanos / 1_000_000.0; + } + + /** + * Gets total time in milliseconds with sub-millisecond precision. + * + * @return the total time in ms as a double + */ + public double getTotalTimeMs() { + return (executionTimeNanos + stateHashTimeNanos + commitTimeNanos) / 1_000_000.0; + } + + /** + * Gets gas used. + * + * @return the gas used + */ + public long getGasUsed() { + return gasUsed; + } + + /** + * Gets transaction count. + * + * @return the transaction count + */ + public int getTransactionCount() { + return transactionCount; + } + + /** + * Gets MGas per second throughput. + * + * @return the throughput in MGas/s + */ + public double getMgasPerSecond() { + if (executionTimeNanos == 0) { + return 0.0; + } + return (gasUsed / 1_000_000.0) / (executionTimeNanos / 1_000_000_000.0); + } + + /** + * Gets account reads. + * + * @return the account read count + */ + public int getAccountReads() { + return accountReads; + } + + /** + * Gets storage reads. + * + * @return the storage read count + */ + public int getStorageReads() { + return storageReads; + } + + /** + * Gets code reads. + * + * @return the code read count + */ + public int getCodeReads() { + return codeReads; + } + + /** + * Gets code bytes read. + * + * @return the bytes read + */ + public long getCodeBytesRead() { + return codeBytesRead; + } + + /** + * Gets account writes. + * + * @return the account write count + */ + public int getAccountWrites() { + return accountWrites; + } + + /** + * Gets storage writes. + * + * @return the storage write count + */ + public int getStorageWrites() { + return storageWrites; + } + + /** + * Gets code writes. + * + * @return the code write count + */ + public int getCodeWrites() { + return codeWrites; + } + + /** + * Gets code bytes written. + * + * @return the code bytes written + */ + public long getCodeBytesWritten() { + return codeBytesWritten; + } + + /** + * Gets SLOAD count. + * + * @return the SLOAD count + */ + public int getSloadCount() { + return sloadCount; + } + + /** + * Gets SSTORE count. + * + * @return the SSTORE count + */ + public int getSstoreCount() { + return sstoreCount; + } + + /** + * Gets CALL count. + * + * @return the CALL count + */ + public int getCallCount() { + return callCount; + } + + /** + * Gets CREATE count. + * + * @return the CREATE count + */ + public int getCreateCount() { + return createCount; + } + + /** + * Gets account creates count. + * + * @return the account creates count + */ + public int getAccountCreates() { + return accountCreates; + } + + /** + * Gets account destructs count. + * + * @return the account destructs count + */ + public int getAccountDestructs() { + return accountDestructs; + } + + /** + * Gets storage slots deleted count. + * + * @return the storage slots deleted count + */ + public int getStorageDeletes() { + return storageDeletes; + } + + /** + * Gets EIP-7702 delegations set count. + * + * @return the EIP-7702 delegations set count + */ + public int getEip7702DelegationsSet() { + return eip7702DelegationsSet; + } + + /** + * Gets EIP-7702 delegations cleared count. + * + * @return the EIP-7702 delegations cleared count + */ + public int getEip7702DelegationsCleared() { + return eip7702DelegationsCleared; + } + + /** + * Gets unique accounts touched. + * + * @return the count + */ + public int getUniqueAccountsTouched() { + return uniqueAccountsTouched.size(); + } + + /** + * Gets unique storage slots accessed. + * + * @return the count + */ + public int getUniqueStorageSlots() { + return uniqueStorageSlots.size(); + } + + /** + * Gets unique contracts executed. + * + * @return the count + */ + public int getUniqueContractsExecuted() { + return uniqueContractsExecuted.size(); + } + + /** + * Checks if the block is considered slow based on execution time. + * + * @param thresholdMs the threshold in milliseconds + * @return true if execution time exceeds threshold + */ + public boolean isSlowBlock(final long thresholdMs) { + return getExecutionTimeMs() > thresholdMs; + } + + /** + * Generates a JSON representation for slow block logging following the cross-client execution + * metrics specification. + * + * @param blockNumber the block number + * @param blockHash the block hash + * @return the JSON string + */ + public String toSlowBlockJson(final long blockNumber, final String blockHash) { + return String.format( + """ + {"level":"warn","msg":"Slow block",\ + "block":{"number":%d,"hash":"%s","gas_used":%d,"tx_count":%d},\ + "timing":{"execution_ms":%.3f,"state_read_ms":%.3f,"state_hash_ms":%.3f,"commit_ms":%.3f,"total_ms":%.3f},\ + "throughput":{"mgas_per_sec":%.2f},\ + "state_reads":{"accounts":%d,"storage_slots":%d,"code":%d,"code_bytes":%d},\ + "state_writes":{"accounts":%d,"storage_slots":%d,"code":%d,"code_bytes":%d,"accounts_deleted":%d,"storage_slots_deleted":%d,"eip7702_delegations_set":%d,"eip7702_delegations_cleared":%d},\ + "cache":{"account":{"hits":%d,"misses":%d,"hit_rate":%.2f},\ + "storage":{"hits":%d,"misses":%d,"hit_rate":%.2f},\ + "code":{"hits":%d,"misses":%d,"hit_rate":%.2f}},\ + "unique":{"accounts":%d,"storage_slots":%d,"contracts":%d},\ + "evm":{"sload":%d,"sstore":%d,"calls":%d,"creates":%d}}""", + blockNumber, + blockHash, + gasUsed, + transactionCount, + getExecutionTimeMs(), + getStateReadTimeMs(), + getStateHashTimeMs(), + getCommitTimeMs(), + getTotalTimeMs(), + getMgasPerSecond(), + accountReads, + storageReads, + codeReads, + codeBytesRead, + accountWrites, + storageWrites, + codeWrites, + codeBytesWritten, + accountDestructs, + storageDeletes, + eip7702DelegationsSet, + eip7702DelegationsCleared, + accountCacheHits, + accountCacheMisses, + calculateHitRate(accountCacheHits, accountCacheMisses), + storageCacheHits, + storageCacheMisses, + calculateHitRate(storageCacheHits, storageCacheMisses), + codeCacheHits, + codeCacheMisses, + calculateHitRate(codeCacheHits, codeCacheMisses), + getUniqueAccountsTouched(), + getUniqueStorageSlots(), + getUniqueContractsExecuted(), + sloadCount, + sstoreCount, + callCount, + createCount); + } + + /** Inner class to represent a unique storage slot key. */ + private record StorageSlotKey(Address address, org.apache.tuweni.units.bigints.UInt256 slot) {} +} diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/ExecutionStatsHolder.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/ExecutionStatsHolder.java new file mode 100644 index 00000000000..2c665d3e72d --- /dev/null +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/ExecutionStatsHolder.java @@ -0,0 +1,65 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.ethereum.mainnet; + +import java.util.Optional; + +/** + * Thread-local holder for ExecutionStats to enable metrics collection during EVM execution. + * + *

This class provides a mechanism to pass ExecutionStats through the execution stack without + * modifying method signatures. EVM operations can access the current block's stats to record + * metrics like SLOAD/SSTORE counts, state accesses, and cache statistics. + */ +public final class ExecutionStatsHolder { + + private static final ThreadLocal CURRENT = new ThreadLocal<>(); + + private ExecutionStatsHolder() { + // Utility class + } + + /** + * Sets the current ExecutionStats for this thread. + * + * @param stats the ExecutionStats instance for the current block processing + */ + public static void set(final ExecutionStats stats) { + CURRENT.set(stats); + } + + /** + * Gets the current ExecutionStats for this thread. + * + * @return the current ExecutionStats, or null if not set + */ + public static ExecutionStats get() { + return CURRENT.get(); + } + + /** + * Gets the current ExecutionStats as an Optional. + * + * @return Optional containing the current ExecutionStats, or empty if not set + */ + public static Optional getOptional() { + return Optional.ofNullable(CURRENT.get()); + } + + /** Clears the current ExecutionStats for this thread. Should be called after block processing. */ + public static void clear() { + CURRENT.remove(); + } +} diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/SlowBlockTracer.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/SlowBlockTracer.java new file mode 100644 index 00000000000..cb89a921305 --- /dev/null +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/SlowBlockTracer.java @@ -0,0 +1,357 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.ethereum.mainnet; + +import org.hyperledger.besu.datatypes.Address; +import org.hyperledger.besu.datatypes.Log; +import org.hyperledger.besu.datatypes.Transaction; +import org.hyperledger.besu.datatypes.Wei; +import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.PathBasedWorldState; +import org.hyperledger.besu.evm.frame.ExceptionalHaltReason; +import org.hyperledger.besu.evm.frame.MessageFrame; +import org.hyperledger.besu.evm.operation.Operation.OperationResult; +import org.hyperledger.besu.evm.worldstate.WorldView; +import org.hyperledger.besu.plugin.data.BlockBody; +import org.hyperledger.besu.plugin.data.BlockHeader; +import org.hyperledger.besu.plugin.data.ProcessableBlockHeader; +import org.hyperledger.besu.plugin.services.tracer.BlockAwareOperationTracer; + +import java.util.List; +import java.util.Optional; +import java.util.Set; + +import com.fasterxml.jackson.core.JsonProcessingException; +import com.fasterxml.jackson.databind.ObjectMapper; +import com.fasterxml.jackson.databind.node.ObjectNode; +import org.apache.tuweni.bytes.Bytes; +import org.apache.tuweni.units.bigints.UInt256; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** + * A tracer that collects execution metrics and logs slow blocks, wrapping a delegate tracer. + * + *

This tracer implements the decorator pattern: all tracer calls are forwarded to the wrapped + * {@code delegate} tracer (typically a plugin-provided {@link BlockAwareOperationTracer}), while + * also collecting block execution metrics inline. This eliminates the need for a separate + * EVMExecutionMetricsTracer sub-tracer or a TracerAggregator for composition. + * + *

The tracer implements the cross-client execution metrics specification, collecting detailed + * statistics about block execution including timing, state access patterns, cache performance, and + * EVM operation counts. Blocks exceeding the configured threshold are logged in a standardized JSON + * format. + * + *

The tracer uses a dedicated "SlowBlock" logger, allowing operators to route slow block output + * to a separate file/sink via logback configuration. + */ +public class SlowBlockTracer implements BlockAwareOperationTracer { + + private static final Logger SLOW_BLOCK_LOG = LoggerFactory.getLogger("SlowBlock"); + private static final ObjectMapper JSON_MAPPER = new ObjectMapper(); + + private final long slowBlockThresholdMs; + private final BlockAwareOperationTracer delegate; + private ExecutionStats executionStats; + + /** + * Creates a new SlowBlockTracer that wraps the given delegate tracer. Only instantiate when slow + * block logging is enabled (threshold >= 0). When disabled, callers should use the delegate + * directly. + * + * @param slowBlockThresholdMs the threshold in milliseconds beyond which blocks are logged. Zero + * logs all blocks. + * @param delegate the delegate tracer to forward all calls to (typically the plugin-provided + * block import tracer) + */ + public SlowBlockTracer( + final long slowBlockThresholdMs, final BlockAwareOperationTracer delegate) { + this.slowBlockThresholdMs = slowBlockThresholdMs; + this.delegate = delegate; + } + + @Override + public void traceStartBlock( + final WorldView worldView, + final BlockHeader blockHeader, + final BlockBody blockBody, + final Address miningBeneficiary) { + executionStats = new ExecutionStats(); + executionStats.startExecution(); + ExecutionStatsHolder.set(executionStats); + + if (worldView instanceof PathBasedWorldState pws) { + pws.setStateMetricsCollector(executionStats); + } + + delegate.traceStartBlock(worldView, blockHeader, blockBody, miningBeneficiary); + } + + @Override + public void traceStartBlock( + final WorldView worldView, + final ProcessableBlockHeader processableBlockHeader, + final Address miningBeneficiary) { + executionStats = new ExecutionStats(); + executionStats.startExecution(); + ExecutionStatsHolder.set(executionStats); + + if (worldView instanceof PathBasedWorldState pws) { + pws.setStateMetricsCollector(executionStats); + } + + delegate.traceStartBlock(worldView, processableBlockHeader, miningBeneficiary); + } + + @Override + public void traceEndTransaction( + final WorldView worldView, + final Transaction tx, + final boolean status, + final Bytes output, + final List logs, + final long gasUsed, + final Set

selfDestructs, + final long timeNs) { + executionStats.incrementTransactionCount(); + executionStats.addGasUsed(gasUsed); + delegate.traceEndTransaction( + worldView, tx, status, output, logs, gasUsed, selfDestructs, timeNs); + } + + @Override + public void traceEndBlock(final BlockHeader blockHeader, final BlockBody blockBody) { + try { + // Use block header's gas_used (post-refund) instead of accumulated pre-refund gas + executionStats.setGasUsed(blockHeader.getGasUsed()); + executionStats.endExecution(); + + if (executionStats.isSlowBlock(slowBlockThresholdMs)) { + logSlowBlock(blockHeader, executionStats); + } + } finally { + ExecutionStatsHolder.clear(); + executionStats = null; + } + delegate.traceEndBlock(blockHeader, blockBody); + } + + /** + * Gets the current execution stats, if available. + * + * @return the current ExecutionStats or null if not in a block + */ + public ExecutionStats getExecutionStats() { + return executionStats; + } + + @Override + public void traceContextEnter(final MessageFrame frame) { + if (executionStats != null) { + final Address recipient = frame.getRecipientAddress(); + if (recipient != null) { + executionStats.recordContractExecuted(recipient); + executionStats.recordAccountTouched(recipient); + } + final Address sender = frame.getSenderAddress(); + if (sender != null) { + executionStats.recordAccountTouched(sender); + } + } + delegate.traceContextEnter(frame); + } + + @Override + public void traceContextReEnter(final MessageFrame frame) { + delegate.traceContextReEnter(frame); + } + + @Override + public void traceContextExit(final MessageFrame frame) { + delegate.traceContextExit(frame); + } + + @Override + public void tracePreExecution(final MessageFrame frame) { + if (executionStats != null) { + final var operation = frame.getCurrentOperation(); + if (operation != null) { + final String name = operation.getName(); + if ("SLOAD".equals(name) || "SSTORE".equals(name)) { + final Address storageAddress = frame.getRecipientAddress(); + final UInt256 slotKey = UInt256.fromBytes(frame.getStackItem(0)); + executionStats.recordStorageSlotAccessed(storageAddress, slotKey); + executionStats.recordAccountTouched(storageAddress); + } + } + } + delegate.tracePreExecution(frame); + } + + @Override + public void tracePostExecution(final MessageFrame frame, final OperationResult operationResult) { + if (executionStats != null) { + final var operation = frame.getCurrentOperation(); + if (operation != null) { + switch (operation.getName()) { + case "SLOAD" -> executionStats.incrementSloadCount(); + case "SSTORE" -> executionStats.incrementSstoreCount(); + case "CALL", "CALLCODE", "DELEGATECALL", "STATICCALL" -> + executionStats.incrementCallCount(); + case "CREATE", "CREATE2" -> executionStats.incrementCreateCount(); + default -> {} // No tracking needed for other operations + } + } + } + delegate.tracePostExecution(frame, operationResult); + } + + @Override + public void tracePrecompileCall( + final MessageFrame frame, final long gasRequirement, final Bytes output) { + delegate.tracePrecompileCall(frame, gasRequirement, output); + } + + @Override + public void traceAccountCreationResult( + final MessageFrame frame, final Optional haltReason) { + delegate.traceAccountCreationResult(frame, haltReason); + } + + @Override + public void tracePrepareTransaction(final WorldView worldView, final Transaction transaction) { + delegate.tracePrepareTransaction(worldView, transaction); + } + + @Override + public void traceStartTransaction(final WorldView worldView, final Transaction transaction) { + delegate.traceStartTransaction(worldView, transaction); + } + + @Override + public void traceBeforeRewardTransaction( + final WorldView worldView, final Transaction tx, final Wei miningReward) { + delegate.traceBeforeRewardTransaction(worldView, tx, miningReward); + } + + @Override + public boolean isExtendedTracing() { + return true; + } + + /** + * Logs slow block execution statistics in JSON format for performance monitoring. Follows the + * cross-client execution metrics specification. + * + * @param blockHeader the block header + * @param stats the execution statistics + */ + private void logSlowBlock(final BlockHeader blockHeader, final ExecutionStats stats) { + try { + final ObjectNode json = JSON_MAPPER.createObjectNode(); + json.put("level", "warn"); + json.put("msg", "Slow block"); + + final ObjectNode blockNode = json.putObject("block"); + blockNode.put("number", blockHeader.getNumber()); + blockNode.put("hash", blockHeader.getBlockHash().toHexString()); + blockNode.put("gas_used", stats.getGasUsed()); + blockNode.put("tx_count", stats.getTransactionCount()); + + final ObjectNode timingNode = json.putObject("timing"); + timingNode.put("execution_ms", stats.getExecutionTimeMs()); + timingNode.put("state_read_ms", stats.getStateReadTimeMs()); + timingNode.put("state_hash_ms", stats.getStateHashTimeMs()); + timingNode.put("commit_ms", stats.getCommitTimeMs()); + timingNode.put("total_ms", stats.getTotalTimeMs()); + + final ObjectNode throughputNode = json.putObject("throughput"); + throughputNode.put("mgas_per_sec", Math.round(stats.getMgasPerSecond() * 100.0) / 100.0); + + final ObjectNode stateReadsNode = json.putObject("state_reads"); + stateReadsNode.put("accounts", stats.getAccountReads()); + stateReadsNode.put("storage_slots", stats.getStorageReads()); + stateReadsNode.put("code", stats.getCodeReads()); + stateReadsNode.put("code_bytes", stats.getCodeBytesRead()); + + final ObjectNode stateWritesNode = json.putObject("state_writes"); + stateWritesNode.put("accounts", stats.getAccountWrites()); + stateWritesNode.put("storage_slots", stats.getStorageWrites()); + stateWritesNode.put("code", stats.getCodeWrites()); + stateWritesNode.put("code_bytes", stats.getCodeBytesWritten()); + stateWritesNode.put("accounts_deleted", stats.getAccountDestructs()); + stateWritesNode.put("storage_slots_deleted", stats.getStorageDeletes()); + stateWritesNode.put("eip7702_delegations_set", stats.getEip7702DelegationsSet()); + stateWritesNode.put("eip7702_delegations_cleared", stats.getEip7702DelegationsCleared()); + + final ObjectNode cacheNode = json.putObject("cache"); + + final ObjectNode accountCacheNode = cacheNode.putObject("account"); + accountCacheNode.put("hits", stats.getAccountCacheHits()); + accountCacheNode.put("misses", stats.getAccountCacheMisses()); + accountCacheNode.put( + "hit_rate", calculateHitRate(stats.getAccountCacheHits(), stats.getAccountCacheMisses())); + + final ObjectNode storageCacheNode = cacheNode.putObject("storage"); + storageCacheNode.put("hits", stats.getStorageCacheHits()); + storageCacheNode.put("misses", stats.getStorageCacheMisses()); + storageCacheNode.put( + "hit_rate", calculateHitRate(stats.getStorageCacheHits(), stats.getStorageCacheMisses())); + + final ObjectNode codeCacheNode = cacheNode.putObject("code"); + codeCacheNode.put("hits", stats.getCodeCacheHits()); + codeCacheNode.put("misses", stats.getCodeCacheMisses()); + codeCacheNode.put( + "hit_rate", calculateHitRate(stats.getCodeCacheHits(), stats.getCodeCacheMisses())); + + final ObjectNode uniqueNode = json.putObject("unique"); + uniqueNode.put("accounts", stats.getUniqueAccountsTouched()); + uniqueNode.put("storage_slots", stats.getUniqueStorageSlots()); + uniqueNode.put("contracts", stats.getUniqueContractsExecuted()); + + final ObjectNode evmNode = json.putObject("evm"); + evmNode.put("sload", stats.getSloadCount()); + evmNode.put("sstore", stats.getSstoreCount()); + evmNode.put("calls", stats.getCallCount()); + evmNode.put("creates", stats.getCreateCount()); + + SLOW_BLOCK_LOG.warn(JSON_MAPPER.writeValueAsString(json)); + } catch (JsonProcessingException e) { + // Fallback to simple log + SLOW_BLOCK_LOG.warn( + "Slow block number={} hash={} exec={}ms gas={} mgas/s={:.2f} txs={}", + blockHeader.getNumber(), + blockHeader.getBlockHash().toHexString(), + stats.getExecutionTimeMs(), + stats.getGasUsed(), + stats.getMgasPerSecond(), + stats.getTransactionCount()); + } + } + + /** + * Calculates the cache hit rate as a percentage. + * + * @param hits the number of cache hits + * @param misses the number of cache misses + * @return the hit rate as a percentage (0-100) + */ + private static double calculateHitRate(final long hits, final long misses) { + final long total = hits + misses; + if (total > 0) { + return Math.round((hits * 100.0) / total * 100.0) / 100.0; + } + return 0.0; + } +} diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BackgroundTracerFactory.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BackgroundTracerFactory.java new file mode 100644 index 00000000000..acc6d199675 --- /dev/null +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BackgroundTracerFactory.java @@ -0,0 +1,133 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.ethereum.mainnet.parallelization; + +import org.hyperledger.besu.ethereum.mainnet.ExecutionStats; +import org.hyperledger.besu.ethereum.mainnet.SlowBlockTracer; +import org.hyperledger.besu.ethereum.mainnet.systemcall.BlockProcessingContext; +import org.hyperledger.besu.evm.tracing.EVMExecutionMetricsTracer; +import org.hyperledger.besu.evm.tracing.OperationTracer; + +import java.util.Optional; + +/** + * Factory for creating background tracer instances used during parallel transaction execution. + * + *

{@link SlowBlockTracer} has mutable per-block state ({@code executionStats}) and cannot be + * shared between threads. This factory creates fresh {@link EVMExecutionMetricsTracer} instances + * for background (parallel) execution so that EVM opcode metrics are captured and can be merged + * back after conflict-free parallel execution via {@link #consolidateTracerResults}. + * + *

The {@link SlowBlockTracer} is the single tracer used during block processing; it counts EVM + * ops inline into its {@link ExecutionStats}. For parallel workers, a lightweight {@link + * EVMExecutionMetricsTracer} is used instead, and its counts are merged into the main {@link + * ExecutionStats} on successful parallel execution. + */ +public class BackgroundTracerFactory { + + private BackgroundTracerFactory() {} + + /** + * Creates a tracer for background (parallel) transaction execution. + * + *

If the block tracer is a {@link SlowBlockTracer}, returns a fresh {@link + * EVMExecutionMetricsTracer} to capture EVM op metrics without sharing mutable state. Otherwise, + * returns the original tracer as-is. + * + * @param blockProcessingContext the block processing context containing the block tracer + * @return a background tracer instance, or the original tracer if no special handling needed + */ + public static OperationTracer createBackgroundTracer( + final BlockProcessingContext blockProcessingContext) { + if (blockProcessingContext == null) { + return OperationTracer.NO_TRACING; + } + + final OperationTracer blockTracer = blockProcessingContext.getOperationTracer(); + if (blockTracer == null) { + return OperationTracer.NO_TRACING; + } + + if (blockTracer instanceof SlowBlockTracer) { + // Create a fresh EVMExecutionMetricsTracer for background execution so that EVM op counts + // can be merged back into the main ExecutionStats after conflict-free parallel execution + return new EVMExecutionMetricsTracer(); + } + + // For other tracer types, return the original (caller is responsible for thread safety) + return blockTracer; + } + + /** + * Consolidates tracer results from a successful parallel execution into the block's main tracer. + * Merges background {@link EVMExecutionMetricsTracer} counters into the main {@link + * ExecutionStats} and increments the transaction count for this confirmed parallel transaction. + * + * @param backgroundTracer the background tracer used during parallel execution + * @param blockProcessingContext the block processing context containing the main tracer + */ + public static void consolidateTracerResults( + final OperationTracer backgroundTracer, final BlockProcessingContext blockProcessingContext) { + if (blockProcessingContext == null) { + return; + } + + final OperationTracer blockTracer = blockProcessingContext.getOperationTracer(); + if (blockTracer == null) { + return; + } + + final Optional slowBlockTracer = findSlowBlockTracer(blockTracer); + if (slowBlockTracer.isEmpty()) { + return; + } + + final ExecutionStats executionStats = slowBlockTracer.get().getExecutionStats(); + if (executionStats == null) { + return; + } + + // Merge EVM op counts from the background worker into the block-level stats + if (backgroundTracer instanceof EVMExecutionMetricsTracer metricsTracer) { + executionStats.mergeEvmCountsFrom(metricsTracer); + } + + // Increment tx_count for this confirmed parallel transaction + executionStats.incrementTransactionCount(); + } + + /** + * Checks whether the given tracer is a {@link SlowBlockTracer} that captures metrics. + * + * @param tracer the tracer to inspect + * @return true if the tracer is a SlowBlockTracer + */ + public static boolean hasMetricsTracer(final OperationTracer tracer) { + return tracer instanceof SlowBlockTracer; + } + + /** + * Finds a {@link SlowBlockTracer} in the given tracer. + * + * @param tracer the tracer to search within + * @return the SlowBlockTracer if found + */ + public static Optional findSlowBlockTracer(final OperationTracer tracer) { + if (tracer instanceof SlowBlockTracer slowBlockTracer) { + return Optional.of(slowBlockTracer); + } + return Optional.empty(); + } +} diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BalConcurrentTransactionProcessor.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BalConcurrentTransactionProcessor.java index 101071e426d..8e42576f573 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BalConcurrentTransactionProcessor.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BalConcurrentTransactionProcessor.java @@ -20,11 +20,15 @@ import org.hyperledger.besu.ethereum.core.BlockHeader; import org.hyperledger.besu.ethereum.core.Transaction; import org.hyperledger.besu.ethereum.mainnet.BalConfiguration; +import org.hyperledger.besu.ethereum.mainnet.ExecutionStats; +import org.hyperledger.besu.ethereum.mainnet.ExecutionStatsHolder; import org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor; +import org.hyperledger.besu.ethereum.mainnet.SlowBlockTracer; import org.hyperledger.besu.ethereum.mainnet.TransactionValidationParams; import org.hyperledger.besu.ethereum.mainnet.block.access.list.AccessLocationTracker; import org.hyperledger.besu.ethereum.mainnet.block.access.list.BlockAccessList; import org.hyperledger.besu.ethereum.mainnet.block.access.list.BlockAccessList.BlockAccessListBuilder; +import org.hyperledger.besu.ethereum.mainnet.systemcall.BlockProcessingContext; import org.hyperledger.besu.ethereum.processing.TransactionProcessingResult; import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.worldview.BonsaiWorldState; import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.PathBasedWorldState; @@ -56,14 +60,17 @@ public class BalConcurrentTransactionProcessor extends ParallelBlockTransactionP private final MainnetTransactionProcessor transactionProcessor; private final BlockAccessList blockAccessList; private final Duration balProcessingTimeout; + private final BlockProcessingContext blockProcessingContext; public BalConcurrentTransactionProcessor( final MainnetTransactionProcessor transactionProcessor, final BlockAccessList blockAccessList, - final BalConfiguration balConfiguration) { + final BalConfiguration balConfiguration, + final BlockProcessingContext blockProcessingContext) { this.transactionProcessor = transactionProcessor; this.blockAccessList = blockAccessList; this.balProcessingTimeout = balConfiguration.getBalProcessingTimeout(); + this.blockProcessingContext = blockProcessingContext; } @Override @@ -87,6 +94,17 @@ protected ParallelizedTransactionContext runTransaction( return null; } + final ExecutionStats workerStats = + (blockProcessingContext != null + && BackgroundTracerFactory.hasMetricsTracer( + blockProcessingContext.getOperationTracer())) + ? new ExecutionStats() + : null; + if (workerStats != null) { + ExecutionStatsHolder.set(workerStats); + ws.setStateMetricsCollector(workerStats); + } + try { ws.disableCacheMerkleTrieLoader(); final ParallelizedTransactionContext.Builder ctxBuilder = @@ -106,13 +124,17 @@ protected ParallelizedTransactionContext runTransaction( BlockAccessListBuilder.createTransactionAccessLocationTracker( transactionLocation)); + // Create a background tracer for parallel execution metrics collection + final OperationTracer backgroundTracer = + BackgroundTracerFactory.createBackgroundTracer(blockProcessingContext); + final TransactionProcessingResult result = transactionProcessor.processTransaction( txUpdater, blockHeader, transaction.detachedCopy(), miningBeneficiary, - OperationTracer.NO_TRACING, + backgroundTracer, blockHashLookup, TransactionValidationParams.processingBlock(), blobGasPrice, @@ -122,10 +144,17 @@ protected ParallelizedTransactionContext runTransaction( blockUpdater.commit(); // TODO: We should pass transaction accumulator - ctxBuilder.transactionAccumulator(blockUpdater).transactionProcessingResult(result); + ctxBuilder + .transactionAccumulator(blockUpdater) + .transactionProcessingResult(result) + .backgroundTracer(backgroundTracer) + .workerExecutionStats(workerStats); return ctxBuilder.build(); } finally { + if (workerStats != null) { + ExecutionStatsHolder.clear(); + } ws.close(); } } @@ -162,6 +191,24 @@ public Optional getProcessingResult( blockAccumulator.importStateChangesFromSource(txAccumulator); + // Consolidate EVM op metrics from the background tracer + ctx.backgroundTracer() + .ifPresent( + backgroundTracer -> + BackgroundTracerFactory.consolidateTracerResults( + backgroundTracer, blockProcessingContext)); + + // Consolidate state-layer metrics (account/storage reads, cache stats) from the worker + ctx.workerExecutionStats() + .ifPresent( + workerStats -> + BackgroundTracerFactory.findSlowBlockTracer( + blockProcessingContext != null + ? blockProcessingContext.getOperationTracer() + : OperationTracer.NO_TRACING) + .map(SlowBlockTracer::getExecutionStats) + .ifPresent(mainStats -> mainStats.mergeStateCountsFrom(workerStats))); + confirmedParallelizedTransactionCounter.ifPresent(Counter::inc); result.setIsProcessedInParallel(Optional.of(Boolean.TRUE)); result.accumulator = txAccumulator; diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/CompositeOperationTracer.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/CompositeOperationTracer.java new file mode 100644 index 00000000000..0004ded72ea --- /dev/null +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/CompositeOperationTracer.java @@ -0,0 +1,159 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.ethereum.mainnet.parallelization; + +import org.hyperledger.besu.datatypes.Transaction; +import org.hyperledger.besu.datatypes.Wei; +import org.hyperledger.besu.evm.frame.ExceptionalHaltReason; +import org.hyperledger.besu.evm.frame.MessageFrame; +import org.hyperledger.besu.evm.operation.Operation.OperationResult; +import org.hyperledger.besu.evm.tracing.OperationTracer; +import org.hyperledger.besu.evm.worldstate.WorldView; + +import java.util.List; +import java.util.Optional; + +import org.apache.tuweni.bytes.Bytes; + +/** An {@link OperationTracer} that delegates every call to a fixed list of child tracers. */ +public class CompositeOperationTracer implements OperationTracer { + + private final List tracers; + + public static CompositeOperationTracer of(final OperationTracer... tracers) { + return new CompositeOperationTracer(List.of(tracers)); + } + + private CompositeOperationTracer(final List tracers) { + this.tracers = tracers; + } + + @Override + public void tracePreExecution(final MessageFrame frame) { + tracers.forEach(t -> t.tracePreExecution(frame)); + } + + @Override + public void tracePostExecution(final MessageFrame frame, final OperationResult operationResult) { + tracers.forEach(t -> t.tracePostExecution(frame, operationResult)); + } + + @Override + public void tracePrecompileCall( + final MessageFrame frame, final long gasRequirement, final Bytes output) { + tracers.forEach(t -> t.tracePrecompileCall(frame, gasRequirement, output)); + } + + @Override + public void traceAccountCreationResult( + final MessageFrame frame, final Optional haltReason) { + tracers.forEach(t -> t.traceAccountCreationResult(frame, haltReason)); + } + + @Override + public void tracePrepareTransaction(final WorldView worldView, final Transaction transaction) { + tracers.forEach(t -> t.tracePrepareTransaction(worldView, transaction)); + } + + @Override + public void traceStartTransaction(final WorldView worldView, final Transaction transaction) { + tracers.forEach(t -> t.traceStartTransaction(worldView, transaction)); + } + + @Override + public void traceBeforeRewardTransaction( + final WorldView worldView, final Transaction tx, final Wei miningReward) { + tracers.forEach(t -> t.traceBeforeRewardTransaction(worldView, tx, miningReward)); + } + + @Override + public void traceEndTransaction( + final WorldView worldView, + final Transaction tx, + final boolean status, + final Bytes output, + final java.util.List logs, + final long gasUsed, + final java.util.Set selfDestructs, + final long timeNs) { + tracers.forEach( + t -> + t.traceEndTransaction( + worldView, tx, status, output, logs, gasUsed, selfDestructs, timeNs)); + } + + @Override + public void traceContextEnter(final MessageFrame frame) { + tracers.forEach(t -> t.traceContextEnter(frame)); + } + + @Override + public void traceContextReEnter(final MessageFrame frame) { + tracers.forEach(t -> t.traceContextReEnter(frame)); + } + + @Override + public void traceContextExit(final MessageFrame frame) { + tracers.forEach(t -> t.traceContextExit(frame)); + } + + @Override + public boolean isExtendedTracing() { + return tracers.stream().anyMatch(OperationTracer::isExtendedTracing); + } + + /** + * Returns {@code true} if {@code tracer} is an instance of {@code tracerType}, or if {@code + * tracer} is a {@link CompositeOperationTracer} that contains a child of that type. + * + * @param tracer the tracer to inspect + * @param tracerType the type to look for + * @param the tracer type + * @return {@code true} when a matching tracer is found + */ + public static boolean hasTracer( + final OperationTracer tracer, final Class tracerType) { + if (tracerType.isInstance(tracer)) { + return true; + } + if (tracer instanceof CompositeOperationTracer composite) { + return composite.tracers.stream().anyMatch(tracerType::isInstance); + } + return false; + } + + /** + * Returns the first child of {@code tracerType} from {@code tracer}, or the tracer itself if it + * matches. Returns {@link Optional#empty()} when no match is found. + * + * @param tracer the tracer to inspect + * @param tracerType the type to look for + * @param the tracer type + * @return an {@link Optional} containing the matched tracer, or empty + */ + public static Optional findTracer( + final OperationTracer tracer, final Class tracerType) { + if (tracerType.isInstance(tracer)) { + return Optional.of(tracerType.cast(tracer)); + } + if (tracer instanceof CompositeOperationTracer composite) { + return composite.tracers.stream() + .filter(tracerType::isInstance) + .map(tracerType::cast) + .findFirst(); + } + return Optional.empty(); + } +} diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelTransactionPreprocessing.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelTransactionPreprocessing.java index dfa575d064c..20eae035d5e 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelTransactionPreprocessing.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelTransactionPreprocessing.java @@ -24,6 +24,7 @@ import org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor; import org.hyperledger.besu.ethereum.mainnet.block.access.list.BlockAccessList; import org.hyperledger.besu.ethereum.mainnet.block.access.list.BlockAccessList.BlockAccessListBuilder; +import org.hyperledger.besu.ethereum.mainnet.systemcall.BlockProcessingContext; import org.hyperledger.besu.ethereum.trie.pathbased.common.provider.PathBasedWorldStateProvider; import org.hyperledger.besu.evm.blockhash.BlockHashLookup; @@ -56,6 +57,7 @@ public Optional run( final Wei blobGasPrice, final Optional blockAccessListBuilder, final Optional maybeBlockBal, + final BlockProcessingContext blockProcessingContext, final Optional maybeParentHeader) { if (!(protocolContext.getWorldStateArchive() instanceof PathBasedWorldStateProvider)) { return Optional.empty(); @@ -66,9 +68,11 @@ public Optional run( if (balConfiguration.isPerfectParallelizationEnabled() && maybeBlockBal.isPresent()) { parallelProcessor = new BalConcurrentTransactionProcessor( - transactionProcessor, maybeBlockBal.get(), balConfiguration); + transactionProcessor, maybeBlockBal.get(), balConfiguration, blockProcessingContext); } else { - parallelProcessor = new ParallelizedConcurrentTransactionProcessor(transactionProcessor); + parallelProcessor = + new ParallelizedConcurrentTransactionProcessor( + transactionProcessor, blockProcessingContext); } parallelProcessor.runAsyncBlock( diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelizedConcurrentTransactionProcessor.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelizedConcurrentTransactionProcessor.java index c3c48bdcdf6..6544082edb1 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelizedConcurrentTransactionProcessor.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelizedConcurrentTransactionProcessor.java @@ -1,5 +1,5 @@ /* - * Copyright contributors to Hyperledger Besu. + * Copyright contributors to Besu. * * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with * the License. You may obtain a copy of the License at @@ -19,10 +19,14 @@ import org.hyperledger.besu.ethereum.ProtocolContext; import org.hyperledger.besu.ethereum.core.BlockHeader; import org.hyperledger.besu.ethereum.core.Transaction; +import org.hyperledger.besu.ethereum.mainnet.ExecutionStats; +import org.hyperledger.besu.ethereum.mainnet.ExecutionStatsHolder; import org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor; +import org.hyperledger.besu.ethereum.mainnet.SlowBlockTracer; import org.hyperledger.besu.ethereum.mainnet.TransactionValidationParams; import org.hyperledger.besu.ethereum.mainnet.block.access.list.AccessLocationTracker; import org.hyperledger.besu.ethereum.mainnet.block.access.list.BlockAccessList.BlockAccessListBuilder; +import org.hyperledger.besu.ethereum.mainnet.systemcall.BlockProcessingContext; import org.hyperledger.besu.ethereum.processing.TransactionProcessingResult; import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.worldview.BonsaiWorldState; import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.PathBasedWorldState; @@ -53,16 +57,22 @@ public class ParallelizedConcurrentTransactionProcessor extends ParallelBlockTra private final TransactionCollisionDetector transactionCollisionDetector; + private final BlockProcessingContext blockProcessingContext; + /** * Constructs a PreloadConcurrentTransactionProcessor with a specified transaction processor. This * processor is responsible for the individual processing of transactions. * * @param transactionProcessor The transaction processor for processing individual transactions. + * @param blockProcessingContext The block processing context containing operation tracers and + * other context. */ public ParallelizedConcurrentTransactionProcessor( - final MainnetTransactionProcessor transactionProcessor) { + final MainnetTransactionProcessor transactionProcessor, + final BlockProcessingContext blockProcessingContext) { this.transactionProcessor = transactionProcessor; this.transactionCollisionDetector = new TransactionCollisionDetector(); + this.blockProcessingContext = blockProcessingContext; } @VisibleForTesting @@ -71,6 +81,17 @@ public ParallelizedConcurrentTransactionProcessor( final TransactionCollisionDetector transactionCollisionDetector) { this.transactionProcessor = transactionProcessor; this.transactionCollisionDetector = transactionCollisionDetector; + this.blockProcessingContext = null; // For testing only + } + + @VisibleForTesting + public ParallelizedConcurrentTransactionProcessor( + final MainnetTransactionProcessor transactionProcessor, + final TransactionCollisionDetector transactionCollisionDetector, + final BlockProcessingContext blockProcessingContext) { + this.transactionProcessor = transactionProcessor; + this.transactionCollisionDetector = transactionCollisionDetector; + this.blockProcessingContext = blockProcessingContext; } @Override @@ -95,6 +116,20 @@ protected ParallelizedTransactionContext runTransaction( return null; } + // Create a per-worker ExecutionStats if slow block tracing is active, so that state-layer + // metrics (account/storage reads, cache hits) from this worker thread are captured and can + // be merged into the block-level stats on successful parallel execution. + final ExecutionStats workerStats = + (blockProcessingContext != null + && BackgroundTracerFactory.hasMetricsTracer( + blockProcessingContext.getOperationTracer())) + ? new ExecutionStats() + : null; + if (workerStats != null) { + ExecutionStatsHolder.set(workerStats); + ws.setStateMetricsCollector(workerStats); + } + try { ws.disableCacheMerkleTrieLoader(); final ParallelizedTransactionContext.Builder contextBuilder = @@ -107,33 +142,47 @@ protected ParallelizedTransactionContext runTransaction( b -> BlockAccessListBuilder.createTransactionAccessLocationTracker( transactionLocation)); + + // Create the mining beneficiary tracer for parallel execution collision detection + final OperationTracer miningBeneficiaryTracer = + new OperationTracer() { + @Override + public void traceBeforeRewardTransaction( + final WorldView worldView, + final org.hyperledger.besu.datatypes.Transaction tx, + final Wei miningReward) { + /* + * This part checks if the mining beneficiary's account was accessed before increasing its balance for rewards. + * Indeed, if the transaction has interacted with the address to read or modify it, + * it means that the value is necessary for the proper execution of the transaction and will therefore be considered in collision detection. + * If this is not the case, we can ignore this address during conflict detection. + */ + if (transactionCollisionDetector + .getAddressesTouchedByTransaction( + transaction, Optional.of(roundWorldStateUpdater)) + .contains(miningBeneficiary)) { + contextBuilder.isMiningBeneficiaryTouchedPreRewardByTransaction(true); + } + contextBuilder.miningBeneficiaryReward(miningReward); + } + }; + + // Create separate background tracer for parallel execution + // This includes a copy of EVMExecutionMetricsTracer if present in the block tracer + final OperationTracer backgroundBlockTracer = + BackgroundTracerFactory.createBackgroundTracer(blockProcessingContext); + + // Compose the background tracer with the mining beneficiary tracer + final OperationTracer composedTracer = + CompositeOperationTracer.of(backgroundBlockTracer, miningBeneficiaryTracer); + final TransactionProcessingResult result = transactionProcessor.processTransaction( transactionUpdater, blockHeader, transaction.detachedCopy(), miningBeneficiary, - new OperationTracer() { - @Override - public void traceBeforeRewardTransaction( - final WorldView worldView, - final org.hyperledger.besu.datatypes.Transaction tx, - final Wei miningReward) { - /* - * This part checks if the mining beneficiary's account was accessed before increasing its balance for rewards. - * Indeed, if the transaction has interacted with the address to read or modify it, - * it means that the value is necessary for the proper execution of the transaction and will therefore be considered in collision detection. - * If this is not the case, we can ignore this address during conflict detection. - */ - if (transactionCollisionDetector - .getAddressesTouchedByTransaction( - transaction, Optional.of(roundWorldStateUpdater)) - .contains(miningBeneficiary)) { - contextBuilder.isMiningBeneficiaryTouchedPreRewardByTransaction(true); - } - contextBuilder.miningBeneficiaryReward(miningReward); - } - }, + composedTracer, blockHashLookup, TransactionValidationParams.processingBlock(), blobGasPrice, @@ -145,7 +194,9 @@ public void traceBeforeRewardTransaction( contextBuilder .transactionAccumulator(ws.getAccumulator()) - .transactionProcessingResult(result); + .transactionProcessingResult(result) + .backgroundTracer(backgroundBlockTracer) + .workerExecutionStats(workerStats); final ParallelizedTransactionContext parallelizedTransactionContext = contextBuilder.build(); if (!parallelizedTransactionContext.isMiningBeneficiaryTouchedPreRewardByTransaction()) { @@ -161,6 +212,9 @@ public void traceBeforeRewardTransaction( // no op as failing to get worldstate return null; } finally { + if (workerStats != null) { + ExecutionStatsHolder.clear(); + } if (ws != null) ws.close(); } } @@ -241,6 +295,26 @@ public Optional getProcessingResult( blockAccumulator.importStateChangesFromSource(transactionAccumulator); + // Consolidate EVM op metrics from the background tracer + parallelizedTransactionContext + .backgroundTracer() + .ifPresent( + backgroundTracer -> + BackgroundTracerFactory.consolidateTracerResults( + backgroundTracer, blockProcessingContext)); + + // Consolidate state-layer metrics (account/storage reads, cache stats) from the worker + parallelizedTransactionContext + .workerExecutionStats() + .ifPresent( + workerStats -> + BackgroundTracerFactory.findSlowBlockTracer( + blockProcessingContext != null + ? blockProcessingContext.getOperationTracer() + : OperationTracer.NO_TRACING) + .map(SlowBlockTracer::getExecutionStats) + .ifPresent(mainStats -> mainStats.mergeStateCountsFrom(workerStats))); + if (confirmedParallelizedTransactionCounter.isPresent()) { confirmedParallelizedTransactionCounter.get().inc(); transactionProcessingResult.setIsProcessedInParallel(Optional.of(Boolean.TRUE)); diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelizedTransactionContext.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelizedTransactionContext.java index aaab06ff0e4..56810f72a74 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelizedTransactionContext.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelizedTransactionContext.java @@ -15,27 +15,36 @@ package org.hyperledger.besu.ethereum.mainnet.parallelization; import org.hyperledger.besu.datatypes.Wei; +import org.hyperledger.besu.ethereum.mainnet.ExecutionStats; import org.hyperledger.besu.ethereum.processing.TransactionProcessingResult; import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.accumulator.PathBasedWorldStateUpdateAccumulator; +import org.hyperledger.besu.evm.tracing.OperationTracer; import java.util.Objects; +import java.util.Optional; public final class ParallelizedTransactionContext { private final PathBasedWorldStateUpdateAccumulator transactionAccumulator; private final TransactionProcessingResult transactionProcessingResult; private final boolean isMiningBeneficiaryTouchedPreRewardByTransaction; private final Wei miningBeneficiaryReward; + private final Optional backgroundTracer; + private final Optional workerExecutionStats; public ParallelizedTransactionContext( final PathBasedWorldStateUpdateAccumulator transactionAccumulator, final TransactionProcessingResult transactionProcessingResult, final boolean isMiningBeneficiaryTouchedPreRewardByTransaction, - final Wei miningBeneficiaryReward) { + final Wei miningBeneficiaryReward, + final Optional backgroundTracer, + final Optional workerExecutionStats) { this.transactionAccumulator = transactionAccumulator; this.transactionProcessingResult = transactionProcessingResult; this.isMiningBeneficiaryTouchedPreRewardByTransaction = isMiningBeneficiaryTouchedPreRewardByTransaction; this.miningBeneficiaryReward = miningBeneficiaryReward; + this.backgroundTracer = backgroundTracer; + this.workerExecutionStats = workerExecutionStats; } public PathBasedWorldStateUpdateAccumulator transactionAccumulator() { @@ -54,6 +63,14 @@ public Wei miningBeneficiaryReward() { return miningBeneficiaryReward; } + public Optional backgroundTracer() { + return backgroundTracer; + } + + public Optional workerExecutionStats() { + return workerExecutionStats; + } + @Override public boolean equals(final Object obj) { if (obj == this) return true; @@ -63,7 +80,9 @@ public boolean equals(final Object obj) { && Objects.equals(this.transactionProcessingResult, that.transactionProcessingResult) && this.isMiningBeneficiaryTouchedPreRewardByTransaction == that.isMiningBeneficiaryTouchedPreRewardByTransaction - && Objects.equals(this.miningBeneficiaryReward, that.miningBeneficiaryReward); + && Objects.equals(this.miningBeneficiaryReward, that.miningBeneficiaryReward) + && Objects.equals(this.backgroundTracer, that.backgroundTracer) + && Objects.equals(this.workerExecutionStats, that.workerExecutionStats); } @Override @@ -72,7 +91,9 @@ public int hashCode() { transactionAccumulator, transactionProcessingResult, isMiningBeneficiaryTouchedPreRewardByTransaction, - miningBeneficiaryReward); + miningBeneficiaryReward, + backgroundTracer, + workerExecutionStats); } @Override @@ -89,14 +110,26 @@ public String toString() { + ", " + "miningBeneficiaryReward=" + miningBeneficiaryReward + + ", " + + "backgroundTracer=" + + backgroundTracer + + ", " + + "workerExecutionStats=" + + workerExecutionStats + ']'; } + public static Builder builder() { + return new Builder(); + } + public static class Builder { private PathBasedWorldStateUpdateAccumulator transactionAccumulator; private TransactionProcessingResult transactionProcessingResult; private boolean isMiningBeneficiaryTouchedPreRewardByTransaction; private Wei miningBeneficiaryReward = Wei.ZERO; + private Optional backgroundTracer = Optional.empty(); + private Optional workerExecutionStats = Optional.empty(); public Builder transactionAccumulator( final PathBasedWorldStateUpdateAccumulator transactionAccumulator) { @@ -122,12 +155,24 @@ public Builder miningBeneficiaryReward(final Wei miningBeneficiaryReward) { return this; } + public Builder backgroundTracer(final OperationTracer backgroundTracer) { + this.backgroundTracer = Optional.ofNullable(backgroundTracer); + return this; + } + + public Builder workerExecutionStats(final ExecutionStats workerExecutionStats) { + this.workerExecutionStats = Optional.ofNullable(workerExecutionStats); + return this; + } + public ParallelizedTransactionContext build() { return new ParallelizedTransactionContext( transactionAccumulator, transactionProcessingResult, isMiningBeneficiaryTouchedPreRewardByTransaction, - miningBeneficiaryReward); + miningBeneficiaryReward, + backgroundTracer, + workerExecutionStats); } } } diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockSimulationParameter.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockSimulationParameter.java index e2d65ee62e6..09ec80ac18a 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockSimulationParameter.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockSimulationParameter.java @@ -44,6 +44,7 @@ public class BlockSimulationParameter { private final boolean traceTransfers; private final boolean returnFullTransactions; private final boolean returnTrieLog; + private final boolean collectExecutionMetrics; private final SECPSignature fakeSignature; public BlockSimulationParameter( @@ -51,7 +52,7 @@ public BlockSimulationParameter( final boolean validation, final boolean traceTransfers, final boolean returnFullTransactions) { - this(blockStateCalls, validation, traceTransfers, returnFullTransactions, false); + this(blockStateCalls, validation, traceTransfers, returnFullTransactions, false, false); } public BlockSimulationParameter( @@ -66,6 +67,24 @@ public BlockSimulationParameter( traceTransfers, returnFullTransactions, returnTrieLog, + false, + new SECPSignature(BigInteger.ZERO, BigInteger.ZERO, (byte) 0)); + } + + public BlockSimulationParameter( + final List blockStateCalls, + final boolean validation, + final boolean traceTransfers, + final boolean returnFullTransactions, + final boolean returnTrieLog, + final boolean collectExecutionMetrics) { + this( + blockStateCalls, + validation, + traceTransfers, + returnFullTransactions, + returnTrieLog, + collectExecutionMetrics, new SECPSignature(BigInteger.ZERO, BigInteger.ZERO, (byte) 0)); } @@ -76,12 +95,31 @@ public BlockSimulationParameter( final boolean returnFullTransactions, final boolean returnTrieLog, final SECPSignature fakeSignature) { + this( + blockStateCalls, + validation, + traceTransfers, + returnFullTransactions, + returnTrieLog, + false, + fakeSignature); + } + + public BlockSimulationParameter( + final List blockStateCalls, + final boolean validation, + final boolean traceTransfers, + final boolean returnFullTransactions, + final boolean returnTrieLog, + final boolean collectExecutionMetrics, + final SECPSignature fakeSignature) { checkNotNull(blockStateCalls); this.blockStateCalls = blockStateCalls; this.validation = validation; this.traceTransfers = traceTransfers; this.returnFullTransactions = returnFullTransactions; this.returnTrieLog = returnTrieLog; + this.collectExecutionMetrics = collectExecutionMetrics; this.fakeSignature = fakeSignature; } @@ -105,6 +143,10 @@ public boolean isReturnTrieLog() { return returnTrieLog; } + public boolean isCollectExecutionMetrics() { + return collectExecutionMetrics; + } + public SECPSignature getFakeSignature() { return fakeSignature; } @@ -207,6 +249,7 @@ public static class BlockSimulationParameterBuilder { private boolean traceTransfers = false; private boolean returnFullTransactions = false; private boolean returnTrieLog = false; + private boolean collectExecutionMetrics = false; private SECPSignature fakeSignature = new SECPSignature(BigInteger.ZERO, BigInteger.ZERO, (byte) 0); @@ -237,6 +280,12 @@ public BlockSimulationParameterBuilder returnTrieLog(final boolean returnTrieLog return this; } + public BlockSimulationParameterBuilder collectExecutionMetrics( + final boolean collectExecutionMetrics) { + this.collectExecutionMetrics = collectExecutionMetrics; + return this; + } + public BlockSimulationParameterBuilder fakeSignature(final SECPSignature fakeSignature) { this.fakeSignature = fakeSignature; return this; @@ -249,6 +298,7 @@ public BlockSimulationParameter build() { traceTransfers, returnFullTransactions, returnTrieLog, + collectExecutionMetrics, fakeSignature); } } diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockSimulationResult.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockSimulationResult.java index 0ef91b28cef..59cc8450182 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockSimulationResult.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockSimulationResult.java @@ -18,6 +18,7 @@ import org.hyperledger.besu.ethereum.core.LogWithMetadata; import org.hyperledger.besu.ethereum.core.TransactionReceipt; import org.hyperledger.besu.ethereum.mainnet.block.access.list.BlockAccessList; +import org.hyperledger.besu.evm.tracing.EVMExecutionMetricsTracer; import org.hyperledger.besu.plugin.data.BlockBody; import org.hyperledger.besu.plugin.data.BlockHeader; import org.hyperledger.besu.plugin.services.trielogs.TrieLog; @@ -33,6 +34,7 @@ public class BlockSimulationResult { final BlockStateCallSimulationResult blockStateCallSimulationResult; final Optional trieLog; final Optional> trieLogSerializer; + final Optional executionMetricsTracer; public BlockSimulationResult( final Block block, final BlockStateCallSimulationResult blockStateCallSimulationResult) { @@ -40,6 +42,7 @@ public BlockSimulationResult( this.blockStateCallSimulationResult = blockStateCallSimulationResult; this.trieLog = Optional.empty(); this.trieLogSerializer = Optional.empty(); + this.executionMetricsTracer = blockStateCallSimulationResult.getEVMExecutionMetricsTracer(); } public BlockSimulationResult( @@ -51,6 +54,20 @@ public BlockSimulationResult( this.blockStateCallSimulationResult = blockStateCallSimulationResult; this.trieLog = Optional.ofNullable(trieLog); this.trieLogSerializer = Optional.ofNullable(trieLogSerializer); + this.executionMetricsTracer = Optional.empty(); + } + + public BlockSimulationResult( + final Block block, + final BlockStateCallSimulationResult blockStateCallSimulationResult, + final TrieLog trieLog, + final Function trieLogSerializer, + final EVMExecutionMetricsTracer executionMetricsTracer) { + this.block = block; + this.blockStateCallSimulationResult = blockStateCallSimulationResult; + this.trieLog = Optional.ofNullable(trieLog); + this.trieLogSerializer = Optional.ofNullable(trieLogSerializer); + this.executionMetricsTracer = Optional.ofNullable(executionMetricsTracer); } public BlockHeader getBlockHeader() { @@ -110,4 +127,8 @@ public Optional getSerializedTrieLog() { public Optional getBlockAccessList() { return blockStateCallSimulationResult.getBlockAccessList(); } + + public Optional getEVMExecutionMetricsTracer() { + return executionMetricsTracer; + } } diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockSimulator.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockSimulator.java index e27c946588b..cd1a07da0aa 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockSimulator.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockSimulator.java @@ -51,6 +51,7 @@ import org.hyperledger.besu.ethereum.mainnet.block.access.list.BlockAccessListFactory; import org.hyperledger.besu.ethereum.mainnet.feemarket.BaseFeeMarket; import org.hyperledger.besu.ethereum.mainnet.feemarket.FeeMarket; +import org.hyperledger.besu.ethereum.mainnet.parallelization.CompositeOperationTracer; import org.hyperledger.besu.ethereum.mainnet.requests.RequestProcessingContext; import org.hyperledger.besu.ethereum.mainnet.requests.RequestProcessorCoordinator; import org.hyperledger.besu.ethereum.mainnet.systemcall.BlockProcessingContext; @@ -61,6 +62,7 @@ import org.hyperledger.besu.ethereum.worldstate.WorldStateArchive; import org.hyperledger.besu.evm.account.MutableAccount; import org.hyperledger.besu.evm.blockhash.BlockHashLookup; +import org.hyperledger.besu.evm.tracing.EVMExecutionMetricsTracer; import org.hyperledger.besu.evm.tracing.EthTransferLogOperationTracer; import org.hyperledger.besu.evm.tracing.OperationTracer; import org.hyperledger.besu.evm.worldstate.WorldUpdater; @@ -204,6 +206,7 @@ public List process( simulationParameter.isValidation(), simulationParameter.isTraceTransfers(), simulationParameter.isReturnTrieLog(), + simulationParameter.isCollectExecutionMetrics(), simulationParameter::getFakeSignature, blockHashCache, simulationCumulativeGasUsed, @@ -233,6 +236,7 @@ private BlockSimulationResult processBlockStateCall( final boolean shouldValidate, final boolean isTraceTransfers, final boolean returnTrieLog, + final boolean collectExecutionMetrics, final Supplier signatureSupplier, final Map blockHashCache, final long simulationCumulativeGasUsed, @@ -312,6 +316,7 @@ private BlockSimulationResult processBlockStateCall( protocolSpec, shouldValidate, isTraceTransfers, + collectExecutionMetrics, transactionProcessor, blockHashLookup, signatureSupplier, @@ -378,6 +383,7 @@ protected BlockStateCallSimulationResult processTransactions( final ProtocolSpec protocolSpec, final boolean shouldValidate, final boolean isTraceTransfers, + final boolean collectExecutionMetrics, final MainnetTransactionProcessor transactionProcessor, final BlockHashLookup blockHashLookup, final Supplier signatureSupplier, @@ -399,6 +405,9 @@ protected BlockStateCallSimulationResult processTransactions( .map(feeRecipient -> header -> feeRecipient) .orElseGet(protocolSpec::getMiningBeneficiaryCalculator); + // Collect per-transaction metrics if requested + final List transactionMetricsTracers = new ArrayList<>(); + final WorldUpdater blockUpdater = ws.updater(); for (int transactionLocation = 0; transactionLocation < blockStateCall.getCalls().size(); @@ -406,19 +415,6 @@ protected BlockStateCallSimulationResult processTransactions( final WorldUpdater transactionUpdater = blockUpdater.updater(); final CallParameter callParameter = blockStateCall.getCalls().get(transactionLocation); - // Custom tracer and EthTraceTransfers are mutually exclusive - OperationTracer finalOperationTracer = operationTracer; - if (isTraceTransfers) { - if (finalOperationTracer == OperationTracer.NO_TRACING) { - finalOperationTracer = new EthTransferLogOperationTracer(); - } else { - // this shouldn't happen, and isTraceTransfers will go away with Glamsterdam - throw new IllegalArgumentException( - "A custom tracer and traceTransfers cannot be used together." - + " Disable traceTransfers or omit the custom tracer."); - } - } - if (callParameter.getGas().isPresent() && callParameter.getGas().getAsLong() > blockStateCallSimulationResult.getRemainingGas()) { @@ -427,6 +423,29 @@ protected BlockStateCallSimulationResult processTransactions( BlockStateCallError.BLOCK_GAS_LIMIT_EXCEEDED); } + // Create separate EVMExecutionMetricsTracer for each transaction (thread-safe) + EVMExecutionMetricsTracer transactionMetricsTracer = null; + if (collectExecutionMetrics) { + transactionMetricsTracer = new EVMExecutionMetricsTracer(); + transactionMetricsTracers.add(transactionMetricsTracer); + } + + // Compose operation tracers + final OperationTracer finalOperationTracer; + if (isTraceTransfers && transactionMetricsTracer != null) { + finalOperationTracer = + CompositeOperationTracer.of( + operationTracer, new EthTransferLogOperationTracer(), transactionMetricsTracer); + } else if (isTraceTransfers) { + finalOperationTracer = + CompositeOperationTracer.of(operationTracer, new EthTransferLogOperationTracer()); + } else if (transactionMetricsTracer != null) { + finalOperationTracer = + CompositeOperationTracer.of(operationTracer, transactionMetricsTracer); + } else { + finalOperationTracer = operationTracer; + } + long gasLimit = transactionSimulator.calculateSimulationGasCap( blockHeader, @@ -489,6 +508,16 @@ protected BlockStateCallSimulationResult processTransactions( } blockAccessListBuilder.ifPresent(b -> blockStateCallSimulationResult.set(b.build())); + + // Aggregate per-transaction execution metrics if collected + if (!transactionMetricsTracers.isEmpty()) { + EVMExecutionMetricsTracer aggregatedTracer = new EVMExecutionMetricsTracer(); + for (EVMExecutionMetricsTracer transactionTracer : transactionMetricsTracers) { + aggregatedTracer.getMetrics().merge(transactionTracer.copyMetrics()); + } + blockStateCallSimulationResult.setEVMExecutionMetricsTracer(aggregatedTracer); + } + return blockStateCallSimulationResult; } @@ -540,7 +569,7 @@ private BlockSimulationResult createFinalBlock( final Optional maybeBlockAwareOperationTracer, final boolean returnTrieLog) { - List transactions = simResult.getTransactions(); + var transactions = simResult.getTransactions(); List receipts = simResult.getReceipts(); boolean isShanghaiPlus = protocolSpec.getWithdrawalsValidator() instanceof AllowedWithdrawals; @@ -593,7 +622,11 @@ private BlockSimulationResult createFinalBlock( var trieLogFactory = pathBasedArchive.getTrieLogManager().getTrieLogFactory(); var trieLog = trieLogFactory.create(pathBasedAccumulator, finalBlockHeader); return new BlockSimulationResult( - block, simResult, trieLog, log -> Bytes.wrap(trieLogFactory.serialize(log))); + block, + simResult, + trieLog, + log -> Bytes.wrap(trieLogFactory.serialize(log)), + simResult.getEVMExecutionMetricsTracer().orElse(null)); } else { // otherwise return result w/o trielog return new BlockSimulationResult(block, simResult); diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockStateCallSimulationResult.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockStateCallSimulationResult.java index ce9449bd71e..1581ccc8ef0 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockStateCallSimulationResult.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/transaction/BlockStateCallSimulationResult.java @@ -20,7 +20,9 @@ import org.hyperledger.besu.ethereum.mainnet.AbstractBlockProcessor; import org.hyperledger.besu.ethereum.mainnet.ProtocolSpec; import org.hyperledger.besu.ethereum.mainnet.block.access.list.BlockAccessList; +import org.hyperledger.besu.ethereum.mainnet.parallelization.CompositeOperationTracer; import org.hyperledger.besu.evm.gascalculator.GasCalculator; +import org.hyperledger.besu.evm.tracing.EVMExecutionMetricsTracer; import org.hyperledger.besu.evm.tracing.EthTransferLogOperationTracer; import org.hyperledger.besu.evm.tracing.OperationTracer; import org.hyperledger.besu.plugin.services.worldstate.MutableWorldState; @@ -40,6 +42,7 @@ public class BlockStateCallSimulationResult { new ArrayList<>(); private long cumulativeGasUsed = 0; private Optional blockAccessList = Optional.empty(); + private Optional executionMetricsTracer = Optional.empty(); private final AbstractBlockProcessor.TransactionReceiptFactory transactionReceiptFactory; private final long blockGasLimit; private long blobCount = 0; @@ -90,9 +93,9 @@ public void add( result.transaction().getType(), result.result(), worldState, cumulativeGasUsed); List logs = - (operationTracer instanceof EthTransferLogOperationTracer) - ? ((EthTransferLogOperationTracer) operationTracer).getLogs() - : transactionReceipt.getLogsList(); + CompositeOperationTracer.findTracer(operationTracer, EthTransferLogOperationTracer.class) + .map(EthTransferLogOperationTracer::getLogs) + .orElseGet(transactionReceipt::getLogsList); transactionSimulatorResults.add( new TransactionSimulatorResultWithMetadata( @@ -129,6 +132,14 @@ public Optional getBlockAccessList() { return blockAccessList; } + public void setEVMExecutionMetricsTracer(final EVMExecutionMetricsTracer executionMetricsTracer) { + this.executionMetricsTracer = Optional.ofNullable(executionMetricsTracer); + } + + public Optional getEVMExecutionMetricsTracer() { + return executionMetricsTracer; + } + /** Represents a single block call simulation result with metadata. */ public record TransactionSimulatorResultWithMetadata( TransactionSimulatorResult result, diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/bonsai/cache/BonsaiCachedMerkleTrieLoader.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/bonsai/cache/BonsaiCachedMerkleTrieLoader.java index 016f55fe88c..70dfb8a3724 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/bonsai/cache/BonsaiCachedMerkleTrieLoader.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/bonsai/cache/BonsaiCachedMerkleTrieLoader.java @@ -19,6 +19,8 @@ import org.hyperledger.besu.datatypes.Address; import org.hyperledger.besu.datatypes.Hash; import org.hyperledger.besu.datatypes.StorageSlotKey; +import org.hyperledger.besu.ethereum.mainnet.ExecutionStats; +import org.hyperledger.besu.ethereum.mainnet.ExecutionStatsHolder; import org.hyperledger.besu.ethereum.trie.MerkleTrie; import org.hyperledger.besu.ethereum.trie.MerkleTrieException; import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.storage.BonsaiWorldStateKeyValueStorage; @@ -140,8 +142,22 @@ public Optional getAccountStateTrieNode( if (nodeHash.equals(MerkleTrie.EMPTY_TRIE_NODE_HASH)) { return Optional.of(MerkleTrie.EMPTY_TRIE_NODE); } else { - return Optional.ofNullable(accountNodes.getIfPresent(nodeHash)) - .or(() -> worldStateKeyValueStorage.getAccountStateTrieNode(location, nodeHash)); + final Bytes cachedNode = accountNodes.getIfPresent(nodeHash); + if (cachedNode != null) { + // Track account cache hit for cross-client execution metrics + final ExecutionStats stats = ExecutionStatsHolder.get(); + if (stats != null) { + stats.incrementAccountCacheHits(); + } + return Optional.of(cachedNode); + } else { + // Track account cache miss for cross-client execution metrics + final ExecutionStats stats = ExecutionStatsHolder.get(); + if (stats != null) { + stats.incrementAccountCacheMisses(); + } + return worldStateKeyValueStorage.getAccountStateTrieNode(location, nodeHash); + } } } @@ -153,11 +169,22 @@ public Optional getAccountStorageTrieNode( if (nodeHash.equals(MerkleTrie.EMPTY_TRIE_NODE_HASH)) { return Optional.of(MerkleTrie.EMPTY_TRIE_NODE); } else { - return Optional.ofNullable(storageNodes.getIfPresent(nodeHash)) - .or( - () -> - worldStateKeyValueStorage.getAccountStorageTrieNode( - accountHash, location, nodeHash)); + final Bytes cachedNode = storageNodes.getIfPresent(nodeHash); + if (cachedNode != null) { + // Track storage cache hit for cross-client execution metrics + final ExecutionStats stats = ExecutionStatsHolder.get(); + if (stats != null) { + stats.incrementStorageCacheHits(); + } + return Optional.of(cachedNode); + } else { + // Track storage cache miss for cross-client execution metrics + final ExecutionStats stats = ExecutionStatsHolder.get(); + if (stats != null) { + stats.incrementStorageCacheMisses(); + } + return worldStateKeyValueStorage.getAccountStorageTrieNode(accountHash, location, nodeHash); + } } } } diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/PathBasedAccount.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/PathBasedAccount.java index ecc1c914670..d16de1497b3 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/PathBasedAccount.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/PathBasedAccount.java @@ -20,6 +20,7 @@ import org.hyperledger.besu.datatypes.Wei; import org.hyperledger.besu.ethereum.rlp.BytesValueRLPOutput; import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.PathBasedWorldView; +import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.StateMetricsCollector; import org.hyperledger.besu.evm.Code; import org.hyperledger.besu.evm.ModificationNotAllowedException; import org.hyperledger.besu.evm.account.MutableAccount; @@ -198,13 +199,25 @@ public Code getOrCreateCachedCode() { // cache hit, overwrite code and return it if (cachedCode != null) { code = cachedCode; + // Track code cache hit and code read for cross-client execution metrics + final StateMetricsCollector collector = context.getStateMetricsCollector(); + collector.incrementCodeCacheHits(); + collector.incrementCodeReads(); + collector.addCodeBytesRead(code.getSize()); return code; } // cache miss get the code from the disk, set it and put it in the cache + final StateMetricsCollector collector = context.getStateMetricsCollector(); + final long startNanos = System.nanoTime(); final Bytes byteCode = context.getCode(address, codeHash).orElse(Bytes.EMPTY); + collector.addStateReadTime(System.nanoTime() - startNanos); code = new Code(byteCode, codeHash); Optional.ofNullable(codeCache).ifPresent(c -> c.put(codeHash, code)); + // Track code cache miss and code read for cross-client execution metrics + collector.incrementCodeCacheMisses(); + collector.incrementCodeReads(); + collector.addCodeBytesRead(code.getSize()); return code; } diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/PathBasedWorldState.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/PathBasedWorldState.java index deabbb1ed9a..0bca9a40f54 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/PathBasedWorldState.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/PathBasedWorldState.java @@ -22,6 +22,7 @@ import org.hyperledger.besu.datatypes.Address; import org.hyperledger.besu.datatypes.Hash; import org.hyperledger.besu.datatypes.StorageSlotKey; +import org.hyperledger.besu.ethereum.mainnet.ExecutionStatsHolder; import org.hyperledger.besu.ethereum.trie.common.StateRootMismatchException; import org.hyperledger.besu.ethereum.trie.pathbased.common.StorageSubscriber; import org.hyperledger.besu.ethereum.trie.pathbased.common.cache.PathBasedCachedWorldStorageManager; @@ -66,6 +67,8 @@ public abstract class PathBasedWorldState // configuration parameters for the world state. protected WorldStateConfig worldStateConfig; + private StateMetricsCollector stateMetricsCollector = StateMetricsCollector.NOOP; + /* * Indicates whether the world state is in "frozen" mode. * @@ -105,6 +108,20 @@ public void setAccumulator(final PathBasedWorldStateUpdateAccumulator accumul this.accumulator = accumulator; } + /** + * Sets the metrics collector for state-layer operations. + * + * @param collector the collector instance + */ + public void setStateMetricsCollector(final StateMetricsCollector collector) { + this.stateMetricsCollector = collector != null ? collector : StateMetricsCollector.NOOP; + } + + @Override + public StateMetricsCollector getStateMetricsCollector() { + return stateMetricsCollector; + } + /** * Returns the world state block hash of this world state * @@ -183,11 +200,17 @@ public void persist(final BlockHeader blockHeader, final StateRootCommitter comm worldStateKeyValueStorage.updater(); Runnable saveTrieLog = () -> {}; Runnable cacheWorldState = () -> {}; + final var executionStats = ExecutionStatsHolder.get(); try { + // Track state hash time (Merkle trie rehashing) + final long stateHashStartNanos = executionStats != null ? System.nanoTime() : 0; final Hash calculatedRootHash = committer.computeRoot( buildStateRootSupplier(stateUpdater, blockHeader), this, stateUpdater, blockHeader); + if (executionStats != null) { + executionStats.addStateHashTime(System.nanoTime() - stateHashStartNanos); + } if (blockHeader != null) { verifyWorldStateRoot(calculatedRootHash, blockHeader); @@ -227,6 +250,9 @@ public void persist(final BlockHeader blockHeader, final StateRootCommitter comm success = true; } finally { if (success) { + // Track commit time (writing state to DB) + final long commitStartNanos = executionStats != null ? System.nanoTime() : 0; + // commit the trielog transaction ahead of the state, in case of an abnormal shutdown: saveTrieLog.run(); // commit only the composed worldstate, as trielog transaction is already complete: @@ -235,6 +261,12 @@ public void persist(final BlockHeader blockHeader, final StateRootCommitter comm // optionally save the committed worldstate state in the cache cacheWorldState.run(); } + + if (executionStats != null) { + executionStats.addCommitTime(System.nanoTime() - commitStartNanos); + } + + accumulator.collectFinalWriteMetrics(stateMetricsCollector); accumulator.reset(); } else { stateUpdater.rollback(); diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/PathBasedWorldView.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/PathBasedWorldView.java index d5bd956c19b..e4f12238f3b 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/PathBasedWorldView.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/PathBasedWorldView.java @@ -63,4 +63,13 @@ static Bytes encodeTrieValue(final Bytes bytes) { WorldUpdater updater(); CodeCache codeCache(); + + /** + * Returns the metrics collector for state-layer operations. + * + * @return the {@link StateMetricsCollector}, defaulting to {@link StateMetricsCollector#NOOP} + */ + default StateMetricsCollector getStateMetricsCollector() { + return StateMetricsCollector.NOOP; + } } diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/StateMetricsCollector.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/StateMetricsCollector.java new file mode 100644 index 00000000000..042e28daf73 --- /dev/null +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/StateMetricsCollector.java @@ -0,0 +1,139 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.ethereum.trie.pathbased.common.worldview; + +/** + * Interface for collecting state-layer metrics during block execution. + * + *

Implementations are threaded through the world state object graph (PathBasedWorldState → + * accumulator → accounts) so that state operations can record metrics without relying on + * ThreadLocal statics. + */ +public interface StateMetricsCollector { + + /** Increments the account read counter. */ + void incrementAccountReads(); + + /** Increments the storage read counter. */ + void incrementStorageReads(); + + /** + * Sets the final unique account write count for the block. + * + * @param count the number of unique accounts written + */ + void setAccountWrites(int count); + + /** + * Sets the final unique storage slot write count for the block. + * + * @param count the number of unique storage slots written + */ + void setStorageWrites(int count); + + /** Increments the account destruct counter. */ + void incrementAccountDestructs(); + + /** + * Adds to the storage slots deleted counter. + * + * @param count the number of storage slots deleted + */ + void addStorageDeletes(int count); + + /** Increments the code read counter. */ + void incrementCodeReads(); + + /** + * Adds bytes read for code. + * + * @param bytes the number of bytes read + */ + void addCodeBytesRead(long bytes); + + /** Increments the code cache hit counter. */ + void incrementCodeCacheHits(); + + /** Increments the code cache miss counter. */ + void incrementCodeCacheMisses(); + + /** Increments the account cache hit counter. */ + void incrementAccountCacheHits(); + + /** Increments the account cache miss counter. */ + void incrementAccountCacheMisses(); + + /** Increments the storage cache hit counter. */ + void incrementStorageCacheHits(); + + /** Increments the storage cache miss counter. */ + void incrementStorageCacheMisses(); + + /** + * Adds elapsed time for a state read operation. + * + * @param nanos elapsed time in nanoseconds + */ + void addStateReadTime(long nanos); + + /** A no-op implementation that discards all metrics. */ + StateMetricsCollector NOOP = + new StateMetricsCollector() { + @Override + public void incrementAccountReads() {} + + @Override + public void incrementStorageReads() {} + + @Override + public void setAccountWrites(final int count) {} + + @Override + public void setStorageWrites(final int count) {} + + @Override + public void incrementAccountDestructs() {} + + @Override + public void addStorageDeletes(final int count) {} + + @Override + public void incrementCodeReads() {} + + @Override + public void addCodeBytesRead(final long bytes) {} + + @Override + public void incrementCodeCacheHits() {} + + @Override + public void incrementCodeCacheMisses() {} + + @Override + public void incrementAccountCacheHits() {} + + @Override + public void incrementAccountCacheMisses() {} + + @Override + public void incrementStorageCacheHits() {} + + @Override + public void incrementStorageCacheMisses() {} + + @Override + public void addStateReadTime(final long nanos) {} + }; +} diff --git a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/accumulator/PathBasedWorldStateUpdateAccumulator.java b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/accumulator/PathBasedWorldStateUpdateAccumulator.java index 6ff962e6f01..01a8e89ba7d 100644 --- a/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/accumulator/PathBasedWorldStateUpdateAccumulator.java +++ b/ethereum/core/src/main/java/org/hyperledger/besu/ethereum/trie/pathbased/common/worldview/accumulator/PathBasedWorldStateUpdateAccumulator.java @@ -26,6 +26,7 @@ import org.hyperledger.besu.ethereum.trie.pathbased.common.storage.PathBasedWorldStateKeyValueStorage; import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.PathBasedWorldState; import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.PathBasedWorldView; +import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.StateMetricsCollector; import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.accumulator.preload.AccountConsumingMap; import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.accumulator.preload.Consumer; import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.accumulator.preload.StorageConsumingMap; @@ -305,6 +306,12 @@ protected ACCOUNT loadAccount( final PathBasedWorldStateUpdateAccumulator worldStateUpdateAccumulator = (PathBasedWorldStateUpdateAccumulator) wrappedWorldView(); account = worldStateUpdateAccumulator.loadAccount(address, accountFunction); + } else if (metricsEnabled()) { + getStateMetricsCollector().incrementAccountCacheMisses(); + final long startNanos = System.nanoTime(); + account = wrappedWorldView().get(address); + getStateMetricsCollector().addStateReadTime(System.nanoTime() - startNanos); + getStateMetricsCollector().incrementAccountReads(); } else { account = wrappedWorldView().get(address); } @@ -319,6 +326,9 @@ protected ACCOUNT loadAccount( return null; } } else { + if (metricsEnabled()) { + getStateMetricsCollector().incrementAccountCacheHits(); + } return accountFunction.apply(pathBasedValue); } } catch (MerkleTrieException e) { @@ -400,13 +410,17 @@ public void commit() { } }); } + if (metricsEnabled()) { + getStateMetricsCollector().incrementAccountDestructs(); + getStateMetricsCollector().addStorageDeletes(deletedStorageUpdates.size()); + } if (deletedStorageUpdates.isEmpty()) { storageToUpdate.remove(deletedAddress); } accountValue.setUpdated(null); } - getUpdatedAccounts().parallelStream() + getUpdatedAccounts().stream() .forEach( tracked -> { final Address updatedAddress = tracked.getAddress(); @@ -463,10 +477,12 @@ public void commit() { if (tracked.getStorageWasCleared()) { storageToClear.add(updatedAddress); + if (metricsEnabled() && !pendingStorageUpdates.isEmpty()) { + getStateMetricsCollector().addStorageDeletes(pendingStorageUpdates.size()); + } pendingStorageUpdates.clear(); } - // parallel stream here may cause database corruption updatedAccount .getUpdatedStorage() .entrySet() @@ -534,14 +550,29 @@ public Optional getStorageValueByStorageSlotKey( if (localAccountStorage != null) { final PathBasedValue value = localAccountStorage.get(storageSlotKey); if (value != null) { + if (metricsEnabled()) { + getStateMetricsCollector().incrementStorageCacheHits(); + } return Optional.ofNullable(value.getUpdated()); } } try { - final Optional valueUInt = - (wrappedWorldView() instanceof PathBasedWorldState worldState) - ? worldState.getStorageValueByStorageSlotKey(address, storageSlotKey) - : wrappedWorldView().getStorageValueByStorageSlotKey(address, storageSlotKey); + final Optional valueUInt; + if (metricsEnabled()) { + getStateMetricsCollector().incrementStorageCacheMisses(); + final long startNanos = System.nanoTime(); + valueUInt = + (wrappedWorldView() instanceof PathBasedWorldState worldState) + ? worldState.getStorageValueByStorageSlotKey(address, storageSlotKey) + : wrappedWorldView().getStorageValueByStorageSlotKey(address, storageSlotKey); + getStateMetricsCollector().addStateReadTime(System.nanoTime() - startNanos); + getStateMetricsCollector().incrementStorageReads(); + } else { + valueUInt = + (wrappedWorldView() instanceof PathBasedWorldState worldState) + ? worldState.getStorageValueByStorageSlotKey(address, storageSlotKey) + : wrappedWorldView().getStorageValueByStorageSlotKey(address, storageSlotKey); + } storageToUpdate .computeIfAbsent( address, @@ -615,6 +646,35 @@ public void markTransactionBoundary() { getDeletedAccounts().clear(); } + /** + * Counts unique accounts and storage slots written during block execution and records them in the + * provided metrics collector. + * + *

Called once per block just before {@code worldState.persist()} so that each modified slot + * and account is counted exactly once, regardless of how many transactions wrote to it. Counting + * here rather than in {@link #commit()} avoids the N-times overcounting that would otherwise + * occur when the same slot is updated across multiple transactions. + * + * @param collector the metrics collector to record into + */ + public void collectFinalWriteMetrics(final StateMetricsCollector collector) { + if (collector == StateMetricsCollector.NOOP) { + return; + } + // Count unique accounts that were written (updated value is non-null = not just deleted) + final int accountWrites = + (int) accountsToUpdate.values().stream().filter(v -> v.getUpdated() != null).count(); + collector.setAccountWrites(accountWrites); + + // Count unique storage slots that were written across all accounts + final int storageWrites = + storageToUpdate.values().stream() + .mapToInt( + slots -> (int) slots.values().stream().filter(v -> v.getUpdated() != null).count()) + .sum(); + collector.setStorageWrites(storageWrites); + } + @Override public boolean isModifyingHeadWorldState() { return true; @@ -625,6 +685,15 @@ public PathBasedWorldStateKeyValueStorage getWorldStateStorage() { return wrappedWorldView().getWorldStateStorage(); } + @Override + public StateMetricsCollector getStateMetricsCollector() { + return wrappedWorldView().getStateMetricsCollector(); + } + + private boolean metricsEnabled() { + return getStateMetricsCollector() != StateMetricsCollector.NOOP; + } + public void rollForward(final TrieLog layer) { layer .getAccountChanges() diff --git a/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/ExecutionStatsIntegrationTest.java b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/ExecutionStatsIntegrationTest.java new file mode 100644 index 00000000000..62d7d68a163 --- /dev/null +++ b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/ExecutionStatsIntegrationTest.java @@ -0,0 +1,978 @@ +/* + * Copyright contributors to Hyperledger Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.ethereum.mainnet; + +import static org.assertj.core.api.Assertions.assertThat; + +import org.hyperledger.besu.config.GenesisConfig; +import org.hyperledger.besu.crypto.KeyPair; +import org.hyperledger.besu.crypto.SECPPrivateKey; +import org.hyperledger.besu.crypto.SignatureAlgorithm; +import org.hyperledger.besu.crypto.SignatureAlgorithmFactory; +import org.hyperledger.besu.datatypes.Address; +import org.hyperledger.besu.datatypes.TransactionType; +import org.hyperledger.besu.datatypes.Wei; +import org.hyperledger.besu.ethereum.chain.DefaultBlockchain; +import org.hyperledger.besu.ethereum.core.BlockHeader; +import org.hyperledger.besu.ethereum.core.BlockHeaderTestFixture; +import org.hyperledger.besu.ethereum.core.ExecutionContextTestFixture; +import org.hyperledger.besu.ethereum.core.Transaction; +import org.hyperledger.besu.ethereum.processing.TransactionProcessingResult; +import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.PathBasedWorldState; +import org.hyperledger.besu.ethereum.worldstate.WorldStateArchive; +import org.hyperledger.besu.evm.blockhash.BlockHashLookup; +import org.hyperledger.besu.plugin.services.storage.DataStorageFormat; +import org.hyperledger.besu.plugin.services.worldstate.MutableWorldState; + +import java.math.BigInteger; +import java.util.Arrays; +import java.util.List; +import java.util.Optional; + +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; +import org.apache.tuweni.bytes.Bytes; +import org.apache.tuweni.bytes.Bytes32; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.web3j.abi.FunctionEncoder; +import org.web3j.abi.datatypes.Function; +import org.web3j.abi.datatypes.Type; +import org.web3j.abi.datatypes.generated.Uint256; + +/** + * End-to-end integration tests for ExecutionStats metrics. + * + *

These tests verify that real transaction processing correctly triggers ExecutionStats metrics. + * Each test targets specific metrics and validates they are updated through the full pipeline: + * Transaction → EVM → World State → ExecutionStats. + * + *

Metrics Coverage Matrix (code_r = code reads when contract code is loaded for execution): + * + * 

+ * | Test                              | accounts_r | storage_r | code_r | accounts_w | storage_w | code_w | sload | sstore | calls |
+ * |-----------------------------------|------------|-----------|--------|------------|-----------|--------|-------|--------|-------|
+ * | shouldTrackMetricsForEthTransfer  | -          | -         | -      | ✓          | -         | -      | -     | -      | -     |
+ * | shouldTrackMetricsForContractDeploy| -         | -         | -      | ✓          | ✓         | ✓      | -     | ✓      | -     |
+ * | shouldTrackMetricsForStorageWrite | -          | -         | ✓      | -          | ✓         | -      | -     | ✓      | -     |
+ * | shouldTrackMetricsForStorageRead  | -          | ✓         | ✓      | -          | -         | -      | ✓     | -      | -     |
+ * | shouldTrackMetricsForBalanceCheck | ✓          | -         | ✓      | -          | -         | -      | -     | -      | -     |
+ * | shouldTrackMetricsForContractCall | ✓          | -         | ✓      | ✓          | -         | -      | -     | -      | ✓     |
+ *
+ */ +class ExecutionStatsIntegrationTest { + + // Use address 0x20 to avoid all precompiles (0x01-0x13 including BLS precompiles) + private static final String RECIPIENT_EOA = "0x0000000000000000000000000000000000000020"; + private static final Address CONTRACT_ADDRESS = + Address.fromHexStringStrict("0x00000000000000000000000000000000000fffff"); + + // Genesis account 1: 0x627306090abab3a6e1400e9345bc60c78a8bef57 + private static final KeyPair GENESIS_ACCOUNT_1_KEYPAIR = + generateKeyPair("c87509a1c067bbde78beb793e6fa76530b6382a4c0241e5e4a9ec0a0f44dc0d3"); + + // Genesis account 2: 0x7f2d653f56ea8de6ffa554c7a0cd4e03af79f3eb + private static final KeyPair GENESIS_ACCOUNT_2_KEYPAIR = + generateKeyPair("fc5141e75bf622179f8eedada7fab3e2e6b3e3da8eb9df4f46d84df22df7430e"); + + private static final String GENESIS_RESOURCE = + "/org/hyperledger/besu/ethereum/mainnet/genesis-bp-it.json"; + + private WorldStateArchive worldStateArchive; + private DefaultBlockchain blockchain; + private MainnetTransactionProcessor transactionProcessor; + private ExecutionStats stats; + private BlockHeader blockHeader; + private MutableWorldState worldState; + private org.hyperledger.besu.evm.tracing.EVMExecutionMetricsTracer evmMetricsTracer; + + @BeforeEach + void setUp() { + final ExecutionContextTestFixture contextTestFixture = + ExecutionContextTestFixture.builder(GenesisConfig.fromResource(GENESIS_RESOURCE)) + .dataStorageFormat(DataStorageFormat.BONSAI) + .build(); + + worldStateArchive = contextTestFixture.getStateArchive(); + blockchain = (DefaultBlockchain) contextTestFixture.getBlockchain(); + + final ProtocolSchedule protocolSchedule = contextTestFixture.getProtocolSchedule(); + final var protocolSpec = + protocolSchedule.getByBlockHeader(new BlockHeaderTestFixture().number(0L).buildHeader()); + + transactionProcessor = protocolSpec.getTransactionProcessor(); + + blockHeader = + new BlockHeaderTestFixture() + .number(1L) + .parentHash(blockchain.getChainHeadHeader().getHash()) + .gasLimit(30_000_000L) + .baseFeePerGas(Wei.of(5)) + .buildHeader(); + + worldState = worldStateArchive.getWorldState(); + + // Initialize stats tracking before each test + stats = new ExecutionStats(); + stats.startExecution(); + ExecutionStatsHolder.set(stats); + evmMetricsTracer = new org.hyperledger.besu.evm.tracing.EVMExecutionMetricsTracer(); + + // Set the collector on the world state so state-layer metrics flow through + if (worldState instanceof PathBasedWorldState pathBasedWorldState) { + pathBasedWorldState.setStateMetricsCollector(stats); + } + } + + @AfterEach + void tearDown() { + ExecutionStatsHolder.clear(); + } + + // ======================================================================== + // Test 1: ETH Transfer - Triggers account writes + // ======================================================================== + + @Test + void shouldTrackMetricsForEthTransfer() { + // Given: An ETH transfer transaction + Transaction transferTx = + Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) + .maxPriorityFeePerGas(Wei.of(0)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(50_000L) + .to(Address.fromHexStringStrict(RECIPIENT_EOA)) + .value(Wei.of(1_000_000_000_000_000_000L)) // 1 ETH + .payload(Bytes.EMPTY) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + + // When: Processing the transaction + processTransaction(transferTx); + collectStats(); + + // Then: Account writes should be tracked (sender balance/nonce + recipient balance) + assertThat(stats.getAccountWrites()) + .as("ETH transfer should write to sender and recipient accounts") + .isGreaterThanOrEqualTo(2); + + // ETH transfers don't involve EVM opcodes + assertThat(stats.getSloadCount()).as("ETH transfer has no SLOAD").isEqualTo(0); + assertThat(stats.getSstoreCount()).as("ETH transfer has no SSTORE").isEqualTo(0); + assertThat(stats.getCallCount()).as("ETH transfer has no CALL").isEqualTo(0); + assertThat(stats.getCreateCount()).as("ETH transfer has no CREATE").isEqualTo(0); + assertThat(stats.getCodeReads()).as("ETH transfer has no code reads").isEqualTo(0); + + // Timing should be captured + assertThat(stats.getExecutionTimeNanos()) + .as("Execution time should be recorded") + .isGreaterThan(0); + + printStats("ETH Transfer"); + } + + // ======================================================================== + // Test 2: Contract Deployment - Triggers code writes, sstore, creates + // ======================================================================== + + @Test + void shouldTrackMetricsForContractDeployment() { + // Given: Contract deployment with init code that stores a value + // Init code: PUSH1 42 PUSH1 0 SSTORE (stores 42 at slot 0) + // PUSH1 01 PUSH1 0 RETURN (returns 1 byte of runtime code) + Bytes initCode = Bytes.fromHexString("0x602a6000556001600060003960016000f3"); + + Transaction deployTx = + Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) + .maxPriorityFeePerGas(Wei.of(0)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(3000000L) + .to(null) // null = contract creation + .value(Wei.ZERO) + .payload(initCode) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + + // When: Processing the transaction + processTransaction(deployTx); + collectStats(); + + // Then: Contract deployment metrics should be tracked + assertThat(stats.getSstoreCount()) + .as("Contract init code should execute SSTORE") + .isGreaterThanOrEqualTo(1); + + assertThat(stats.getStorageWrites()) + .as("Contract init code should write to storage") + .isGreaterThanOrEqualTo(1); + + assertThat(stats.getAccountWrites()) + .as("Contract deployment should update accounts (sender + new contract)") + .isGreaterThanOrEqualTo(2); + + // TODO: Code writes and code bytes written tracking not yet instrumented in state layer + // These metrics (geth: CodeUpdated, CodeBytesWrite) will be added in a follow-up + + printStats("Contract Deployment"); + } + + // ======================================================================== + // Test 3: Storage Write (SSTORE) - Triggers sstore, storage writes + // ======================================================================== + + @Test + void shouldTrackMetricsForStorageWrite() { + // Given: A transaction that calls setSlot1(42) on the contract + Transaction setSlotTx = createContractCallTransaction("setSlot1", Optional.of(42)); + + // When: Processing the transaction + processTransaction(setSlotTx); + collectStats(); + + // Then: SSTORE and storage writes should be tracked + assertThat(stats.getSstoreCount()) + .as("setSlot1 should execute SSTORE") + .isGreaterThanOrEqualTo(1); + + assertThat(stats.getStorageWrites()) + .as("setSlot1 should write to storage") + .isGreaterThanOrEqualTo(1); + + // Code reads are tracked when contract code is loaded for execution + assertThat(stats.getCodeReads()) + .as("Calling contract should read code for execution") + .isGreaterThanOrEqualTo(1); + + assertThat(stats.getCodeBytesRead()) + .as("Contract code bytes should be tracked") + .isGreaterThan(0); + + printStats("Storage Write (SSTORE)"); + } + + // ======================================================================== + // Test 4: Storage Read (SLOAD) - Triggers sload, storage reads + // ======================================================================== + + @Test + void shouldTrackMetricsForStorageRead() { + // Given: A transaction that calls getSlot1() on the contract (view function with SLOAD) + Transaction getSlotTx = createContractCallTransaction("getSlot1", Optional.empty()); + + // When: Processing the transaction + processTransaction(getSlotTx); + collectStats(); + + // Then: SLOAD should be tracked via the EVM tracer + assertThat(stats.getSloadCount()).as("getSlot1 should execute SLOAD").isGreaterThanOrEqualTo(1); + + // Storage reads should be tracked when SLOAD fetches from state (cache miss) + assertThat(stats.getStorageReads()) + .as("getSlot1 should read from storage state") + .isGreaterThanOrEqualTo(1); + + // Code reads are tracked when contract code is loaded for execution + assertThat(stats.getCodeReads()) + .as("Calling contract should read code for execution") + .isGreaterThanOrEqualTo(1); + + printStats("Storage Read (SLOAD)"); + } + + // ======================================================================== + // Test 5: Balance Check (BALANCE opcode) - Triggers account reads + // ======================================================================== + + @Test + void shouldTrackMetricsForBalanceCheck() { + // Given: A transaction that calls getBalance(address) on the contract + // This uses the BALANCE opcode internally + Address targetAddress = Address.fromHexStringStrict(RECIPIENT_EOA); + Transaction balanceCheckTx = createGetBalanceTransaction(targetAddress); + + // When: Processing the transaction + processTransaction(balanceCheckTx); + collectStats(); + + // Account reads should be tracked (BALANCE opcode triggers account load from state) + assertThat(stats.getAccountReads()) + .as("BALANCE opcode should trigger account reads from state") + .isGreaterThanOrEqualTo(1); + + // Code reads are tracked when contract code is loaded for execution + assertThat(stats.getCodeReads()) + .as("Calling contract should read code for execution") + .isGreaterThanOrEqualTo(1); + + printStats("Balance Check (BALANCE opcode)"); + } + + // ======================================================================== + // Test 6: Contract Call (CALL opcode) - Triggers calls, account reads + // ======================================================================== + + @Test + void shouldTrackMetricsForContractCall() { + // Given: A transaction that calls transferTo(address, amount) which uses CALL internally + // First, send some ETH to the contract so it has balance to transfer + // Gas limit must exceed 21000 because CONTRACT_ADDRESS has code (receive/fallback executes) + Transaction fundContractTx = + Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) + .maxPriorityFeePerGas(Wei.of(0)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(100_000L) + .to(CONTRACT_ADDRESS) + .value(Wei.of(1_000_000_000_000_000_000L)) // 1 ETH + .payload(Bytes.EMPTY) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + + processTransaction(fundContractTx); + + // Reset stats for the actual test + stats.reset(); + stats.startExecution(); + evmMetricsTracer.reset(); + + // Now call transferTo which uses CALL internally + Address recipient = Address.fromHexStringStrict(RECIPIENT_EOA); + Transaction transferToTx = createTransferToTransaction(recipient, 1000); + + // When: Processing the transaction + processTransaction(transferToTx); + collectStats(); + + // Then: Contract execution metrics should be tracked + // Account reads should be tracked (CALL target address lookup triggers state read) + assertThat(stats.getAccountReads()) + .as("Contract CALL should trigger account reads from state") + .isGreaterThanOrEqualTo(1); + + // Note: Code reads are NOT expected here because the contract code was already + // loaded during the funding transaction above. This is correct geth-parity behavior: + // code is only tracked as a "read" when it crosses the DB/cache boundary for the first + // time in a block. The code remains cached on the account object between transactions. + // This matches geth's stateObject.Code() which only increments CodeLoaded when loading + // from the code reader, not when returning from the cached code field. + + printStats("Contract Call (CALL opcode)"); + } + + // ======================================================================== + // Test 7: Cache Statistics JSON Structure - Verifies cache stats in output + // ======================================================================== + + @Test + void shouldIncludeCacheStatisticsInJsonOutput() throws Exception { + // Given: A transaction that exercises state access + Transaction callTx = createContractCallTransaction("getSlot1", Optional.empty()); + + // When: Processing the transaction + processTransaction(callTx); + collectStats(); + + // Manually set some cache stats to verify JSON serialization works correctly + // (In production, these would be set by the actual code loading paths) + stats.setCacheStats(5, 3, 10, 2, 8, 1); + stats.incrementTransactionCount(); + stats.addGasUsed(100000); + + String json = stats.toSlowBlockJson(1L, "0xcache-test"); + ObjectMapper mapper = new ObjectMapper(); + JsonNode root = mapper.readTree(json); + + // Then: Cache section should exist with all required fields per geth parity spec + JsonNode cacheNode = root.path("cache"); + assertThat(cacheNode.isMissingNode()).as("JSON should contain 'cache' section").isFalse(); + + // Account cache stats + assertThat(cacheNode.path("account").path("hits").asInt()) + .as("Account cache hits should be serialized") + .isEqualTo(5); + assertThat(cacheNode.path("account").path("misses").asInt()) + .as("Account cache misses should be serialized") + .isEqualTo(3); + assertThat(cacheNode.path("account").path("hit_rate").asDouble()) + .as("Account cache hit_rate should be calculated (5/(5+3) = 62.5%)") + .isGreaterThan(60.0) + .isLessThan(63.0); + + // Storage cache stats + assertThat(cacheNode.path("storage").path("hits").asInt()) + .as("Storage cache hits should be serialized") + .isEqualTo(10); + assertThat(cacheNode.path("storage").path("misses").asInt()) + .as("Storage cache misses should be serialized") + .isEqualTo(2); + assertThat(cacheNode.path("storage").path("hit_rate").asDouble()) + .as("Storage cache hit_rate should be calculated (10/(10+2) = 83.33%)") + .isGreaterThan(83.0) + .isLessThan(84.0); + + // Code cache stats + assertThat(cacheNode.path("code").path("hits").asInt()) + .as("Code cache hits should be serialized") + .isEqualTo(8); + assertThat(cacheNode.path("code").path("misses").asInt()) + .as("Code cache misses should be serialized") + .isEqualTo(1); + assertThat(cacheNode.path("code").path("hit_rate").asDouble()) + .as("Code cache hit_rate should be calculated (8/(8+1) = 88.89%)") + .isGreaterThan(88.0) + .isLessThan(89.0); + + System.out.println("\n=== Cache Statistics JSON Test ==="); + System.out.println( + "JSON cache section: " + + mapper.writerWithDefaultPrettyPrinter().writeValueAsString(cacheNode)); + } + + // ======================================================================== + // Test 8: CREATE2 Operation Tracking - Verifies CREATE opcode counting + // ======================================================================== + + @Test + void shouldTrackCreate2Operations() { + // Given: Deploy a factory contract that uses CREATE2 + // Factory bytecode that deploys a minimal contract using CREATE2: + // PUSH32 salt, PUSH1 size, PUSH1 offset, PUSH1 value, CREATE2 + // For simplicity, we'll deploy a contract with CREATE opcode in init code + // Init code: PUSH1 size PUSH1 offset PUSH1 value CREATE (creates a minimal contract) + // + // Actually, let's use a simpler approach: deploy a contract whose init code + // itself uses CREATE to spawn a child contract. + // + // Minimal init code that CREATEs a child: + // PUSH1 0x01 (size 1) + // PUSH1 0x00 (offset 0) + // PUSH1 0x00 (value 0) + // CREATE + // Then return the deployed contract + // + // Actually even simpler - just verify the CREATE count from a basic deployment + // since CONTRACT_ADDRESS already exists with code that we can use. + + // Use a contract deployment which triggers CREATE tracking + Bytes initCodeWithCreate = + Bytes.fromHexString( + // This init code creates a child contract + // PUSH1 0 (size for child - empty runtime) + // PUSH1 0 (offset) + // PUSH1 0 (value) + // CREATE + // POP (discard result) + // PUSH1 0 (return size) + // PUSH1 0 (return offset) + // RETURN + "0x6000600060006000f0506000600060003960006000f3"); + + Transaction deployWithCreate = + Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) + .maxPriorityFeePerGas(Wei.of(0)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(3000000L) + .to(null) // Contract creation + .value(Wei.ZERO) + .payload(initCodeWithCreate) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + + // When: Processing the transaction + processTransaction(deployWithCreate); + collectStats(); + + // Then: CREATE operations should be tracked + // Note: The init code itself runs CREATE, so we expect createCount >= 1 + assertThat(stats.getCreateCount()) + .as("Init code with CREATE opcode should track CREATE operations") + .isGreaterThanOrEqualTo(1); + + printStats("CREATE Operation Tracking"); + } + + // ======================================================================== + // Test 9: EIP-7702 Delegation Tracking - Verifies delegation counters + // ======================================================================== + + @Test + void shouldTrackEip7702DelegationMetrics() throws Exception { + // Given: We'll simulate EIP-7702 delegation tracking via direct stats calls + // since creating a fully signed 7702 transaction is complex. + // This test verifies that the delegation counters are properly collected + // and serialized in the slow block JSON output. + + // Simulate some EIP-7702 delegations being set and cleared + // (In production, this happens via CodeDelegationService.processCodeDelegation()) + stats.incrementEip7702DelegationsSet(); + stats.incrementEip7702DelegationsSet(); + stats.incrementEip7702DelegationsSet(); + stats.incrementEip7702DelegationsCleared(); + + // Process a simple transaction to have realistic execution context + Transaction transferTx = + Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) + .maxPriorityFeePerGas(Wei.of(0)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(50_000L) + .to(Address.fromHexStringStrict(RECIPIENT_EOA)) + .value(Wei.of(1_000_000_000L)) + .payload(Bytes.EMPTY) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + + processTransaction(transferTx); + collectStats(); + + // Then: EIP-7702 delegation counters should be collected + assertThat(stats.getEip7702DelegationsSet()) + .as("EIP-7702 delegations set should be tracked (geth parity)") + .isEqualTo(3); + + assertThat(stats.getEip7702DelegationsCleared()) + .as("EIP-7702 delegations cleared should be tracked (geth parity)") + .isEqualTo(1); + + // Verify JSON output includes EIP-7702 fields + stats.incrementTransactionCount(); + stats.addGasUsed(21000); + String json = stats.toSlowBlockJson(1L, "0xeip7702-test"); + ObjectMapper mapper = new ObjectMapper(); + JsonNode root = mapper.readTree(json); + + assertThat(root.path("state_writes").path("eip7702_delegations_set").asInt()) + .as("JSON should include eip7702_delegations_set") + .isEqualTo(3); + + assertThat(root.path("state_writes").path("eip7702_delegations_cleared").asInt()) + .as("JSON should include eip7702_delegations_cleared") + .isEqualTo(1); + + System.out.println("\n=== EIP-7702 Delegation Tracking Test ==="); + System.out.println("Delegations set: " + stats.getEip7702DelegationsSet()); + System.out.println("Delegations cleared: " + stats.getEip7702DelegationsCleared()); + System.out.println( + "JSON state_writes section: " + + mapper + .writerWithDefaultPrettyPrinter() + .writeValueAsString(root.path("state_writes"))); + } + + // ======================================================================== + // Test 10: JSON Field Validation - All 38 required fields exist + // ======================================================================== + + @Test + void shouldValidateAllJsonFieldsExist() throws Exception { + // Given: A transaction to populate metrics + Transaction transferTx = + Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) + .maxPriorityFeePerGas(Wei.of(0)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(50_000L) + .to(Address.fromHexStringStrict(RECIPIENT_EOA)) + .value(Wei.of(1_000_000_000_000_000_000L)) + .payload(Bytes.EMPTY) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + + processTransaction(transferTx); + collectStats(); + stats.incrementTransactionCount(); + stats.addGasUsed(21000); + + // When: Generating JSON output + String json = stats.toSlowBlockJson(1L, "0xtest"); + ObjectMapper mapper = new ObjectMapper(); + JsonNode root = mapper.readTree(json); + + // Then: All required fields should exist per cross-client execution metrics spec + String[] requiredPaths = { + // Top level + "level", + "msg", + // Block section + "block/number", + "block/hash", + "block/gas_used", + "block/tx_count", + // Timing section + "timing/execution_ms", + "timing/state_read_ms", + "timing/state_hash_ms", + "timing/commit_ms", + "timing/total_ms", + // Throughput section + "throughput/mgas_per_sec", + // State reads section + "state_reads/accounts", + "state_reads/storage_slots", + "state_reads/code", + "state_reads/code_bytes", + // State writes section + "state_writes/accounts", + "state_writes/storage_slots", + "state_writes/code", + "state_writes/code_bytes", + "state_writes/eip7702_delegations_set", + "state_writes/eip7702_delegations_cleared", + // Cache section + "cache/account/hits", + "cache/account/misses", + "cache/account/hit_rate", + "cache/storage/hits", + "cache/storage/misses", + "cache/storage/hit_rate", + "cache/code/hits", + "cache/code/misses", + "cache/code/hit_rate", + // Unique section + "unique/accounts", + "unique/storage_slots", + "unique/contracts", + // EVM section + "evm/sload", + "evm/sstore", + "evm/calls", + "evm/creates" + }; + + for (String path : requiredPaths) { + JsonNode node = root.at("/" + path); + assertThat(node.isMissingNode()).as("Field '%s' should exist in JSON output", path).isFalse(); + } + + System.out.println("\n=== All " + requiredPaths.length + " required JSON fields validated ==="); + System.out.println(mapper.writerWithDefaultPrettyPrinter().writeValueAsString(root)); + } + + // ======================================================================== + // Test 11: Unique write counting - Same slot written in multiple transactions + // counts as ONE write, not N writes (regression test for per-tx overcounting) + // ======================================================================== + + @Test + void shouldCountUniqueStorageWritesNotPerTransactionWrites() { + // Two transactions from account 1 both call setSlot1(), writing to the same storage slot. + // If writes are counted per-transaction the result would be 2; the correct answer is 1. + Transaction firstWrite = + Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) + .maxPriorityFeePerGas(Wei.of(5)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(3000000L) + .to(CONTRACT_ADDRESS) + .value(Wei.ZERO) + .payload(encodeFunction("setSlot1", Optional.of(11))) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + + Transaction secondWrite = + Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(1) // same sender, next nonce + .maxPriorityFeePerGas(Wei.of(5)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(3000000L) + .to(CONTRACT_ADDRESS) + .value(Wei.ZERO) + .payload(encodeFunction("setSlot1", Optional.of(22))) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + + processTransaction(firstWrite); + processTransaction(secondWrite); + collectStats(); + + assertThat(stats.getSstoreCount()) + .as("Two SSTORE opcodes should be counted (one per tx)") + .isEqualTo(2); + + assertThat(stats.getStorageWrites()) + .as( + "Only 1 unique storage slot was written in the block — " + + "write count must not be inflated by the number of transactions touching the slot") + .isEqualTo(1); + } + + // ======================================================================== + // Test 12: Unique read counting - Same slot read in multiple transactions + // counts as ONE read, not N reads (validates cache-based deduplication) + // ======================================================================== + + @Test + void shouldCountUniqueStorageReadsNotPerTransactionReads() { + // Two transactions from separate accounts both call getSlot1() on the contract, + // reading the same storage slot. The first read is a cache miss (counted); + // the second should be a cache hit (not counted again). + Transaction firstRead = + Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) + .maxPriorityFeePerGas(Wei.of(5)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(3000000L) + .to(CONTRACT_ADDRESS) + .value(Wei.ZERO) + .payload(encodeFunction("getSlot1", Optional.empty())) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + + Transaction secondRead = + Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) // different sender, same slot + .maxPriorityFeePerGas(Wei.of(5)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(3000000L) + .to(CONTRACT_ADDRESS) + .value(Wei.ZERO) + .payload(encodeFunction("getSlot1", Optional.empty())) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_2_KEYPAIR); + + processTransaction(firstRead); + processTransaction(secondRead); + collectStats(); + + assertThat(stats.getSloadCount()) + .as("Two SLOAD opcodes should be counted (one per tx)") + .isEqualTo(2); + + assertThat(stats.getStorageReads()) + .as( + "Only 1 unique storage slot was loaded from underlying storage — " + + "the second tx should hit the accumulator cache, not count as a new read") + .isEqualTo(1); + + assertThat(stats.getStorageCacheHits()) + .as("Second read of the same slot should be recorded as a cache hit") + .isGreaterThanOrEqualTo(1); + } + + // ======================================================================== + // Test 13 (was 11): Combined metrics summary + // ======================================================================== + + @Test + void shouldTrackCombinedMetricsForMixedBlock() throws Exception { + // Given: Multiple transactions of different types in one block + // Transaction 1: ETH transfer + Transaction ethTransfer = + Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) + .maxPriorityFeePerGas(Wei.of(0)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(50_000L) + .to(Address.fromHexStringStrict(RECIPIENT_EOA)) + .value(Wei.of(1_000_000_000_000_000_000L)) + .payload(Bytes.EMPTY) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + + // Transaction 2: Storage write (using different sender) + Transaction storageWrite = + Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) // Different sender + .maxPriorityFeePerGas(Wei.of(5)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(3000000L) + .to(CONTRACT_ADDRESS) + .value(Wei.ZERO) + .payload(encodeFunction("setSlot1", Optional.of(999))) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_2_KEYPAIR); + + // When: Processing all transactions + processTransaction(ethTransfer); + processTransaction(storageWrite); + collectStats(); + + // Then: Multiple metric categories should be populated + assertThat(stats.getAccountWrites()) + .as("Combined block should have account writes from ETH transfer") + .isGreaterThanOrEqualTo(2); + + assertThat(stats.getSstoreCount()) + .as("Combined block should have SSTORE from storage write") + .isGreaterThanOrEqualTo(1); + + // Verify JSON captures all metrics + stats.incrementTransactionCount(); + stats.incrementTransactionCount(); + stats.addGasUsed(100000); + + String json = stats.toSlowBlockJson(1L, "0xcombined"); + ObjectMapper mapper = new ObjectMapper(); + JsonNode root = mapper.readTree(json); + + assertThat(root.path("state_writes").path("accounts").asInt()) + .as("JSON should reflect account writes") + .isGreaterThan(0); + + assertThat(root.path("evm").path("sstore").asInt()) + .as("JSON should reflect SSTORE operations") + .isGreaterThan(0); + + printStats("Combined Mixed Block"); + } + + // ======================================================================== + // Helper Methods + // ======================================================================== + + private void processTransaction(final Transaction tx) { + var worldUpdater = worldState.updater(); + BlockHashLookup blockHashLookup = + (frame, blockNumber) -> blockchain.getChainHeadHeader().getHash(); + + TransactionProcessingResult result = + transactionProcessor.processTransaction( + worldUpdater, + blockHeader, + tx, + blockHeader.getCoinbase(), + evmMetricsTracer, + blockHashLookup, + ImmutableTransactionValidationParams.builder().build(), + Wei.ZERO); + + if (result.isSuccessful()) { + worldUpdater.commit(); + } + } + + private void collectStats() { + // Collect final write metrics from accumulator (mirrors what persist() does at end-of-block) + if (worldState instanceof PathBasedWorldState pathBasedWorldState) { + pathBasedWorldState + .getAccumulator() + .collectFinalWriteMetrics(pathBasedWorldState.getStateMetricsCollector()); + } + // Collect EVM operation counts from the tracer + var metrics = evmMetricsTracer.getMetrics(); + stats.setSloadCount(metrics.getSloadCount()); + stats.setSstoreCount(metrics.getSstoreCount()); + stats.setCallCount(metrics.getCallCount()); + stats.setCreateCount(metrics.getCreateCount()); + stats.endExecution(); + } + + private void printStats(final String testName) { + System.out.println("\n=== " + testName + " Metrics ==="); + System.out.println("Account reads: " + stats.getAccountReads()); + System.out.println("Account writes: " + stats.getAccountWrites()); + System.out.println("Storage reads: " + stats.getStorageReads()); + System.out.println("Storage writes: " + stats.getStorageWrites()); + System.out.println("Code reads: " + stats.getCodeReads()); + System.out.println("Code bytes read: " + stats.getCodeBytesRead()); + System.out.println("Code writes: " + stats.getCodeWrites()); + System.out.println("Code bytes written: " + stats.getCodeBytesWritten()); + System.out.println("SLOAD: " + stats.getSloadCount()); + System.out.println("SSTORE: " + stats.getSstoreCount()); + System.out.println("CALL: " + stats.getCallCount()); + System.out.println("CREATE: " + stats.getCreateCount()); + System.out.println("Execution time (ms): " + stats.getExecutionTimeMs()); + } + + private static KeyPair generateKeyPair(final String privateKeyHex) { + return SignatureAlgorithmFactory.getInstance() + .createKeyPair( + SECPPrivateKey.create( + Bytes32.fromHexString(privateKeyHex), SignatureAlgorithm.ALGORITHM)); + } + + @SuppressWarnings("rawtypes") + private Transaction createContractCallTransaction( + final String methodName, final Optional value) { + return Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) + .maxPriorityFeePerGas(Wei.of(5)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(3000000L) + .to(CONTRACT_ADDRESS) + .value(Wei.ZERO) + .payload(encodeFunction(methodName, value)) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + } + + @SuppressWarnings("rawtypes") + private Bytes encodeFunction(final String methodName, final Optional value) { + List inputParameters = + value.isPresent() ? Arrays.asList(new Uint256(value.get())) : List.of(); + Function function = new Function(methodName, inputParameters, List.of()); + return Bytes.fromHexString(FunctionEncoder.encode(function)); + } + + @SuppressWarnings("rawtypes") + private Transaction createGetBalanceTransaction(final Address targetAddress) { + // getBalance(address) function + List inputParameters = + Arrays.asList(new org.web3j.abi.datatypes.Address(targetAddress.toHexString())); + Function function = new Function("getBalance", inputParameters, List.of()); + Bytes payload = Bytes.fromHexString(FunctionEncoder.encode(function)); + + return Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(0) + .maxPriorityFeePerGas(Wei.of(5)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(3000000L) + .to(CONTRACT_ADDRESS) + .value(Wei.ZERO) + .payload(payload) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + } + + @SuppressWarnings("rawtypes") + private Transaction createTransferToTransaction(final Address recipient, final long amount) { + // transferTo(address payable recipient, uint256 amount) + List inputParameters = + Arrays.asList( + new org.web3j.abi.datatypes.Address(recipient.toHexString()), new Uint256(amount)); + Function function = new Function("transferTo", inputParameters, List.of()); + Bytes payload = Bytes.fromHexString(FunctionEncoder.encode(function)); + + return Transaction.builder() + .type(TransactionType.EIP1559) + .nonce(1) // After funding transaction + .maxPriorityFeePerGas(Wei.of(5)) + .maxFeePerGas(Wei.of(7)) + .gasLimit(3000000L) + .to(CONTRACT_ADDRESS) + .value(Wei.ZERO) + .payload(payload) + .chainId(BigInteger.valueOf(42)) + .signAndBuild(GENESIS_ACCOUNT_1_KEYPAIR); + } +} diff --git a/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BackgroundTracerFactoryTest.java b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BackgroundTracerFactoryTest.java new file mode 100644 index 00000000000..05a9a2cead4 --- /dev/null +++ b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BackgroundTracerFactoryTest.java @@ -0,0 +1,120 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.ethereum.mainnet.parallelization; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.when; + +import org.hyperledger.besu.datatypes.Address; +import org.hyperledger.besu.ethereum.core.BlockHeader; +import org.hyperledger.besu.ethereum.mainnet.SlowBlockTracer; +import org.hyperledger.besu.ethereum.mainnet.systemcall.BlockProcessingContext; +import org.hyperledger.besu.evm.tracing.EVMExecutionMetricsTracer; +import org.hyperledger.besu.evm.tracing.OperationTracer; +import org.hyperledger.besu.plugin.services.tracer.BlockAwareOperationTracer; + +import org.junit.jupiter.api.Test; + +/** Unit tests for {@link BackgroundTracerFactory}. */ +class BackgroundTracerFactoryTest { + + private static SlowBlockTracer newSlowBlockTracer() { + return new SlowBlockTracer(0, mock(BlockAwareOperationTracer.class)); + } + + @Test + void createBackgroundTracer_nullContext_returnsNoTracing() { + assertThat(BackgroundTracerFactory.createBackgroundTracer(null)) + .isSameAs(OperationTracer.NO_TRACING); + } + + @Test + void createBackgroundTracer_nullTracer_returnsNoTracing() { + final BlockProcessingContext bpc = mock(BlockProcessingContext.class); + when(bpc.getOperationTracer()).thenReturn(null); + assertThat(BackgroundTracerFactory.createBackgroundTracer(bpc)) + .isSameAs(OperationTracer.NO_TRACING); + } + + @Test + void createBackgroundTracer_withSlowBlockTracer_returnsNewEVMExecutionMetricsTracer() { + final SlowBlockTracer slowBlockTracer = newSlowBlockTracer(); + final BlockProcessingContext bpc = mock(BlockProcessingContext.class); + when(bpc.getOperationTracer()).thenReturn(slowBlockTracer); + + final OperationTracer background = BackgroundTracerFactory.createBackgroundTracer(bpc); + + assertThat(background).isInstanceOf(EVMExecutionMetricsTracer.class); + assertThat(background).isNotSameAs(slowBlockTracer); + } + + @Test + void createBackgroundTracer_withUnknownTracer_returnsOriginal() { + final OperationTracer unknownTracer = mock(OperationTracer.class); + final BlockProcessingContext bpc = mock(BlockProcessingContext.class); + when(bpc.getOperationTracer()).thenReturn(unknownTracer); + + final OperationTracer background = BackgroundTracerFactory.createBackgroundTracer(bpc); + + assertThat(background).isSameAs(unknownTracer); + } + + @Test + void hasMetricsTracer_slowBlockTracer() { + assertThat(BackgroundTracerFactory.hasMetricsTracer(newSlowBlockTracer())).isTrue(); + } + + @Test + void hasMetricsTracer_noMetricsTracer() { + assertThat(BackgroundTracerFactory.hasMetricsTracer(mock(OperationTracer.class))).isFalse(); + } + + @Test + void findSlowBlockTracer_directInstance() { + final SlowBlockTracer sbt = newSlowBlockTracer(); + assertThat(BackgroundTracerFactory.findSlowBlockTracer(sbt)).contains(sbt); + } + + @Test + void findSlowBlockTracer_notPresent() { + assertThat(BackgroundTracerFactory.findSlowBlockTracer(mock(OperationTracer.class))).isEmpty(); + } + + @Test + void consolidateTracerResults_mergesMetricsAndIncrementsTxCount() { + final SlowBlockTracer slowBlockTracer = newSlowBlockTracer(); + final BlockHeader blockHeader = mock(BlockHeader.class); + slowBlockTracer.traceStartBlock(null, blockHeader, null, Address.ZERO); + + final BlockProcessingContext bpc = mock(BlockProcessingContext.class); + when(bpc.getOperationTracer()).thenReturn(slowBlockTracer); + + final EVMExecutionMetricsTracer backgroundTracer = new EVMExecutionMetricsTracer(); + + BackgroundTracerFactory.consolidateTracerResults(backgroundTracer, bpc); + + assertThat(slowBlockTracer.getExecutionStats().getTransactionCount()) + .as("tx_count should be incremented after consolidation") + .isEqualTo(1); + } + + @Test + void consolidateTracerResults_nullContext_doesNotThrow() { + final EVMExecutionMetricsTracer backgroundTracer = new EVMExecutionMetricsTracer(); + // Should not throw + BackgroundTracerFactory.consolidateTracerResults(backgroundTracer, null); + } +} diff --git a/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BalParallelBlockProcessorIntegrationTest.java b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BalParallelBlockProcessorIntegrationTest.java index 08cc5d4b811..8c315599e2b 100644 --- a/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BalParallelBlockProcessorIntegrationTest.java +++ b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BalParallelBlockProcessorIntegrationTest.java @@ -35,6 +35,7 @@ import org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor; import org.hyperledger.besu.ethereum.mainnet.ProtocolSpec; import org.hyperledger.besu.ethereum.mainnet.block.access.list.BlockAccessList; +import org.hyperledger.besu.ethereum.mainnet.systemcall.BlockProcessingContext; import org.hyperledger.besu.ethereum.trie.pathbased.common.provider.WorldStateQueryParams; import org.hyperledger.besu.evm.blockhash.BlockHashLookup; import org.hyperledger.besu.plugin.services.worldstate.MutableWorldState; @@ -295,6 +296,7 @@ public Optional run( final Wei blobGasPrice, final Optional blockAccessListBuilder, final Optional maybeBlockBal, + final BlockProcessingContext blockProcessingContext, final Optional maybeParentHeader) { return super.run( protocolContext, @@ -305,6 +307,7 @@ public Optional run( blobGasPrice, blockAccessListBuilder, Optional.of(preComputedBal), + blockProcessingContext, maybeParentHeader); } } diff --git a/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BalTransactionProcessorUnitTest.java b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BalTransactionProcessorUnitTest.java index 02438bca648..da4bd7ed8f4 100644 --- a/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BalTransactionProcessorUnitTest.java +++ b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/BalTransactionProcessorUnitTest.java @@ -165,7 +165,7 @@ void transactionProcessorCalledWithCorrectParams() { final BalConcurrentTransactionProcessor processor = new BalConcurrentTransactionProcessor( - transactionProcessor, blockAccessList, BalConfiguration.DEFAULT); + transactionProcessor, blockAccessList, BalConfiguration.DEFAULT, null); processor.runAsyncBlock( env.protocolContext(), @@ -203,7 +203,7 @@ void allTransactionsProcessed() { final BalConcurrentTransactionProcessor processor = new BalConcurrentTransactionProcessor( - transactionProcessor, blockAccessList, BalConfiguration.DEFAULT); + transactionProcessor, blockAccessList, BalConfiguration.DEFAULT, null); processor.runAsyncBlock( env.protocolContext(), @@ -230,7 +230,7 @@ void processingResultReturnedForSuccessfulTransaction() { final BalConcurrentTransactionProcessor processor = new BalConcurrentTransactionProcessor( - transactionProcessor, blockAccessList, BalConfiguration.DEFAULT); + transactionProcessor, blockAccessList, BalConfiguration.DEFAULT, null); processor.runAsyncBlock( env.protocolContext(), @@ -271,7 +271,7 @@ void skipsProcessingWhenParentHeaderAbsent() { final BonsaiWorldState worldStateForResult = createEmptyWorldState(); final BalConcurrentTransactionProcessor processor = new BalConcurrentTransactionProcessor( - transactionProcessor, blockAccessList, BalConfiguration.DEFAULT); + transactionProcessor, blockAccessList, BalConfiguration.DEFAULT, null); processor.runAsyncBlock( protocolContext, @@ -308,7 +308,7 @@ void skipsProcessingWhenArchiveHasNoWorldState() { final Transaction transaction = mock(Transaction.class); final BalConcurrentTransactionProcessor processor = new BalConcurrentTransactionProcessor( - transactionProcessor, blockAccessList, BalConfiguration.DEFAULT); + transactionProcessor, blockAccessList, BalConfiguration.DEFAULT, null); processor.runAsyncBlock( env.protocolContext(), @@ -346,7 +346,7 @@ void loadWorldStateUsesParentBlockHeader() { final BlockHeader parent = env.maybeParentHeader().orElseThrow(); final BalConcurrentTransactionProcessor processor = new BalConcurrentTransactionProcessor( - transactionProcessor, blockAccessList, BalConfiguration.DEFAULT); + transactionProcessor, blockAccessList, BalConfiguration.DEFAULT, null); processor.runAsyncBlock( env.protocolContext(), @@ -489,7 +489,7 @@ void preStateSetupFromBlockAccessList() { final BalConcurrentTransactionProcessor processor = new BalConcurrentTransactionProcessor( - transactionProcessor, blockAccessList, BalConfiguration.DEFAULT); + transactionProcessor, blockAccessList, BalConfiguration.DEFAULT, null); final Transaction tx0 = mockTransaction(); final Transaction tx1 = mockTransaction(); @@ -544,7 +544,7 @@ void returnsEmptyWhenParallelContextIsNull() { final BalConcurrentTransactionProcessor processor = new BalConcurrentTransactionProcessor( - transactionProcessor, blockAccessList, BalConfiguration.DEFAULT); + transactionProcessor, blockAccessList, BalConfiguration.DEFAULT, null); processor.runAsyncBlock( env.protocolContext(), diff --git a/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelBlockTransactionProcessorTest.java b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelBlockTransactionProcessorTest.java new file mode 100644 index 00000000000..3beea718ad2 --- /dev/null +++ b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelBlockTransactionProcessorTest.java @@ -0,0 +1,571 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.ethereum.mainnet.parallelization; + +import static org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.WorldStateConfig.createStatefulConfigWithTrie; +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.mockito.ArgumentMatchers.any; +import static org.mockito.ArgumentMatchers.argThat; +import static org.mockito.ArgumentMatchers.eq; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.times; +import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.when; + +import org.hyperledger.besu.datatypes.Address; +import org.hyperledger.besu.datatypes.Hash; +import org.hyperledger.besu.datatypes.StorageSlotKey; +import org.hyperledger.besu.datatypes.Wei; +import org.hyperledger.besu.ethereum.ProtocolContext; +import org.hyperledger.besu.ethereum.chain.MutableBlockchain; +import org.hyperledger.besu.ethereum.core.BlockHeader; +import org.hyperledger.besu.ethereum.core.InMemoryKeyValueStorageProvider; +import org.hyperledger.besu.ethereum.core.Transaction; +import org.hyperledger.besu.ethereum.mainnet.BalConfiguration; +import org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor; +import org.hyperledger.besu.ethereum.mainnet.TransactionValidationParams; +import org.hyperledger.besu.ethereum.mainnet.ValidationResult; +import org.hyperledger.besu.ethereum.mainnet.block.access.list.BlockAccessList; +import org.hyperledger.besu.ethereum.mainnet.block.access.list.BlockAccessList.BlockAccessListBuilder; +import org.hyperledger.besu.ethereum.mainnet.block.access.list.PartialBlockAccessView; +import org.hyperledger.besu.ethereum.mainnet.systemcall.BlockProcessingContext; +import org.hyperledger.besu.ethereum.processing.TransactionProcessingResult; +import org.hyperledger.besu.ethereum.transaction.TransactionInvalidReason; +import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.cache.CodeCache; +import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.cache.NoOpBonsaiCachedWorldStorageManager; +import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.cache.NoopBonsaiCachedMerkleTrieLoader; +import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.storage.BonsaiWorldStateKeyValueStorage; +import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.worldview.BonsaiWorldState; +import org.hyperledger.besu.ethereum.trie.pathbased.common.trielog.NoOpTrieLogManager; +import org.hyperledger.besu.ethereum.worldstate.DataStorageConfiguration; +import org.hyperledger.besu.ethereum.worldstate.WorldStateArchive; +import org.hyperledger.besu.evm.account.Account; +import org.hyperledger.besu.evm.blockhash.BlockHashLookup; +import org.hyperledger.besu.evm.internal.EvmConfiguration; +import org.hyperledger.besu.evm.tracing.OperationTracer; +import org.hyperledger.besu.evm.worldstate.WorldUpdater; +import org.hyperledger.besu.metrics.noop.NoOpMetricsSystem; + +import java.util.Collections; +import java.util.Optional; +import java.util.concurrent.Executor; +import java.util.concurrent.atomic.AtomicInteger; +import java.util.stream.Stream; + +import org.apache.tuweni.bytes.Bytes; +import org.apache.tuweni.units.bigints.UInt256; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.TestInstance; +import org.junit.jupiter.params.ParameterizedTest; +import org.junit.jupiter.params.provider.MethodSource; + +@TestInstance(TestInstance.Lifecycle.PER_CLASS) +class ParallelBlockTransactionProcessorTest { + + private enum ProcessorVariant { + PARALLELIZED, + BAL + } + + private final Executor sameThreadExecutor = Runnable::run; + private static final Address MINING_BENEFICIARY = Address.fromHexString("0x1"); + private static final Wei BLOB_GAS_PRICE = Wei.ZERO; + + private Stream processorVariants() { + return Stream.of(ProcessorVariant.PARALLELIZED, ProcessorVariant.BAL); + } + + private BonsaiWorldState createEmptyWorldState() { + final BonsaiWorldStateKeyValueStorage bonsaiWorldStateKeyValueStorage = + new BonsaiWorldStateKeyValueStorage( + new InMemoryKeyValueStorageProvider(), + new NoOpMetricsSystem(), + DataStorageConfiguration.DEFAULT_BONSAI_CONFIG); + + return new BonsaiWorldState( + bonsaiWorldStateKeyValueStorage, + new NoopBonsaiCachedMerkleTrieLoader(), + new NoOpBonsaiCachedWorldStorageManager( + bonsaiWorldStateKeyValueStorage, EvmConfiguration.DEFAULT, new CodeCache()), + new NoOpTrieLogManager(), + EvmConfiguration.DEFAULT, + createStatefulConfigWithTrie(), + new CodeCache()); + } + + private ParallelBlockTransactionProcessor createProcessor( + final ProcessorVariant variant, + final MainnetTransactionProcessor transactionProcessor, + final TransactionCollisionDetector collisionDetector, + final BlockAccessList blockAccessList) { + + return switch (variant) { + case PARALLELIZED -> + new ParallelizedConcurrentTransactionProcessor(transactionProcessor, collisionDetector); + case BAL -> { + final BlockProcessingContext bpc = mock(BlockProcessingContext.class); + when(bpc.getOperationTracer()).thenReturn(OperationTracer.NO_TRACING); + yield new BalConcurrentTransactionProcessor( + transactionProcessor, blockAccessList, BalConfiguration.DEFAULT, bpc); + } + }; + } + + private record TestEnvironment( + ProtocolContext protocolContext, BlockHeader blockHeader, BonsaiWorldState worldState) {} + + private TestEnvironment createTestEnvironment() { + final ProtocolContext protocolContext = mock(ProtocolContext.class); + final MutableBlockchain blockchain = mock(MutableBlockchain.class); + final BlockHeader chainHeadBlockHeader = mock(BlockHeader.class); + final BlockHeader blockHeader = mock(BlockHeader.class); + final WorldStateArchive worldStateArchive = mock(WorldStateArchive.class); + final BonsaiWorldState worldState = createEmptyWorldState(); + + when(protocolContext.getBlockchain()).thenReturn(blockchain); + when(blockchain.getChainHeadHeader()).thenReturn(chainHeadBlockHeader); + when(chainHeadBlockHeader.getHash()).thenReturn(Hash.ZERO); + when(chainHeadBlockHeader.getStateRoot()).thenReturn(Hash.EMPTY_TRIE_HASH); + + when(blockHeader.getParentHash()).thenReturn(Hash.ZERO); + when(blockHeader.getStateRoot()).thenReturn(Hash.EMPTY_TRIE_HASH); + when(blockHeader.getBlockHash()).thenReturn(Hash.ZERO); + + when(protocolContext.getWorldStateArchive()).thenReturn(worldStateArchive); + when(worldStateArchive.getWorldState(any())).thenReturn(Optional.of(worldState)); + + return new TestEnvironment(protocolContext, blockHeader, worldState); + } + + private BlockAccessList mockEmptyBlockAccessList() { + final BlockAccessList blockAccessList = mock(BlockAccessList.class); + when(blockAccessList.accountChanges()).thenReturn(Collections.emptyList()); + return blockAccessList; + } + + private Transaction mockTransaction() { + final Transaction transaction = mock(Transaction.class); + when(transaction.detachedCopy()).thenReturn(transaction); + return transaction; + } + + private record ProcessorTestFixture( + ProcessorVariant variant, + MainnetTransactionProcessor transactionProcessor, + TransactionCollisionDetector collisionDetector, + BlockAccessList blockAccessList, + Transaction transaction, + TestEnvironment env, + ParallelBlockTransactionProcessor processor) {} + + private ProcessorTestFixture createFixture(final ProcessorVariant variant) { + final MainnetTransactionProcessor transactionProcessor = + mock(MainnetTransactionProcessor.class); + final TransactionCollisionDetector collisionDetector = mock(TransactionCollisionDetector.class); + final BlockAccessList blockAccessList = mockEmptyBlockAccessList(); + final Transaction transaction = mockTransaction(); + final TestEnvironment env = createTestEnvironment(); + final ParallelBlockTransactionProcessor processor = + createProcessor(variant, transactionProcessor, collisionDetector, blockAccessList); + + if (variant == ProcessorVariant.PARALLELIZED) { + when(collisionDetector.hasCollision(any(), any(), any(), any())).thenReturn(false); + } + + return new ProcessorTestFixture( + variant, + transactionProcessor, + collisionDetector, + blockAccessList, + transaction, + env, + processor); + } + + private void stubSuccessfulTransaction( + final MainnetTransactionProcessor transactionProcessor, + final Optional partialView) { + + when(transactionProcessor.processTransaction( + any(), any(), any(), any(), any(), any(), any(), any(), any())) + .thenReturn( + TransactionProcessingResult.successful( + Collections.emptyList(), 0, 0, Bytes.EMPTY, partialView, ValidationResult.valid())); + } + + @ParameterizedTest(name = "{index}: {0}") + @MethodSource("processorVariants") + void testRunTransaction(final ProcessorVariant variant) { + final ProcessorTestFixture f = createFixture(variant); + stubSuccessfulTransaction(f.transactionProcessor(), Optional.empty()); + + f.processor() + .runAsyncBlock( + f.env().protocolContext(), + f.env().blockHeader(), + Collections.singletonList(f.transaction()), + MINING_BENEFICIARY, + (__, ___) -> Hash.EMPTY, + BLOB_GAS_PRICE, + sameThreadExecutor, + Optional.empty(), + Optional.of(f.env().blockHeader())); + + verify(f.transactionProcessor(), times(1)) + .processTransaction( + any(WorldUpdater.class), + eq(f.env().blockHeader()), + eq(f.transaction()), + eq(MINING_BENEFICIARY), + any(OperationTracer.class), + any(BlockHashLookup.class), + eq(TransactionValidationParams.processingBlock()), + eq(BLOB_GAS_PRICE), + eq(Optional.empty())); + + final Optional maybeResult = + f.processor() + .getProcessingResult( + f.env().worldState(), + MINING_BENEFICIARY, + f.transaction(), + 0, + Optional.empty(), + Optional.empty()); + + assertTrue(maybeResult.isPresent(), "Expected the transaction result to be present"); + assertTrue(maybeResult.get().isSuccessful(), "Expected the processing to be successful"); + } + + @ParameterizedTest(name = "{index}: {0}") + @MethodSource("processorVariants") + void testRunTransactionWithFailure(final ProcessorVariant variant) { + final ProcessorTestFixture f = createFixture(variant); + when(f.transactionProcessor() + .processTransaction(any(), any(), any(), any(), any(), any(), any(), any(), any())) + .thenReturn( + TransactionProcessingResult.failed( + 0, + 0, + ValidationResult.invalid( + TransactionInvalidReason.BLOB_GAS_PRICE_BELOW_CURRENT_BLOB_BASE_FEE), + Optional.of(Bytes.EMPTY), + Optional.empty(), + Optional.empty())); + + f.processor() + .runAsyncBlock( + f.env().protocolContext(), + f.env().blockHeader(), + Collections.singletonList(f.transaction()), + MINING_BENEFICIARY, + (__, ___) -> Hash.EMPTY, + BLOB_GAS_PRICE, + sameThreadExecutor, + Optional.empty(), + Optional.of(f.env().blockHeader())); + + final Optional maybeResult = + f.processor() + .getProcessingResult( + f.env().worldState(), + MINING_BENEFICIARY, + f.transaction(), + 0, + Optional.empty(), + Optional.empty()); + + if (variant == ProcessorVariant.BAL) { + assertFalse(maybeResult.isEmpty(), "Expected non-empty result for the BAL variant"); + assertTrue(maybeResult.get().getStatus() == TransactionProcessingResult.Status.FAILED); + } else { + assertTrue( + maybeResult.isEmpty(), + "Expected empty result so the block processor re-executes the transaction"); + } + } + + @Test + void testRunTransactionWithConflict() { + final ProcessorTestFixture f = createFixture(ProcessorVariant.PARALLELIZED); + stubSuccessfulTransaction(f.transactionProcessor(), Optional.empty()); + + f.processor() + .runAsyncBlock( + f.env().protocolContext(), + f.env().blockHeader(), + Collections.singletonList(f.transaction()), + MINING_BENEFICIARY, + (__, ___) -> Hash.EMPTY, + BLOB_GAS_PRICE, + sameThreadExecutor, + Optional.empty(), + Optional.of(f.env().blockHeader())); + + verify(f.transactionProcessor(), times(1)) + .processTransaction( + any(WorldUpdater.class), + eq(f.env().blockHeader()), + eq(f.transaction()), + eq(MINING_BENEFICIARY), + any(OperationTracer.class), + any(BlockHashLookup.class), + eq(TransactionValidationParams.processingBlock()), + eq(BLOB_GAS_PRICE), + eq(Optional.empty())); + + // simulate a conflict + when(f.collisionDetector().hasCollision(any(), any(), any(), any())).thenReturn(true); + + final Optional maybeResult = + f.processor() + .getProcessingResult( + f.env().worldState(), + MINING_BENEFICIARY, + f.transaction(), + 0, + Optional.empty(), + Optional.empty()); + + assertTrue( + maybeResult.isEmpty(), "Expected no transaction result to be applied due to conflict"); + } + + @Test + void testApplyResultUsesAccessLocationTrackerAndUpdatesPartialBlockAccessView() { + final ProcessorTestFixture f = createFixture(ProcessorVariant.PARALLELIZED); + + final PartialBlockAccessView partialView = mock(PartialBlockAccessView.class); + final PartialBlockAccessView.AccountChanges beneficiaryChanges = + mock(PartialBlockAccessView.AccountChanges.class); + when(beneficiaryChanges.getAddress()).thenReturn(MINING_BENEFICIARY); + when(partialView.accountChanges()).thenReturn(Collections.singletonList(beneficiaryChanges)); + + // Stub processTransaction to also simulate traceBeforeRewardTransaction with a non-zero reward, + // so that getProcessingResult updates the post-balance in the partial block access view. + final Wei simulatedReward = Wei.of(1_000_000L); + when(f.transactionProcessor() + .processTransaction(any(), any(), any(), any(), any(), any(), any(), any(), any())) + .thenAnswer( + invocation -> { + final OperationTracer tracer = invocation.getArgument(4, OperationTracer.class); + tracer.traceBeforeRewardTransaction(null, null, simulatedReward); + return TransactionProcessingResult.successful( + Collections.emptyList(), + 0, + 0, + Bytes.EMPTY, + Optional.of(partialView), + ValidationResult.valid()); + }); + + final BlockAccessListBuilder balBuilder = mock(BlockAccessListBuilder.class); + + f.processor() + .runAsyncBlock( + f.env().protocolContext(), + f.env().blockHeader(), + Collections.singletonList(f.transaction()), + MINING_BENEFICIARY, + (__, ___) -> Hash.EMPTY, + BLOB_GAS_PRICE, + sameThreadExecutor, + Optional.of(balBuilder), + Optional.of(f.env().blockHeader())); + + verify(f.transactionProcessor()) + .processTransaction( + any(WorldUpdater.class), + eq(f.env().blockHeader()), + eq(f.transaction()), + eq(MINING_BENEFICIARY), + any(OperationTracer.class), + any(BlockHashLookup.class), + eq(TransactionValidationParams.processingBlock()), + eq(BLOB_GAS_PRICE), + argThat(Optional::isPresent)); + + final Optional maybeResult = + f.processor() + .getProcessingResult( + f.env().worldState(), + MINING_BENEFICIARY, + f.transaction(), + 0, + Optional.empty(), + Optional.empty()); + + assertTrue( + maybeResult.isPresent(), "Expected the parallelized transaction result to be applied"); + final TransactionProcessingResult result = maybeResult.get(); + assertTrue(result.getPartialBlockAccessView().isPresent(), "Expected BAL view to be present"); + verify(beneficiaryChanges).setPostBalance(any(Wei.class)); + } + + @Test + void testPreStateSetup() { + final TestEnvironment env = createTestEnvironment(); + + final Address accountAddress = + Address.fromHexString("0x1000000000000000000000000000000000000001"); + + final UInt256 slot1Key = UInt256.ONE; + final UInt256 slot2Key = UInt256.valueOf(2); + final StorageSlotKey slot1 = new StorageSlotKey(slot1Key); + final StorageSlotKey slot2 = new StorageSlotKey(slot2Key); + + final Wei tx0Balance = Wei.of(100); + final long tx0Nonce = 1L; + final Bytes tx0Code = Bytes.fromHexString("0xAA"); + final UInt256 tx0Slot1Value = UInt256.valueOf(1); + final UInt256 tx0Slot2Value = UInt256.valueOf(3); + + final Wei tx1Balance = Wei.of(200); + final long tx1Nonce = 2L; + final Bytes tx1Code = Bytes.fromHexString("0xBB"); + final UInt256 tx1Slot1Value = UInt256.valueOf(5); + final UInt256 tx1Slot2Value = UInt256.ZERO; + + final Wei tx2Balance = Wei.of(300); + final long tx2Nonce = 3L; + final Bytes tx2Code = Bytes.fromHexString("0xCC"); + final UInt256 tx2Slot1Value = UInt256.valueOf(7); + + final BlockAccessList.BlockAccessListBuilder balBuilder = BlockAccessList.builder(); + + final PartialBlockAccessView.PartialBlockAccessViewBuilder p0 = + new PartialBlockAccessView.PartialBlockAccessViewBuilder().withTxIndex(0); + final PartialBlockAccessView.AccountChangesBuilder a0 = + p0.getOrCreateAccountBuilder(accountAddress); + a0.withPostBalance(tx0Balance); + a0.withNonceChange(tx0Nonce); + a0.withNewCode(tx0Code); + a0.addStorageChange(slot1, tx0Slot1Value); + a0.addStorageChange(slot2, tx0Slot2Value); + balBuilder.apply(p0.build()); + + final PartialBlockAccessView.PartialBlockAccessViewBuilder p1 = + new PartialBlockAccessView.PartialBlockAccessViewBuilder().withTxIndex(1); + final PartialBlockAccessView.AccountChangesBuilder a1 = + p1.getOrCreateAccountBuilder(accountAddress); + a1.withPostBalance(tx1Balance); + a1.withNonceChange(tx1Nonce); + a1.withNewCode(tx1Code); + a1.addStorageChange(slot1, tx1Slot1Value); + a1.addStorageChange(slot2, null); + balBuilder.apply(p1.build()); + + final PartialBlockAccessView.PartialBlockAccessViewBuilder p2 = + new PartialBlockAccessView.PartialBlockAccessViewBuilder().withTxIndex(2); + final PartialBlockAccessView.AccountChangesBuilder a2 = + p2.getOrCreateAccountBuilder(accountAddress); + a2.withPostBalance(tx2Balance); + a2.withNonceChange(tx2Nonce); + a2.withNewCode(tx2Code); + a2.addStorageChange(slot1, tx2Slot1Value); + balBuilder.apply(p2.build()); + + final BlockAccessList blockAccessList = balBuilder.build(); + + final MainnetTransactionProcessor transactionProcessor = + mock(MainnetTransactionProcessor.class); + + final AtomicInteger locationCounter = new AtomicInteger(0); + when(transactionProcessor.processTransaction( + any(), any(), any(), any(), any(), any(), any(), any(), any())) + .thenAnswer( + invocation -> { + final int transactionLocation = locationCounter.getAndIncrement(); + final WorldUpdater worldUpdater = invocation.getArgument(0, WorldUpdater.class); + final Account account = worldUpdater.get(accountAddress); + + assertTrue(account != null, "Expected account to exist in world updater"); + + switch (transactionLocation) { + case 0 -> { + // transactionLocation = 0 -> balIndex = 1 -> latest < 1 is tx0 + assertEquals(tx0Balance, account.getBalance()); + assertEquals(tx0Nonce, account.getNonce()); + assertEquals(tx0Code, account.getCode()); + assertEquals(tx0Slot1Value, account.getStorageValue(slot1Key)); + assertEquals(tx0Slot2Value, account.getStorageValue(slot2Key)); + } + case 1 -> { + // transactionLocation = 1 -> balIndex = 2 -> latest < 2 is tx1 + assertEquals(tx1Balance, account.getBalance()); + assertEquals(tx1Nonce, account.getNonce()); + assertEquals(tx1Code, account.getCode()); + assertEquals(tx1Slot1Value, account.getStorageValue(slot1Key)); + assertEquals(tx1Slot2Value, account.getStorageValue(slot2Key)); + } + case 2 -> { + // transactionLocation = 2 -> balIndex = 3 -> latest < 3 is tx2 + assertEquals(tx2Balance, account.getBalance()); + assertEquals(tx2Nonce, account.getNonce()); + assertEquals(tx2Code, account.getCode()); + assertEquals(tx2Slot1Value, account.getStorageValue(slot1Key)); + } + default -> + throw new IllegalStateException( + "Unexpected transactionLocation " + transactionLocation); + } + + return TransactionProcessingResult.successful( + Collections.emptyList(), + 0, + 0, + Bytes.EMPTY, + Optional.empty(), + ValidationResult.valid()); + }); + + final BlockProcessingContext bpc = mock(BlockProcessingContext.class); + when(bpc.getOperationTracer()).thenReturn(OperationTracer.NO_TRACING); + final BalConcurrentTransactionProcessor processor = + new BalConcurrentTransactionProcessor( + transactionProcessor, blockAccessList, BalConfiguration.DEFAULT, bpc); + + final Transaction tx0 = mockTransaction(); + final Transaction tx1 = mockTransaction(); + final Transaction tx2 = mockTransaction(); + + processor.runAsyncBlock( + env.protocolContext(), + env.blockHeader(), + java.util.List.of(tx0, tx1, tx2), + MINING_BENEFICIARY, + (__, ___) -> Hash.EMPTY, + BLOB_GAS_PRICE, + sameThreadExecutor, + Optional.empty(), + Optional.of(env.blockHeader())); + + final Transaction[] txs = new Transaction[] {tx0, tx1, tx2}; + for (int i = 0; i < txs.length; i++) { + final Optional maybeResult = + processor.getProcessingResult( + env.worldState(), MINING_BENEFICIARY, txs[i], i, Optional.empty(), Optional.empty()); + + assertTrue( + maybeResult.isPresent(), + "Expected processing result for transactionLocation " + i + " to be present"); + assertTrue( + maybeResult.get().isSuccessful(), + "Expected processing result for transactionLocation " + i + " to be successful"); + } + } +} diff --git a/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelizedConcurrentTransactionProcessorTracerTest.java b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelizedConcurrentTransactionProcessorTracerTest.java new file mode 100644 index 00000000000..078e77aea10 --- /dev/null +++ b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/ParallelizedConcurrentTransactionProcessorTracerTest.java @@ -0,0 +1,431 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.ethereum.mainnet.parallelization; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.mockito.ArgumentMatchers.any; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.when; + +import org.hyperledger.besu.datatypes.Address; +import org.hyperledger.besu.datatypes.Hash; +import org.hyperledger.besu.datatypes.Wei; +import org.hyperledger.besu.ethereum.ProtocolContext; +import org.hyperledger.besu.ethereum.chain.MutableBlockchain; +import org.hyperledger.besu.ethereum.core.BlockHeader; +import org.hyperledger.besu.ethereum.core.InMemoryKeyValueStorageProvider; +import org.hyperledger.besu.ethereum.core.Transaction; +import org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor; +import org.hyperledger.besu.ethereum.mainnet.SlowBlockTracer; +import org.hyperledger.besu.ethereum.mainnet.ValidationResult; +import org.hyperledger.besu.ethereum.mainnet.systemcall.BlockProcessingContext; +import org.hyperledger.besu.ethereum.processing.TransactionProcessingResult; +import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.cache.CodeCache; +import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.cache.NoOpBonsaiCachedWorldStorageManager; +import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.cache.NoopBonsaiCachedMerkleTrieLoader; +import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.storage.BonsaiWorldStateKeyValueStorage; +import org.hyperledger.besu.ethereum.trie.pathbased.bonsai.worldview.BonsaiWorldState; +import org.hyperledger.besu.ethereum.trie.pathbased.common.trielog.NoOpTrieLogManager; +import org.hyperledger.besu.ethereum.trie.pathbased.common.worldview.WorldStateConfig; +import org.hyperledger.besu.ethereum.worldstate.DataStorageConfiguration; +import org.hyperledger.besu.ethereum.worldstate.WorldStateArchive; +import org.hyperledger.besu.evm.frame.MessageFrame; +import org.hyperledger.besu.evm.internal.EvmConfiguration; +import org.hyperledger.besu.evm.operation.Operation; +import org.hyperledger.besu.evm.tracing.EVMExecutionMetricsTracer; +import org.hyperledger.besu.evm.tracing.OperationTracer; +import org.hyperledger.besu.metrics.noop.NoOpMetricsSystem; +import org.hyperledger.besu.plugin.services.tracer.BlockAwareOperationTracer; + +import java.util.Collections; +import java.util.List; +import java.util.Optional; +import java.util.concurrent.Executor; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; + +import org.apache.tuweni.bytes.Bytes; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +/** + * Tests for tracer handling in parallel transaction processing, specifically verifying that + * SlowBlockTracer metrics are correctly captured and merged during parallel transaction execution. + * Tests cover both the BackgroundTracerFactory utility methods and the end-to-end integration + * through ParallelizedConcurrentTransactionProcessor. + */ +@SuppressWarnings({"unchecked", "rawtypes"}) +class ParallelizedConcurrentTransactionProcessorTracerTest { + + private static final Address MINING_BENEFICIARY = Address.fromHexString("0x1"); + private static final Wei BLOB_GAS_PRICE = Wei.ZERO; + + private final Executor sameThreadExecutor = Runnable::run; + + private MainnetTransactionProcessor transactionProcessor; + private TransactionCollisionDetector collisionDetector; + private ProtocolContext protocolContext; + private BlockHeader blockHeader; + private BonsaiWorldState worldState; + + @BeforeEach + void setUp() { + transactionProcessor = mock(MainnetTransactionProcessor.class); + collisionDetector = mock(TransactionCollisionDetector.class); + + // No collisions by default + when(collisionDetector.hasCollision(any(), any(), any(), any())).thenReturn(false); + + // Stub successful transaction processing + when(transactionProcessor.processTransaction( + any(), any(), any(), any(), any(), any(), any(), any(), any())) + .thenReturn( + TransactionProcessingResult.successful( + Collections.emptyList(), + 0, + 0, + Bytes.EMPTY, + Optional.empty(), + ValidationResult.valid())); + + protocolContext = mock(ProtocolContext.class); + final MutableBlockchain blockchain = mock(MutableBlockchain.class); + final BlockHeader chainHeadBlockHeader = mock(BlockHeader.class); + blockHeader = mock(BlockHeader.class); + final WorldStateArchive worldStateArchive = mock(WorldStateArchive.class); + worldState = createEmptyWorldState(); + + when(protocolContext.getBlockchain()).thenReturn(blockchain); + when(blockchain.getChainHeadHeader()).thenReturn(chainHeadBlockHeader); + when(chainHeadBlockHeader.getHash()).thenReturn(Hash.ZERO); + when(chainHeadBlockHeader.getStateRoot()).thenReturn(Hash.EMPTY_TRIE_HASH); + when(blockHeader.getParentHash()).thenReturn(Hash.ZERO); + when(blockHeader.getStateRoot()).thenReturn(Hash.EMPTY_TRIE_HASH); + when(blockHeader.getBlockHash()).thenReturn(Hash.ZERO); + when(protocolContext.getWorldStateArchive()).thenReturn(worldStateArchive); + when(worldStateArchive.getWorldState(any())).thenReturn(Optional.of(worldState)); + } + + private static BonsaiWorldState createEmptyWorldState() { + final BonsaiWorldStateKeyValueStorage storage = + new BonsaiWorldStateKeyValueStorage( + new InMemoryKeyValueStorageProvider(), + new NoOpMetricsSystem(), + DataStorageConfiguration.DEFAULT_BONSAI_CONFIG); + + return new BonsaiWorldState( + storage, + new NoopBonsaiCachedMerkleTrieLoader(), + new NoOpBonsaiCachedWorldStorageManager(storage, EvmConfiguration.DEFAULT, new CodeCache()), + new NoOpTrieLogManager(), + EvmConfiguration.DEFAULT, + WorldStateConfig.createStatefulConfigWithTrie(), + new CodeCache()); + } + + private static Transaction mockTransaction() { + final Transaction transaction = mock(Transaction.class); + when(transaction.detachedCopy()).thenReturn(transaction); + return transaction; + } + + private static SlowBlockTracer newSlowBlockTracer() { + return new SlowBlockTracer(0, mock(BlockAwareOperationTracer.class)); + } + + private ParallelizedConcurrentTransactionProcessor createProcessorWithTracer( + final BlockProcessingContext bpc) { + return new ParallelizedConcurrentTransactionProcessor( + transactionProcessor, collisionDetector, bpc); + } + + // ---- BackgroundTracerFactory unit tests ---- + + @Test + void createBackgroundTracer_withSlowBlockTracer_createsMetricsTracer() { + // When blockProcessingContext has a SlowBlockTracer, the background tracer should be + // an EVMExecutionMetricsTracer (not NO_TRACING) + final SlowBlockTracer slowBlockTracer = newSlowBlockTracer(); + final BlockProcessingContext bpc = mock(BlockProcessingContext.class); + when(bpc.getOperationTracer()).thenReturn(slowBlockTracer); + + // Capture the tracer passed to processTransaction + when(transactionProcessor.processTransaction( + any(), any(), any(), any(), any(), any(), any(), any(), any())) + .thenAnswer( + invocation -> { + final OperationTracer tracer = invocation.getArgument(4, OperationTracer.class); + // The composed tracer should contain an EVMExecutionMetricsTracer (background) + // and the miningBeneficiaryTracer, NOT NO_TRACING + assertThat( + CompositeOperationTracer.hasTracer(tracer, EVMExecutionMetricsTracer.class)) + .as("Background tracer should contain EVMExecutionMetricsTracer") + .isTrue(); + return TransactionProcessingResult.successful( + Collections.emptyList(), + 0, + 0, + Bytes.EMPTY, + Optional.empty(), + ValidationResult.valid()); + }); + + final Transaction transaction = mockTransaction(); + final ParallelizedConcurrentTransactionProcessor processor = createProcessorWithTracer(bpc); + + processor.runAsyncBlock( + protocolContext, + blockHeader, + Collections.singletonList(transaction), + MINING_BENEFICIARY, + (__, ___) -> Hash.EMPTY, + BLOB_GAS_PRICE, + sameThreadExecutor, + Optional.empty(), + Optional.of(blockHeader)); + + // Verify processTransaction was actually called (and our assertion ran) + verify(transactionProcessor) + .processTransaction(any(), any(), any(), any(), any(), any(), any(), any(), any()); + } + + // ---- End-to-end integration tests through getProcessingResult ---- + + @Test + void consolidateTracerResults_mergesMetricsIntoSlowBlockTracer() { + final SlowBlockTracer slowBlockTracer = newSlowBlockTracer(); + slowBlockTracer.traceStartBlock(null, blockHeader, null, MINING_BENEFICIARY); + + final BlockProcessingContext bpc = mock(BlockProcessingContext.class); + when(bpc.getOperationTracer()).thenReturn(slowBlockTracer); + + final Transaction transaction = mockTransaction(); + final ParallelizedConcurrentTransactionProcessor processor = createProcessorWithTracer(bpc); + + processor.runAsyncBlock( + protocolContext, + blockHeader, + Collections.singletonList(transaction), + MINING_BENEFICIARY, + (__, ___) -> Hash.EMPTY, + BLOB_GAS_PRICE, + sameThreadExecutor, + Optional.empty(), + Optional.of(blockHeader)); + + final Optional result = + processor.getProcessingResult( + worldState, MINING_BENEFICIARY, transaction, 0, Optional.empty(), Optional.empty()); + + assertThat(result).isPresent(); + assertThat(result.get().isSuccessful()).isTrue(); + + assertThat(slowBlockTracer.getExecutionStats().getTransactionCount()) + .as("SlowBlockTracer tx_count should be incremented for confirmed parallel tx") + .isEqualTo(1); + } + + @Test + void consolidateTracerResults_incrementsTxCountForMultipleConfirmedTxs() { + final SlowBlockTracer slowBlockTracer = newSlowBlockTracer(); + slowBlockTracer.traceStartBlock(null, blockHeader, null, MINING_BENEFICIARY); + + final BlockProcessingContext bpc = mock(BlockProcessingContext.class); + when(bpc.getOperationTracer()).thenReturn(slowBlockTracer); + + final Transaction tx0 = mockTransaction(); + final Transaction tx1 = mockTransaction(); + final Transaction tx2 = mockTransaction(); + + final ParallelizedConcurrentTransactionProcessor processor = createProcessorWithTracer(bpc); + + processor.runAsyncBlock( + protocolContext, + blockHeader, + List.of(tx0, tx1, tx2), + MINING_BENEFICIARY, + (__, ___) -> Hash.EMPTY, + BLOB_GAS_PRICE, + sameThreadExecutor, + Optional.empty(), + Optional.of(blockHeader)); + + final List txs = List.of(tx0, tx1, tx2); + for (int i = 0; i < 3; i++) { + final Optional result = + processor.getProcessingResult( + worldState, MINING_BENEFICIARY, txs.get(i), i, Optional.empty(), Optional.empty()); + assertThat(result).isPresent(); + } + + assertThat(slowBlockTracer.getExecutionStats().getTransactionCount()) + .as("tx_count should equal number of confirmed parallel txs") + .isEqualTo(3); + } + + @Test + void consolidateTracerResults_doesNotIncrementTxCountForFailedTx() { + final SlowBlockTracer slowBlockTracer = newSlowBlockTracer(); + slowBlockTracer.traceStartBlock(null, blockHeader, null, MINING_BENEFICIARY); + + final BlockProcessingContext bpc = mock(BlockProcessingContext.class); + when(bpc.getOperationTracer()).thenReturn(slowBlockTracer); + + when(transactionProcessor.processTransaction( + any(), any(), any(), any(), any(), any(), any(), any(), any())) + .thenReturn( + TransactionProcessingResult.failed( + 0, + 0, + ValidationResult.invalid( + org.hyperledger.besu.ethereum.transaction.TransactionInvalidReason + .BLOB_GAS_PRICE_BELOW_CURRENT_BLOB_BASE_FEE), + Optional.of(Bytes.EMPTY), + Optional.empty(), + Optional.empty())); + + final Transaction transaction = mockTransaction(); + final ParallelizedConcurrentTransactionProcessor processor = createProcessorWithTracer(bpc); + + processor.runAsyncBlock( + protocolContext, + blockHeader, + Collections.singletonList(transaction), + MINING_BENEFICIARY, + (__, ___) -> Hash.EMPTY, + BLOB_GAS_PRICE, + sameThreadExecutor, + Optional.empty(), + Optional.of(blockHeader)); + + final Optional result = + processor.getProcessingResult( + worldState, MINING_BENEFICIARY, transaction, 0, Optional.empty(), Optional.empty()); + + assertThat(result).isEmpty(); + + assertThat(slowBlockTracer.getExecutionStats().getTransactionCount()) + .as("tx_count should not be incremented for failed tx") + .isEqualTo(0); + } + + @Test + void parallelExecution_mergesEvmMetricsFromMultipleThreads() throws Exception { + // Verify that EVM opcode metrics captured on separate threads are correctly merged + // into the main SlowBlockTracer after conflict-free parallel execution + final SlowBlockTracer slowBlockTracer = newSlowBlockTracer(); + slowBlockTracer.traceStartBlock(null, blockHeader, null, MINING_BENEFICIARY); + + final BlockProcessingContext bpc = mock(BlockProcessingContext.class); + when(bpc.getOperationTracer()).thenReturn(slowBlockTracer); + + // Each parallel thread needs its own world state — return a fresh one per call + final WorldStateArchive worldStateArchive = mock(WorldStateArchive.class); + when(worldStateArchive.getWorldState(any())) + .thenAnswer(invocation -> Optional.of(createEmptyWorldState())); + when(protocolContext.getWorldStateArchive()).thenReturn(worldStateArchive); + + // Mock processTransaction to simulate EVM opcode activity on the background tracer. + // The composed tracer (CompositeOperationTracer of EVMExecutionMetricsTracer + + // miningBeneficiaryTracer) + // is passed to processTransaction; simulating opcodes on it forwards to the + // EVMExecutionMetricsTracer. + when(transactionProcessor.processTransaction( + any(), any(), any(), any(), any(), any(), any(), any(), any())) + .thenAnswer( + invocation -> { + final OperationTracer tracer = invocation.getArgument(4, OperationTracer.class); + // Simulate 2 SLOAD operations per transaction + simulateOpcode(tracer, "SLOAD"); + simulateOpcode(tracer, "SLOAD"); + // Simulate 1 CALL per transaction + simulateOpcode(tracer, "CALL"); + + return TransactionProcessingResult.successful( + Collections.emptyList(), + 0, + 0, + Bytes.EMPTY, + Optional.empty(), + ValidationResult.valid()); + }); + + final Transaction tx0 = mockTransaction(); + final Transaction tx1 = mockTransaction(); + final Transaction tx2 = mockTransaction(); + + final ParallelizedConcurrentTransactionProcessor processor = createProcessorWithTracer(bpc); + + // Use a real thread pool for actual parallel execution + final ExecutorService threadPool = Executors.newFixedThreadPool(3); + try { + processor.runAsyncBlock( + protocolContext, + blockHeader, + List.of(tx0, tx1, tx2), + MINING_BENEFICIARY, + (__, ___) -> Hash.EMPTY, + BLOB_GAS_PRICE, + threadPool, + Optional.empty(), + Optional.of(blockHeader)); + + // Wait for all parallel tasks to complete before confirming + threadPool.shutdown(); + assertThat(threadPool.awaitTermination(30, java.util.concurrent.TimeUnit.SECONDS)) + .as("Thread pool should terminate within timeout") + .isTrue(); + + // Confirm all three transactions on the main thread + final List txs = List.of(tx0, tx1, tx2); + for (int i = 0; i < 3; i++) { + final Optional result = + processor.getProcessingResult( + worldState, MINING_BENEFICIARY, txs.get(i), i, Optional.empty(), Optional.empty()); + assertThat(result).as("Transaction %d should be confirmed", i).isPresent(); + } + } finally { + if (!threadPool.isShutdown()) { + threadPool.shutdown(); + } + } + + // Verify merged EVM metrics in executionStats: 3 txs x 2 SLOADs = 6, 3 txs x 1 CALL = 3 + assertThat(slowBlockTracer.getExecutionStats().getSloadCount()) + .as("SLOAD count should be sum across all parallel txs") + .isEqualTo(6); + assertThat(slowBlockTracer.getExecutionStats().getCallCount()) + .as("CALL count should be sum across all parallel txs") + .isEqualTo(3); + assertThat(slowBlockTracer.getExecutionStats().getSstoreCount()) + .as("SSTORE count should be zero (no SSTORE ops simulated)") + .isEqualTo(0); + + // Verify tx_count + assertThat(slowBlockTracer.getExecutionStats().getTransactionCount()) + .as("tx_count should equal number of confirmed parallel txs") + .isEqualTo(3); + } + + /** Simulates an EVM opcode by calling tracePostExecution with a mocked MessageFrame. */ + private static void simulateOpcode(final OperationTracer tracer, final String opcodeName) { + final MessageFrame frame = mock(MessageFrame.class); + final Operation operation = mock(Operation.class); + when(frame.getCurrentOperation()).thenReturn(operation); + when(operation.getName()).thenReturn(opcodeName); + tracer.tracePostExecution(frame, mock(Operation.OperationResult.class)); + } +} diff --git a/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/TransactionCollisionDetectorTest.java b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/TransactionCollisionDetectorTest.java index 997dd9171f9..dfceda83189 100644 --- a/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/TransactionCollisionDetectorTest.java +++ b/ethereum/core/src/test/java/org/hyperledger/besu/ethereum/mainnet/parallelization/TransactionCollisionDetectorTest.java @@ -31,6 +31,7 @@ import org.hyperledger.besu.evm.internal.EvmConfiguration; import java.math.BigInteger; +import java.util.Optional; import java.util.concurrent.ConcurrentHashMap; import org.apache.tuweni.bytes.Bytes; @@ -117,7 +118,8 @@ void testCollisionWithModifiedBalance() { collisionDetector.hasCollision( transaction, Address.ZERO, - new ParallelizedTransactionContext(trxUpdater, null, false, Wei.ZERO), + new ParallelizedTransactionContext( + trxUpdater, null, false, Wei.ZERO, Optional.empty(), Optional.empty()), bonsaiUpdater); assertTrue(hasCollision, "Expected a collision with the modified address"); @@ -146,7 +148,8 @@ void testCollisionWithModifiedNonce() { collisionDetector.hasCollision( transaction, Address.ZERO, - new ParallelizedTransactionContext(trxUpdater, null, false, Wei.ZERO), + new ParallelizedTransactionContext( + trxUpdater, null, false, Wei.ZERO, Optional.empty(), Optional.empty()), bonsaiUpdater); assertTrue(hasCollision, "Expected a collision with the modified address"); @@ -175,7 +178,8 @@ void testCollisionWithModifiedCode() { collisionDetector.hasCollision( transaction, Address.ZERO, - new ParallelizedTransactionContext(trxUpdater, null, false, Wei.ZERO), + new ParallelizedTransactionContext( + trxUpdater, null, false, Wei.ZERO, Optional.empty(), Optional.empty()), bonsaiUpdater); assertTrue(hasCollision, "Expected a collision with the modified address"); @@ -216,7 +220,8 @@ void testCollisionWithModifiedStorageRootAndSameSlot() { collisionDetector.hasCollision( transaction, Address.ZERO, - new ParallelizedTransactionContext(trxUpdater, null, false, Wei.ZERO), + new ParallelizedTransactionContext( + trxUpdater, null, false, Wei.ZERO, Optional.empty(), Optional.empty()), bonsaiUpdater); assertTrue(hasCollision, "Expected a collision with the modified address"); @@ -256,7 +261,8 @@ void testCollisionWithModifiedStorageRootNotSameSlot() { collisionDetector.hasCollision( transaction, Address.ZERO, - new ParallelizedTransactionContext(trxUpdater, null, false, Wei.ZERO), + new ParallelizedTransactionContext( + trxUpdater, null, false, Wei.ZERO, Optional.empty(), Optional.empty()), bonsaiUpdater); assertFalse( @@ -275,7 +281,8 @@ void testCollisionWithMiningBeneficiaryAddress() { collisionDetector.hasCollision( transaction, miningBeneficiary, - new ParallelizedTransactionContext(trxUpdater, null, false, Wei.ZERO), + new ParallelizedTransactionContext( + trxUpdater, null, false, Wei.ZERO, Optional.empty(), Optional.empty()), bonsaiUpdater); assertTrue(hasCollision, "Expected collision with the mining beneficiary address as sender"); @@ -300,7 +307,8 @@ void testCollisionWithAnotherMiningBeneficiaryAddress() { collisionDetector.hasCollision( transaction, miningBeneficiary, - new ParallelizedTransactionContext(trxUpdater, null, true, Wei.ZERO), + new ParallelizedTransactionContext( + trxUpdater, null, true, Wei.ZERO, Optional.empty(), Optional.empty()), bonsaiUpdater); assertTrue(hasCollision, "Expected collision with the read mining beneficiary address"); @@ -323,7 +331,8 @@ void testCollisionWithDeletedAddress() { collisionDetector.hasCollision( transaction, Address.ZERO, - new ParallelizedTransactionContext(trxUpdater, null, false, Wei.ZERO), + new ParallelizedTransactionContext( + trxUpdater, null, false, Wei.ZERO, Optional.empty(), Optional.empty()), bonsaiUpdater); assertTrue(hasCollision, "Expected a collision with the deleted address"); @@ -350,7 +359,8 @@ void testCollisionWithNoModifiedAddress() { collisionDetector.hasCollision( transaction, Address.ZERO, - new ParallelizedTransactionContext(trxUpdater, null, false, Wei.ZERO), + new ParallelizedTransactionContext( + trxUpdater, null, false, Wei.ZERO, Optional.empty(), Optional.empty()), bonsaiUpdater); assertFalse(hasCollision, "Expected no collision with the read address"); diff --git a/evm/src/main/java/org/hyperledger/besu/evm/tracing/EVMExecutionMetricsTracer.java b/evm/src/main/java/org/hyperledger/besu/evm/tracing/EVMExecutionMetricsTracer.java new file mode 100644 index 00000000000..9948ae8b23d --- /dev/null +++ b/evm/src/main/java/org/hyperledger/besu/evm/tracing/EVMExecutionMetricsTracer.java @@ -0,0 +1,286 @@ +/* + * Copyright contributors to Besu. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on + * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + */ +package org.hyperledger.besu.evm.tracing; + +import org.hyperledger.besu.datatypes.Address; +import org.hyperledger.besu.evm.frame.ExceptionalHaltReason; +import org.hyperledger.besu.evm.frame.MessageFrame; +import org.hyperledger.besu.evm.operation.Operation.OperationResult; + +import java.util.HashSet; +import java.util.Optional; +import java.util.Set; + +import org.apache.tuweni.bytes.Bytes; +import org.apache.tuweni.units.bigints.UInt256; + +/** + * An OperationTracer that collects execution metrics for EVM operations. + * + *

This tracer follows the standard Besu tracer pattern and is designed to be passed through + * method parameters like DebugOperationTracer. When instantiated, it tracks all available metrics: + * + *

    + *
  • EVM operation counts (SLOAD, SSTORE, CALL, CREATE) + *
  • State access operations (account/storage/code reads/writes) + *
  • EIP-7702 delegation operations + *
+ * + *

The decision of whether to collect metrics is made at tracer instantiation time, not during + * execution. If metrics collection is not desired, use {@link OperationTracer#NO_TRACING} instead + * of instantiating this tracer. + * + *

The metrics collected by this tracer can be aggregated across parallel transaction executions + * and provide detailed insights into block execution performance. + */ +public class EVMExecutionMetricsTracer implements OperationTracer { + + /** + * Container for EVM operation metrics. + * + *

This class holds only EVM opcode-level counters (SLOAD, SSTORE, CALL, CREATE). State-layer + * metrics (account/storage/code reads and writes, cache stats) are collected via the {@code + * StateMetricsCollector} threaded through the world state object graph. + */ + public static final class ExecutionMetrics { + // EVM operation counters + private int sloadCount; + private int sstoreCount; + private int callCount; + private int createCount; + + // Unique tracking sets + private final Set

uniqueAccountsTouched = new HashSet<>(); + private final Set uniqueStorageSlots = new HashSet<>(); + private final Set
uniqueContractsExecuted = new HashSet<>(); + + /** + * Record representing a unique storage slot identified by contract address and slot key. + * + * @param address the contract address + * @param slot the storage slot key + */ + public record StorageSlotKey(Address address, UInt256 slot) {} + + /** Creates a new ExecutionMetrics instance with all counters initialized to zero. */ + public ExecutionMetrics() { + // All primitive int fields are automatically initialized to 0 + } + + /** Reset all counters to zero. */ + public void reset() { + sloadCount = 0; + sstoreCount = 0; + callCount = 0; + createCount = 0; + uniqueAccountsTouched.clear(); + uniqueStorageSlots.clear(); + uniqueContractsExecuted.clear(); + } + + /** + * Merge metrics from another ExecutionMetrics instance into this one. + * + * @param other the metrics to merge + */ + public void merge(final ExecutionMetrics other) { + this.sloadCount += other.sloadCount; + this.sstoreCount += other.sstoreCount; + this.callCount += other.callCount; + this.createCount += other.createCount; + this.uniqueAccountsTouched.addAll(other.uniqueAccountsTouched); + this.uniqueStorageSlots.addAll(other.uniqueStorageSlots); + this.uniqueContractsExecuted.addAll(other.uniqueContractsExecuted); + } + + /** + * Returns the number of SLOAD operations executed. + * + * @return the number of SLOAD operations executed + */ + public int getSloadCount() { + return sloadCount; + } + + /** + * Returns the number of SSTORE operations executed. + * + * @return the number of SSTORE operations executed + */ + public int getSstoreCount() { + return sstoreCount; + } + + /** + * Returns the number of CALL operations executed. + * + * @return the number of CALL operations executed + */ + public int getCallCount() { + return callCount; + } + + /** + * Returns the number of CREATE operations executed. + * + * @return the number of CREATE operations executed + */ + public int getCreateCount() { + return createCount; + } + + /** + * Returns the set of unique accounts touched during execution. + * + * @return the set of unique account addresses + */ + public Set
getUniqueAccountsTouched() { + return uniqueAccountsTouched; + } + + /** + * Returns the set of unique storage slots accessed during execution. + * + * @return the set of unique storage slot keys + */ + public Set getUniqueStorageSlots() { + return uniqueStorageSlots; + } + + /** + * Returns the set of unique contracts executed during execution. + * + * @return the set of unique contract addresses + */ + public Set
getUniqueContractsExecuted() { + return uniqueContractsExecuted; + } + } + + private final ExecutionMetrics metrics = new ExecutionMetrics(); + + /** Create a new EVMExecutionMetricsTracer that tracks all available metrics. */ + public EVMExecutionMetricsTracer() { + // This tracer tracks all available execution metrics when instantiated + } + + @Override + public void traceContextEnter(final MessageFrame frame) { + final Address recipient = frame.getRecipientAddress(); + if (recipient != null) { + metrics.uniqueContractsExecuted.add(recipient); + metrics.uniqueAccountsTouched.add(recipient); + } + final Address sender = frame.getSenderAddress(); + if (sender != null) { + metrics.uniqueAccountsTouched.add(sender); + } + } + + @Override + public void tracePreExecution(final MessageFrame frame) { + final var operation = frame.getCurrentOperation(); + if (operation != null) { + final String name = operation.getName(); + if ("SLOAD".equals(name) || "SSTORE".equals(name)) { + final Address storageAddress = frame.getRecipientAddress(); + final UInt256 slotKey = UInt256.fromBytes(frame.getStackItem(0)); + metrics.uniqueStorageSlots.add( + new ExecutionMetrics.StorageSlotKey(storageAddress, slotKey)); + metrics.uniqueAccountsTouched.add(storageAddress); + } + } + } + + @Override + public void tracePostExecution(final MessageFrame frame, final OperationResult operationResult) { + // Track EVM operation based on the operation being executed + final var operation = frame.getCurrentOperation(); + if (operation != null) { + final String opcodeName = operation.getName(); + + switch (opcodeName) { + case "SLOAD": + metrics.sloadCount++; + break; + case "SSTORE": + metrics.sstoreCount++; + break; + case "CALL": + case "CALLCODE": + case "DELEGATECALL": + case "STATICCALL": + metrics.callCount++; + break; + case "CREATE": + case "CREATE2": + metrics.createCount++; + break; + default: + // No tracking needed for other operations + break; + } + } + } + + @Override + public void traceAccountCreationResult( + final MessageFrame frame, final Optional haltReason) { + // Creation operations are already tracked in tracePostExecution + } + + @Override + public void tracePrecompileCall( + final MessageFrame frame, final long gasRequirement, final Bytes output) { + // Precompile calls can be considered as special CALL operations + // But we may want to track them separately if needed + } + + /** + * Get the current execution metrics. + * + * @return the execution metrics + */ + public ExecutionMetrics getMetrics() { + return metrics; + } + + /** Reset all metrics to zero. */ + public void reset() { + metrics.reset(); + } + + /** + * Create a copy of the current metrics. + * + * @return a new ExecutionMetrics instance with copied values + */ + public ExecutionMetrics copyMetrics() { + final ExecutionMetrics copy = new ExecutionMetrics(); + copy.merge(metrics); + return copy; + } + + /** + * Merge metrics from another ExecutionMetricsTracer into this tracer. This method is used during + * parallel execution consolidation to combine metrics from background execution with the main + * block tracer. + * + * @param other the EVMExecutionMetricsTracer to merge metrics from + */ + public void mergeFrom(final EVMExecutionMetricsTracer other) { + this.metrics.merge(other.metrics); + } +} diff --git a/metrics/core/src/main/java/org/hyperledger/besu/metrics/BesuMetricCategory.java b/metrics/core/src/main/java/org/hyperledger/besu/metrics/BesuMetricCategory.java index 8e59e48aac9..c396f277792 100644 --- a/metrics/core/src/main/java/org/hyperledger/besu/metrics/BesuMetricCategory.java +++ b/metrics/core/src/main/java/org/hyperledger/besu/metrics/BesuMetricCategory.java @@ -56,7 +56,7 @@ public enum BesuMetricCategory implements MetricCategory { BLOCK_PROCESSING("block_processing"), /** Block access list besu metric category. */ BAL("bal"), - /** Block processing besu metric category. */ + /** Bonsai cache besu metric category. */ BONSAI_CACHE("bonsai_cache"); private static final Optional BESU_PREFIX = Optional.of("besu_");