diff --git a/Cargo.lock b/Cargo.lock index d6e58c2ffe..26017be914 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -6418,6 +6418,7 @@ dependencies = [ "ethereum-types", "evm-tracing-events", "hex", + "log", "moonbeam-rpc-primitives-debug", "parity-scale-codec", "serde", diff --git a/client/evm-tracing/Cargo.toml b/client/evm-tracing/Cargo.toml index a6e3b7ca5e..bba2e6e882 100644 --- a/client/evm-tracing/Cargo.toml +++ b/client/evm-tracing/Cargo.toml @@ -12,6 +12,7 @@ ethereum-types = { workspace = true, features = [ "std" ] } hex = { workspace = true, features = [ "serde" ] } serde = { workspace = true, features = [ "derive", "std" ] } serde_json = { workspace = true, default-features = true } +log = { workspace = true } # Moonbeam evm-tracing-events = { workspace = true, features = [ "std" ] } diff --git a/client/evm-tracing/src/formatters/call_tracer.rs b/client/evm-tracing/src/formatters/call_tracer.rs index ce9b833a2a..a2a42ac475 100644 --- a/client/evm-tracing/src/formatters/call_tracer.rs +++ b/client/evm-tracing/src/formatters/call_tracer.rs @@ -36,12 +36,18 @@ impl super::ResponseFormatter for Formatter { type Listener = Listener; type Response = Vec; - fn format(mut listener: Listener) -> Option> { - // Remove empty BTreeMaps pushed to `entries`. - // I.e. InvalidNonce or other pallet_evm::runner exits - listener.entries.retain(|x| !x.is_empty()); + fn format(listener: Listener) -> Option> { let mut traces = Vec::new(); for (eth_tx_index, entry) in listener.entries.iter().enumerate() { + // Skip empty BTreeMaps pushed to `entries`. + // I.e. InvalidNonce or other pallet_evm::runner exits + if entry.is_empty() { + log::debug!( + target: "tracing", + "Empty trace entry with transaction index {}, skipping...", eth_tx_index + ); + continue; + } let mut result: Vec = entry .into_iter() .map(|(_, it)| { diff --git a/client/evm-tracing/src/formatters/trace_filter.rs b/client/evm-tracing/src/formatters/trace_filter.rs index 27dff285fd..f3ae3307f6 100644 --- a/client/evm-tracing/src/formatters/trace_filter.rs +++ b/client/evm-tracing/src/formatters/trace_filter.rs @@ -30,12 +30,18 @@ impl super::ResponseFormatter for Formatter { type Listener = Listener; type Response = Vec; - fn format(mut listener: Listener) -> Option> { - // Remove empty BTreeMaps pushed to `entries`. - // I.e. InvalidNonce or other pallet_evm::runner exits - listener.entries.retain(|x| !x.is_empty()); + fn format(listener: Listener) -> Option> { let mut traces = Vec::new(); for (eth_tx_index, entry) in listener.entries.iter().enumerate() { + // Skip empty BTreeMaps pushed to `entries`. + // I.e. InvalidNonce or other pallet_evm::runner exits + if entry.is_empty() { + log::debug!( + target: "tracing", + "Empty trace entry with transaction index {}, skipping...", eth_tx_index + ); + continue; + } let mut tx_traces: Vec<_> = entry .into_iter() .map(|(_, trace)| match trace.inner.clone() { diff --git a/client/rpc/trace/src/lib.rs b/client/rpc/trace/src/lib.rs index 79c84f8160..fef940efc6 100644 --- a/client/rpc/trace/src/lib.rs +++ b/client/rpc/trace/src/lib.rs @@ -803,7 +803,7 @@ where substrate_hash, e ) })? - .ok_or_else(|| format!("Subtrate block {} don't exist", substrate_hash))?; + .ok_or_else(|| format!("Substrate block {} don't exist", substrate_hash))?; let height = *block_header.number(); let substrate_parent_hash = *block_header.parent_hash(); @@ -890,6 +890,7 @@ where .map_err(|e| format!("Blockchain error when replaying block {} : {:?}", height, e))? .map_err(|e| { tracing::warn!( + target: "tracing", "Internal runtime error when replaying block {} : {:?}", height, e @@ -935,6 +936,7 @@ where } None => { log::warn!( + target: "tracing", "A trace in block {} does not map to any known ethereum transaction. Trace: {:?}", height, trace, diff --git a/runtime/common/src/apis.rs b/runtime/common/src/apis.rs index 61f8332d3d..ed33b7afa9 100644 --- a/runtime/common/src/apis.rs +++ b/runtime/common/src/apis.rs @@ -173,6 +173,14 @@ macro_rules! impl_runtime_apis_plus_common { for ext in extrinsics.into_iter() { let _ = match &ext.0.function { RuntimeCall::Ethereum(transact { transaction }) => { + + // Reset the previously consumed weight when tracing ethereum transactions. + // This is necessary because EVM tracing introduces additional + // (ref_time) overhead, which differs from the production runtime behavior. + // Without resetting the block weight, the extra tracing overhead could + // leading to some transactions to incorrectly fail during tracing. + frame_system::BlockWeight::::kill(); + if transaction == traced_transaction { EvmTracer::new().trace(|| Executive::apply_extrinsic(ext)); return Ok(()); @@ -249,16 +257,47 @@ macro_rules! impl_runtime_apis_plus_common { for ext in extrinsics.into_iter() { match &ext.0.function { RuntimeCall::Ethereum(transact { transaction }) => { - if known_transactions.contains(&transaction.hash()) { + + // Reset the previously consumed weight when tracing multiple transactions. + // This is necessary because EVM tracing introduces additional + // (ref_time) overhead, which differs from the production runtime behavior. + // Without resetting the block weight, the extra tracing overhead could + // leading to some transactions to incorrectly fail during tracing. + frame_system::BlockWeight::::kill(); + + let tx_hash = &transaction.hash(); + if known_transactions.contains(&tx_hash) { // Each known extrinsic is a new call stack. EvmTracer::emit_new(); - EvmTracer::new().trace(|| Executive::apply_extrinsic(ext)); + EvmTracer::new().trace(|| { + if let Err(err) = Executive::apply_extrinsic(ext) { + log::debug!( + target: "tracing", + "Could not trace eth transaction (hash: {}): {:?}", + &tx_hash, + err + ); + } + }); } else { - let _ = Executive::apply_extrinsic(ext); + if let Err(err) = Executive::apply_extrinsic(ext) { + log::debug!( + target: "tracing", + "Failed to apply eth extrinsic (hash: {}): {:?}", + &tx_hash, + err + ); + } } } _ => { - let _ = Executive::apply_extrinsic(ext); + if let Err(err) = Executive::apply_extrinsic(ext) { + log::debug!( + target: "tracing", + "Failed to apply non-eth extrinsic: {:?}", + err + ); + } } }; } diff --git a/test/suites/tracing-tests/test-trace-filter-weight-limits.ts b/test/suites/tracing-tests/test-trace-filter-weight-limits.ts new file mode 100644 index 0000000000..23cc50c124 --- /dev/null +++ b/test/suites/tracing-tests/test-trace-filter-weight-limits.ts @@ -0,0 +1,76 @@ +import { afterAll, customDevRpcRequest, describeSuite, expect } from "@moonwall/cli"; +import { ALITH_ADDRESS, createEthersTransaction } from "@moonwall/util"; +import { sleep } from "../../helpers"; +import { encodeFunctionData } from "viem"; + +describeSuite({ + id: "T18", + title: "Trace filter - Test block weight limits with evm-tracing enabled", + foundationMethods: "dev", + testCases: ({ context, it }) => { + afterAll(async () => { + await sleep(500); // Add sleep to allow for graceful teardown + }); + + it({ + id: "T01", + title: + "The number of unique transaction traces should be the same as the number of transactions included in a block", + test: async function () { + const { abi, contractAddress } = await context.deployContract!("BloatedContract"); + + let nonce = await context.viem().getTransactionCount({ address: ALITH_ADDRESS }); + const tx = []; + for (let i = 0; i < 500; i++) { + tx.push( + await createEthersTransaction(context, { + to: contractAddress, + data: encodeFunctionData({ abi, functionName: "doSomething", args: [] }), + gasLimit: 10_000_000, + nonce: nonce++, + }) + ); + } + + const substrateBlock = await context.createBlock(tx, { allowFailures: false }); + const txHashes = (substrateBlock.result || []) + .filter((result) => result.successful) + .map((result) => result.hash); + + const blockNumber = (await context.polkadotJs().query.ethereum.currentBlock()) + .unwrap() + .header.number.toNumber(); + const blockNumberHex = blockNumber.toString(16); + const ethBlock = await customDevRpcRequest("eth_getBlockByNumber", [blockNumberHex, false]); + + // Confirm that all transactions were included in the ethereum block + expect(ethBlock.transactions.length).to.equal(txHashes.length); + + const traceFilterResponse = await customDevRpcRequest("trace_filter", [ + { + fromBlock: blockNumberHex, + toBlock: blockNumberHex, + }, + ]); + const uniqueTxsInTraces = Object.keys( + traceFilterResponse.reduce( + (prev, cur) => ({ + ...prev, + [cur.transactionHash]: true, + }), + {} + ) + ); + + console.log(` + Ethereum transactions count: ${ethBlock.transactions.length}, + Ethereum traces count: ${traceFilterResponse.length}, + Ethereum unique transactions in traces count: ${uniqueTxsInTraces.length} + `); + + // Assert that all eth transactions were traced + expect(ethBlock.transactions.length).to.equal(uniqueTxsInTraces.length); + }, + }); + }, +});