From b6967eec18d882ef97a3f7896e610e88951e49bf Mon Sep 17 00:00:00 2001 From: DaniPopes <57450786+DaniPopes@users.noreply.github.com> Date: Sat, 2 Dec 2023 18:35:04 +0100 Subject: [PATCH 1/4] chore: add tracing to trace decoder --- crates/evm/traces/src/decoder/mod.rs | 75 +++++++++++--------- crates/evm/traces/src/decoder/precompiles.rs | 1 + 2 files changed, 44 insertions(+), 32 deletions(-) diff --git a/crates/evm/traces/src/decoder/mod.rs b/crates/evm/traces/src/decoder/mod.rs index 2866d8319a39..e6a2ea7c8aed 100644 --- a/crates/evm/traces/src/decoder/mod.rs +++ b/crates/evm/traces/src/decoder/mod.rs @@ -17,6 +17,7 @@ use foundry_evm_core::{ use itertools::Itertools; use once_cell::sync::OnceCell; use std::collections::{hash_map::Entry, BTreeMap, HashMap}; +use tracing::field; mod precompiles; @@ -223,14 +224,17 @@ impl CallTraceDecoder { } async fn decode_function(&self, trace: &mut CallTrace) { + let span = trace_span!("decode_function", label = field::Empty).entered(); + // Decode precompile if precompiles::decode(trace, 1) { - return + return; } // Set label if trace.label.is_none() { if let Some(label) = self.labels.get(&trace.address) { + span.record("label", label); trace.label = Some(label.clone()); } } @@ -245,8 +249,9 @@ impl CallTraceDecoder { let TraceCallData::Raw(cdata) = &trace.data else { return }; if trace.address == DEFAULT_CREATE2_DEPLOYER { + trace!("decoded as create2"); trace.data = TraceCallData::Decoded { signature: "create2".to_string(), args: vec![] }; - return + return; } if cdata.len() >= SELECTOR_LEN { @@ -273,15 +278,15 @@ impl CallTraceDecoder { let signature = if cdata.is_empty() && has_receive { "receive()" } else { "fallback()" }.into(); let args = if cdata.is_empty() { Vec::new() } else { vec![cdata.to_string()] }; + trace!(?signature, ?args, "decoded fallback data"); trace.data = TraceCallData::Decoded { signature, args }; if let TraceRetData::Raw(rdata) = &trace.output { if !trace.success { - trace.output = TraceRetData::Decoded(decode::decode_revert( - rdata, - Some(&self.errors), - Some(trace.status), - )); + let decoded = + decode::decode_revert(rdata, Some(&self.errors), Some(trace.status)); + trace!(?decoded, "decoded fallback output"); + trace.output = TraceRetData::Decoded(decoded); } } } @@ -305,8 +310,10 @@ impl CallTraceDecoder { } } } - trace.data = - TraceCallData::Decoded { signature: func.signature(), args: args.unwrap_or_default() }; + + let signature = func.signature(); + trace!(?signature, ?args, "decoded function input"); + trace.data = TraceCallData::Decoded { signature, args: args.unwrap_or_default() }; } /// Custom decoding for cheatcode inputs. @@ -377,34 +384,36 @@ impl CallTraceDecoder { /// Decodes a function's output into the given trace. fn decode_function_output(&self, trace: &mut CallTrace, funcs: &[Function]) { let TraceRetData::Raw(data) = &trace.output else { return }; + let mut s = None; if trace.success { if trace.address == CHEATCODE_ADDRESS { - if let Some(decoded) = - funcs.iter().find_map(|func| self.decode_cheatcode_outputs(func)) - { - trace.output = TraceRetData::Decoded(decoded); - return - } + s = funcs.iter().find_map(|func| self.decode_cheatcode_outputs(func)); } - if let Some(values) = - funcs.iter().find_map(|func| func.abi_decode_output(data, false).ok()) - { - // Functions coming from an external database do not have any outputs specified, - // and will lead to returning an empty list of values. - if values.is_empty() { - return + if !s.is_none() { + if let Some(values) = + funcs.iter().find_map(|func| func.abi_decode_output(data, false).ok()) + { + // Functions coming from an external database do not have any outputs specified, + // and will lead to returning an empty list of values. + if !values.is_empty() { + s = Some( + values + .iter() + .map(|value| self.apply_label(value)) + .format(", ") + .to_string(), + ); + } } - trace.output = TraceRetData::Decoded( - values.iter().map(|value| self.apply_label(value)).format(", ").to_string(), - ); } } else { - trace.output = TraceRetData::Decoded(decode::decode_revert( - data, - Some(&self.errors), - Some(trace.status), - )); + s = decode::maybe_decode_revert(data, Some(&self.errors), Some(trace.status)); + } + + if let Some(decoded) = s { + trace!(?decoded, "decoded function output"); + trace.output = TraceRetData::Decoded(decoded); } } @@ -440,8 +449,10 @@ impl CallTraceDecoder { for event in events { if let Ok(decoded) = event.decode_log(raw_log, false) { let params = reconstruct_params(event, &decoded); + let name = event.name.clone(); + trace!(?name, ?params, "decoded event"); *log = TraceLog::Decoded( - event.name.clone(), + name, params .into_iter() .zip(event.inputs.iter()) @@ -452,7 +463,7 @@ impl CallTraceDecoder { }) .collect(), ); - break + break; } } } diff --git a/crates/evm/traces/src/decoder/precompiles.rs b/crates/evm/traces/src/decoder/precompiles.rs index a1b3f9425034..801ec92df844 100644 --- a/crates/evm/traces/src/decoder/precompiles.rs +++ b/crates/evm/traces/src/decoder/precompiles.rs @@ -76,6 +76,7 @@ pub(super) fn decode(trace: &mut CallTrace, _chain_id: u64) -> bool { // TODO: Other chain precompiles + trace!(?signature, ?args, "decoded precompile call"); trace.data = TraceCallData::Decoded { signature: signature.to_string(), args }; trace.label = Some("PRECOMPILES".into()); From ddaf36fabb916b009132df5bc71ea788e60cd626 Mon Sep 17 00:00:00 2001 From: DaniPopes <57450786+DaniPopes@users.noreply.github.com> Date: Sat, 2 Dec 2023 19:06:36 +0100 Subject: [PATCH 2/4] cleanup hh console --- crates/evm/core/src/abi/hardhat_console.rs | 40 ++++++++++++++-------- crates/evm/core/src/abi/mod.rs | 2 +- crates/evm/evm/src/inspectors/logs.rs | 4 +-- 3 files changed, 28 insertions(+), 18 deletions(-) diff --git a/crates/evm/core/src/abi/hardhat_console.rs b/crates/evm/core/src/abi/hardhat_console.rs index 955ebc087f9d..12e5cfc4cf45 100644 --- a/crates/evm/core/src/abi/hardhat_console.rs +++ b/crates/evm/core/src/abi/hardhat_console.rs @@ -1,3 +1,4 @@ +use alloy_primitives::Selector; use alloy_sol_types::sol; use foundry_macros::ConsoleFmt; use once_cell::sync::Lazy; @@ -10,24 +11,33 @@ sol!( "src/abi/HardhatConsole.json" ); -/// If the input starts with a known `hardhat/console.log` `uint` selector, then this will replace -/// it with the selector `abigen!` bindings expect. -pub fn patch_hardhat_console_selector(input: &mut [u8]) { - if let Some(selector) = input.get_mut(..4) { - let selector: &mut [u8; 4] = selector.try_into().unwrap(); - if let Some(generated_selector) = HARDHAT_CONSOLE_SELECTOR_PATCHES.get(selector) { - *selector = *generated_selector; - } +/// Patches the given Hardhat `console` function selector to its ABI-normalized form. +/// +/// See `HARDHAT_CONSOLE_SELECTOR_PATCHES` for more details. +pub fn patch_hh_console_selector(input: &mut [u8]) { + if let Some(selector) = hh_console_selector(input) { + input[..4].copy_from_slice(selector.as_slice()); + } +} + +/// Returns the ABI-normalized selector for the given Hardhat `console` function selector. +/// +/// See `HARDHAT_CONSOLE_SELECTOR_PATCHES` for more details. +pub fn hh_console_selector(input: &[u8]) -> Option<&'static Selector> { + if let Some(selector) = input.get(..4) { + let selector: &[u8; 4] = selector.try_into().unwrap(); + HARDHAT_CONSOLE_SELECTOR_PATCHES.get(selector).map(Into::into) + } else { + None } } -/// This contains a map with all the `hardhat/console.log` log selectors that use `uint` or `int` -/// as key and the selector of the call with `uint256`, +/// Maps all the `hardhat/console.log` log selectors that use the legacy ABI (`int`, `uint`) to +/// their normalized counterparts (`int256`, `uint256`). /// -/// This is a bit terrible but a workaround for the differing selectors used by hardhat and the call -/// bindings which `abigen!` creates. `hardhat/console.log` logs its events in functions that accept -/// `uint` manually as `abi.encodeWithSignature("log(int)", p0)`, but `abigen!` uses `uint256` for -/// its call bindings (`HardhatConsoleCalls`) as generated by solc. +/// `hardhat/console.log` logs its events manually, and in functions that accept integers they're +/// encoded as `abi.encodeWithSignature("log(int)", p0)`, which is not the canonical ABI encoding +/// for `int` that Solc (and [`sol!`]) uses. static HARDHAT_CONSOLE_SELECTOR_PATCHES: Lazy> = Lazy::new(|| { HashMap::from([ // log(bool,uint256,uint256,address) @@ -549,7 +559,7 @@ mod tests { fn hardhat_console_patch() { for (hh, generated) in HARDHAT_CONSOLE_SELECTOR_PATCHES.iter() { let mut hh = *hh; - patch_hardhat_console_selector(&mut hh); + patch_hh_console_selector(&mut hh); assert_eq!(hh, *generated); } } diff --git a/crates/evm/core/src/abi/mod.rs b/crates/evm/core/src/abi/mod.rs index 6fba308b2d26..879c9ab4b244 100644 --- a/crates/evm/core/src/abi/mod.rs +++ b/crates/evm/core/src/abi/mod.rs @@ -6,4 +6,4 @@ mod console; pub use console::Console; mod hardhat_console; -pub use hardhat_console::{patch_hardhat_console_selector, HardhatConsole}; +pub use hardhat_console::{hh_console_selector, patch_hh_console_selector, HardhatConsole}; diff --git a/crates/evm/evm/src/inspectors/logs.rs b/crates/evm/evm/src/inspectors/logs.rs index 466cf9fee7b8..f517f042e7ed 100644 --- a/crates/evm/evm/src/inspectors/logs.rs +++ b/crates/evm/evm/src/inspectors/logs.rs @@ -3,7 +3,7 @@ use alloy_sol_types::{SolEvent, SolInterface, SolValue}; use ethers_core::types::Log; use foundry_common::{fmt::ConsoleFmt, types::ToEthers, ErrorExt}; use foundry_evm_core::{ - abi::{patch_hardhat_console_selector, Console, HardhatConsole}, + abi::{patch_hh_console_selector, Console, HardhatConsole}, constants::HARDHAT_CONSOLE_ADDRESS, }; use revm::{ @@ -23,7 +23,7 @@ pub struct LogCollector { impl LogCollector { fn hardhat_log(&mut self, mut input: Vec) -> (InstructionResult, Bytes) { // Patch the Hardhat-style selector (`uint` instead of `uint256`) - patch_hardhat_console_selector(&mut input); + patch_hh_console_selector(&mut input); // Decode the call let decoded = match HardhatConsole::HardhatConsoleCalls::abi_decode(&input, false) { From fbe201294f9e5e021259d802331561d244db8751 Mon Sep 17 00:00:00 2001 From: DaniPopes <57450786+DaniPopes@users.noreply.github.com> Date: Sat, 2 Dec 2023 19:41:50 +0100 Subject: [PATCH 3/4] feat: decode Hardhat console logs in traces --- crates/evm/core/src/abi/hardhat_console.rs | 6 +-- crates/evm/core/src/abi/mod.rs | 5 ++- crates/evm/traces/src/decoder/mod.rs | 32 ++++++++++++--- crates/forge/tests/it/repros.rs | 46 ++++++++++++++++++++++ testdata/repros/Issue6501.t.sol | 14 +++++++ 5 files changed, 93 insertions(+), 10 deletions(-) create mode 100644 testdata/repros/Issue6501.t.sol diff --git a/crates/evm/core/src/abi/hardhat_console.rs b/crates/evm/core/src/abi/hardhat_console.rs index 12e5cfc4cf45..4b9aa3ba2a89 100644 --- a/crates/evm/core/src/abi/hardhat_console.rs +++ b/crates/evm/core/src/abi/hardhat_console.rs @@ -13,7 +13,7 @@ sol!( /// Patches the given Hardhat `console` function selector to its ABI-normalized form. /// -/// See `HARDHAT_CONSOLE_SELECTOR_PATCHES` for more details. +/// See [`HARDHAT_CONSOLE_SELECTOR_PATCHES`] for more details. pub fn patch_hh_console_selector(input: &mut [u8]) { if let Some(selector) = hh_console_selector(input) { input[..4].copy_from_slice(selector.as_slice()); @@ -22,7 +22,7 @@ pub fn patch_hh_console_selector(input: &mut [u8]) { /// Returns the ABI-normalized selector for the given Hardhat `console` function selector. /// -/// See `HARDHAT_CONSOLE_SELECTOR_PATCHES` for more details. +/// See [`HARDHAT_CONSOLE_SELECTOR_PATCHES`] for more details. pub fn hh_console_selector(input: &[u8]) -> Option<&'static Selector> { if let Some(selector) = input.get(..4) { let selector: &[u8; 4] = selector.try_into().unwrap(); @@ -38,7 +38,7 @@ pub fn hh_console_selector(input: &[u8]) -> Option<&'static Selector> { /// `hardhat/console.log` logs its events manually, and in functions that accept integers they're /// encoded as `abi.encodeWithSignature("log(int)", p0)`, which is not the canonical ABI encoding /// for `int` that Solc (and [`sol!`]) uses. -static HARDHAT_CONSOLE_SELECTOR_PATCHES: Lazy> = Lazy::new(|| { +pub static HARDHAT_CONSOLE_SELECTOR_PATCHES: Lazy> = Lazy::new(|| { HashMap::from([ // log(bool,uint256,uint256,address) ([241, 97, 178, 33], [0, 221, 135, 185]), diff --git a/crates/evm/core/src/abi/mod.rs b/crates/evm/core/src/abi/mod.rs index 879c9ab4b244..39566cf796fc 100644 --- a/crates/evm/core/src/abi/mod.rs +++ b/crates/evm/core/src/abi/mod.rs @@ -6,4 +6,7 @@ mod console; pub use console::Console; mod hardhat_console; -pub use hardhat_console::{hh_console_selector, patch_hh_console_selector, HardhatConsole}; +pub use hardhat_console::{ + hh_console_selector, patch_hh_console_selector, HardhatConsole, + HARDHAT_CONSOLE_SELECTOR_PATCHES, +}; diff --git a/crates/evm/traces/src/decoder/mod.rs b/crates/evm/traces/src/decoder/mod.rs index e6a2ea7c8aed..a1740a1ef061 100644 --- a/crates/evm/traces/src/decoder/mod.rs +++ b/crates/evm/traces/src/decoder/mod.rs @@ -7,7 +7,7 @@ use alloy_json_abi::{Event, Function, JsonAbi as Abi}; use alloy_primitives::{Address, Selector, B256}; use foundry_common::{abi::get_indexed_event, fmt::format_token, SELECTOR_LEN}; use foundry_evm_core::{ - abi::{Console, HardhatConsole, Vm}, + abi::{Console, HardhatConsole, Vm, HARDHAT_CONSOLE_SELECTOR_PATCHES}, constants::{ CALLER, CHEATCODE_ADDRESS, DEFAULT_CREATE2_DEPLOYER, HARDHAT_CONSOLE_ADDRESS, TEST_CONTRACT_ADDRESS, @@ -118,6 +118,23 @@ impl CallTraceDecoder { } fn init() -> Self { + /// All functions from the Hardhat console ABI. + /// + /// See [`HARDHAT_CONSOLE_SELECTOR_PATCHES`] for more details. + fn hh_funcs() -> impl Iterator { + let functions = HardhatConsole::abi::functions(); + let mut functions: Vec<_> = + functions.into_values().flatten().map(|func| (func.selector(), func)).collect(); + let len = functions.len(); + // `functions` is the list of all patched functions; duplicate the unpatched ones + for (unpatched, patched) in HARDHAT_CONSOLE_SELECTOR_PATCHES.iter() { + if let Some((_, func)) = functions[..len].iter().find(|(sel, _)| sel == patched) { + functions.push((unpatched.into(), func.clone())); + } + } + functions.into_iter() + } + Self { contracts: Default::default(), @@ -130,11 +147,14 @@ impl CallTraceDecoder { ] .into(), - functions: HardhatConsole::abi::functions() - .into_values() - .chain(Vm::abi::functions().into_values()) - .flatten() - .map(|func| (func.selector(), vec![func])) + functions: hh_funcs() + .chain( + Vm::abi::functions() + .into_values() + .flatten() + .map(|func| (func.selector(), func)), + ) + .map(|(selector, func)| (selector, vec![func])) .collect(), events: Console::abi::events() diff --git a/crates/forge/tests/it/repros.rs b/crates/forge/tests/it/repros.rs index a472123a615a..36ee48d390d3 100644 --- a/crates/forge/tests/it/repros.rs +++ b/crates/forge/tests/it/repros.rs @@ -5,6 +5,11 @@ use alloy_primitives::{address, Address}; use ethers_core::abi::{Event, EventParam, Log, LogParam, ParamType, RawLog, Token}; use forge::result::TestStatus; use foundry_config::{fs_permissions::PathPermission, Config, FsPermissions}; +use foundry_evm::{ + constants::HARDHAT_CONSOLE_ADDRESS, + traces::{CallTraceDecoder, TraceCallData, TraceKind}, + utils::CallKind, +}; use foundry_test_utils::Filter; /// Creates a test that runs `testdata/repros/Issue{issue}.t.sol`. @@ -214,3 +219,44 @@ test_repro!(6355, false, None, |res| { // https://github.com/foundry-rs/foundry/issues/6437 test_repro!(6437); + +// Test we decode Hardhat console logs AND traces correctly. +// https://github.com/foundry-rs/foundry/issues/6501 +test_repro!(6501, false, None, |res| { + let mut res = res.remove("repros/Issue6501.t.sol:Issue6501Test").unwrap(); + let test = res.test_results.remove("test_hhLogs()").unwrap(); + assert_eq!(test.status, TestStatus::Success); + assert_eq!(test.decoded_logs, ["a".to_string(), "1".to_string(), "b 2".to_string()]); + + let (kind, mut traces) = test.traces[1].clone(); + assert_eq!(kind, TraceKind::Execution); + + let test_call = traces.arena.first().unwrap(); + assert_eq!(test_call.idx, 0); + assert_eq!(test_call.children, [1, 2, 3]); + assert_eq!(test_call.trace.depth, 0); + assert!(test_call.trace.success); + + CallTraceDecoder::new().decode(&mut traces).await; + + let expected = [ + ("log(string)", vec!["\"a\""]), + ("log(uint256)", vec!["1"]), + ("log(string,uint256)", vec!["\"b\"", "2"]), + ]; + for (node, expected) in traces.arena[1..=3].iter().zip(expected) { + let trace = &node.trace; + assert_eq!(trace.kind, CallKind::StaticCall); + assert_eq!(trace.address, HARDHAT_CONSOLE_ADDRESS); + assert_eq!(trace.label, Some("console".into())); + assert_eq!(trace.depth, 1); + assert!(trace.success); + assert_eq!( + trace.data, + TraceCallData::Decoded { + signature: expected.0.into(), + args: expected.1.into_iter().map(ToOwned::to_owned).collect(), + } + ); + } +}); diff --git a/testdata/repros/Issue6501.t.sol b/testdata/repros/Issue6501.t.sol new file mode 100644 index 000000000000..392f0f1abc8a --- /dev/null +++ b/testdata/repros/Issue6501.t.sol @@ -0,0 +1,14 @@ +// SPDX-License-Identifier: MIT OR Apache-2.0 +pragma solidity 0.8.18; + +import "ds-test/test.sol"; +import "../logs/console.sol"; + +// https://github.com/foundry-rs/foundry/issues/6501 +contract Issue6501Test is DSTest { + function test_hhLogs() public { + console.log("a"); + console.log(uint256(1)); + console.log("b", uint256(2)); + } +} From e445b2b60b1fec341d096b252550c88f7dcfcf03 Mon Sep 17 00:00:00 2001 From: DaniPopes <57450786+DaniPopes@users.noreply.github.com> Date: Sat, 2 Dec 2023 19:51:35 +0100 Subject: [PATCH 4/4] chore: clippy --- crates/evm/traces/src/decoder/mod.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/crates/evm/traces/src/decoder/mod.rs b/crates/evm/traces/src/decoder/mod.rs index a1740a1ef061..3c4c1d766212 100644 --- a/crates/evm/traces/src/decoder/mod.rs +++ b/crates/evm/traces/src/decoder/mod.rs @@ -410,7 +410,7 @@ impl CallTraceDecoder { s = funcs.iter().find_map(|func| self.decode_cheatcode_outputs(func)); } - if !s.is_none() { + if s.is_some() { if let Some(values) = funcs.iter().find_map(|func| func.abi_decode_output(data, false).ok()) {