From 08e69236d9bd783ae870cbcfdb6277398d80f4a5 Mon Sep 17 00:00:00 2001 From: Andrei Silviu Dragnea Date: Tue, 10 Oct 2023 12:58:56 +0300 Subject: [PATCH] NDEV-2252: Clean up tracer implementation (#208) * NDEV-2252: Use preserve_order serde_json feature * NDEV-2252: Make StructLog and StructLoggerResult Geth-compatible NDEV-2252: Fix StructLog field order NDEV-2252: Fix StructLoggerResult field order NDEV-2252: Output storage only on SLOAD and SSTORE opcodes NDEV-2252: Output storage in hex format without 0x prefix NDEV-2252: Output memory in hex format without 0x prefix NDEV-2252: Add StructLoggerResult serialization tests NDEV-2252: Fix StructLog format NDEV-2252: Add github link * NDEV-2252: Make tracer_config optional * NDEV-2252: Remove unused trace Events * NDEV-2252: Add more links to Geth structs --- evm_loader/Cargo.lock | 5 +- evm_loader/api/Cargo.toml | 2 +- evm_loader/cli/Cargo.toml | 2 +- evm_loader/lib/Cargo.toml | 2 +- evm_loader/program/Cargo.toml | 2 +- evm_loader/program/src/evm/memory.rs | 68 +------- evm_loader/program/src/evm/mod.rs | 30 +--- evm_loader/program/src/evm/opcode.rs | 1 - evm_loader/program/src/evm/stack.rs | 22 +-- evm_loader/program/src/evm/tracing/mod.rs | 18 +- .../src/evm/tracing/tracers/struct_logger.rs | 155 +++++++++++++----- 11 files changed, 143 insertions(+), 164 deletions(-) diff --git a/evm_loader/Cargo.lock b/evm_loader/Cargo.lock index 1d1b1b288..1cbfcb4d2 100644 --- a/evm_loader/Cargo.lock +++ b/evm_loader/Cargo.lock @@ -3998,10 +3998,11 @@ dependencies = [ [[package]] name = "serde_json" -version = "1.0.105" +version = "1.0.107" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "693151e1ac27563d6dbcec9dee9fbd5da8539b20fa14ad3752b2e6d363ace360" +checksum = "6b420ce6e3d8bd882e9b243c6eed35dbc9a6110c9769e74b584e0d68d1f20c65" dependencies = [ + "indexmap 2.0.0", "itoa", "ryu", "serde", diff --git a/evm_loader/api/Cargo.toml b/evm_loader/api/Cargo.toml index 5c2ab3447..a68c3a4e6 100644 --- a/evm_loader/api/Cargo.toml +++ b/evm_loader/api/Cargo.toml @@ -11,7 +11,7 @@ evm-loader = { path = "../program", default-features = false, features = ["log"] solana-sdk = "=1.16.15" solana-client = "=1.16.15" serde = "1.0.186" -serde_json = "1.0.85" +serde_json = { version = "1.0.107", features = ["preserve_order"] } ethnum = { version = "1.4", default-features = false, features = ["serde"] } tokio = { version = "1", features = ["full"] } tracing = "0.1" diff --git a/evm_loader/cli/Cargo.toml b/evm_loader/cli/Cargo.toml index 9dd6cbffd..3304562fa 100644 --- a/evm_loader/cli/Cargo.toml +++ b/evm_loader/cli/Cargo.toml @@ -14,7 +14,7 @@ solana-clap-utils = "=1.16.15" solana-cli-config = "=1.16.15" hex = "0.4.2" serde = "1.0.186" -serde_json = "1.0.85" +serde_json = { version = "1.0.107", features = ["preserve_order"] } log = "0.4.17" fern = "0.6" ethnum = { version = "1.4", default-features = false, features = ["serde"] } diff --git a/evm_loader/lib/Cargo.toml b/evm_loader/lib/Cargo.toml index 5f4e56d8d..49bc51c39 100644 --- a/evm_loader/lib/Cargo.toml +++ b/evm_loader/lib/Cargo.toml @@ -21,7 +21,7 @@ spl-associated-token-account = { version = "~1.1", default-features = false, fea bs58 = "0.4.0" hex = "0.4.2" serde = "1.0.186" -serde_json = "1.0.105" +serde_json = { version = "1.0.107", features = ["preserve_order"] } log = "0.4.17" rand = "0.8" ethnum = { version = "1.4", default-features = false, features = ["serde"] } diff --git a/evm_loader/program/Cargo.toml b/evm_loader/program/Cargo.toml index 800269a84..3aa57a42e 100644 --- a/evm_loader/program/Cargo.toml +++ b/evm_loader/program/Cargo.toml @@ -51,7 +51,7 @@ borsh = "0.9" bincode = "1" serde_bytes = "0.11.12" serde = { version = "1.0.186", default-features = false, features = ["derive", "rc"] } -serde_json = { version = "1.0.105", optional = true } +serde_json = { version = "1.0.107", features = ["preserve_order"], optional = true } ethnum = { version = "1.4", default-features = false, features = ["serde"] } const_format = { version = "0.2.21" } cfg-if = { version = "1.0" } diff --git a/evm_loader/program/src/evm/memory.rs b/evm_loader/program/src/evm/memory.rs index 2ccb671fe..bff80dd62 100644 --- a/evm_loader/program/src/evm/memory.rs +++ b/evm_loader/program/src/evm/memory.rs @@ -4,11 +4,9 @@ use std::ops::Range; use solana_program::program_memory::{sol_memcpy, sol_memset}; use crate::error::Error; -#[cfg(not(target_os = "solana"))] -use crate::evm::tracing::TracerTypeOpt; use super::utils::checked_next_multiple_of_32; -use super::{tracing_event, Buffer}; +use super::Buffer; const MAX_MEMORY_SIZE: usize = 64 * 1024; const MEMORY_CAPACITY: usize = 1024; @@ -20,23 +18,14 @@ pub struct Memory { data: *mut u8, capacity: usize, size: usize, - #[cfg(not(target_os = "solana"))] - tracer: TracerTypeOpt, } impl Memory { - pub fn new(#[cfg(not(target_os = "solana"))] tracer: TracerTypeOpt) -> Self { - Self::with_capacity( - MEMORY_CAPACITY, - #[cfg(not(target_os = "solana"))] - tracer, - ) + pub fn new() -> Self { + Self::with_capacity(MEMORY_CAPACITY) } - pub fn with_capacity( - capacity: usize, - #[cfg(not(target_os = "solana"))] tracer: TracerTypeOpt, - ) -> Self { + pub fn with_capacity(capacity: usize) -> Self { unsafe { let layout = Layout::from_size_align_unchecked(capacity, MEMORY_ALIGN); let data = crate::allocator::EVM.alloc_zeroed(layout); @@ -48,8 +37,6 @@ impl Memory { data, capacity, size: 0, - #[cfg(not(target_os = "solana"))] - tracer, } } } @@ -70,8 +57,6 @@ impl Memory { data, capacity, size: v.len(), - #[cfg(not(target_os = "solana"))] - tracer: None, } } } @@ -157,14 +142,6 @@ impl Memory { } pub fn write_32(&mut self, offset: usize, value: &[u8; 32]) -> Result<(), Error> { - tracing_event!( - self, - super::tracing::Event::MemorySet { - offset, - data: value.to_vec() - } - ); - self.realloc(offset, 32)?; unsafe { @@ -176,14 +153,6 @@ impl Memory { } pub fn write_byte(&mut self, offset: usize, value: u8) -> Result<(), Error> { - tracing_event!( - self, - super::tracing::Event::MemorySet { - offset, - data: vec![value] - } - ); - self.realloc(offset, 1)?; unsafe { @@ -214,45 +183,16 @@ impl Memory { match source_offset { source_offset if source_offset >= source.len() => { - tracing_event!( - self, - super::tracing::Event::MemorySet { - offset, - data: vec![0; length] - } - ); - sol_memset(data, 0, length); } source_offset if (source_offset + length) > source.len() => { let source = &source[source_offset..]; - tracing_event!( - self, - super::tracing::Event::MemorySet { - offset, - data: { - let mut buffer = vec![0_u8; length]; - buffer[..source.len()].copy_from_slice(source); - buffer - } - } - ); - data[..source.len()].copy_from_slice(source); data[source.len()..].fill(0_u8); } source_offset => { let source = &source[source_offset..source_offset + length]; - - tracing_event!( - self, - super::tracing::Event::MemorySet { - offset, - data: source.to_vec() - } - ); - sol_memcpy(data, source, length); } } diff --git a/evm_loader/program/src/evm/mod.rs b/evm_loader/program/src/evm/mod.rs index 9e270e81b..add5b66f2 100644 --- a/evm_loader/program/src/evm/mod.rs +++ b/evm_loader/program/src/evm/mod.rs @@ -284,14 +284,8 @@ impl Machine { call_data: trx.extract_call_data(), return_data: Buffer::empty(), return_range: 0..0, - stack: Stack::new( - #[cfg(not(target_os = "solana"))] - tracer.clone(), - ), - memory: Memory::new( - #[cfg(not(target_os = "solana"))] - tracer.clone(), - ), + stack: Stack::new(), + memory: Memory::new(), pc: 0_usize, is_static: false, reason: Reason::Call, @@ -336,14 +330,8 @@ impl Machine { gas_limit: trx.gas_limit(), return_data: Buffer::empty(), return_range: 0..0, - stack: Stack::new( - #[cfg(not(target_os = "solana"))] - tracer.clone(), - ), - memory: Memory::new( - #[cfg(not(target_os = "solana"))] - tracer.clone(), - ), + stack: Stack::new(), + memory: Memory::new(), pc: 0_usize, is_static: false, reason: Reason::Create, @@ -449,14 +437,8 @@ impl Machine { call_data, return_data: Buffer::empty(), return_range: 0..0, - stack: Stack::new( - #[cfg(not(target_os = "solana"))] - self.tracer.clone(), - ), - memory: Memory::new( - #[cfg(not(target_os = "solana"))] - self.tracer.clone(), - ), + stack: Stack::new(), + memory: Memory::new(), pc: 0_usize, is_static: self.is_static, reason, diff --git a/evm_loader/program/src/evm/opcode.rs b/evm_loader/program/src/evm/opcode.rs index f1f8c9b48..6e3690291 100644 --- a/evm_loader/program/src/evm/opcode.rs +++ b/evm_loader/program/src/evm/opcode.rs @@ -811,7 +811,6 @@ impl Machine { let index = self.stack.pop_u256()?; let value = *self.stack.pop_array()?; - tracing_event!(self, super::tracing::Event::StorageSet { index, value }); tracing_event!(self, super::tracing::Event::StorageAccess { index, value }); backend.set_storage(self.context.contract, index, value)?; diff --git a/evm_loader/program/src/evm/stack.rs b/evm_loader/program/src/evm/stack.rs index 9470e0fd0..71d45258f 100644 --- a/evm_loader/program/src/evm/stack.rs +++ b/evm_loader/program/src/evm/stack.rs @@ -7,12 +7,8 @@ use std::{ use ethnum::{I256, U256}; -#[cfg(not(target_os = "solana"))] -use crate::evm::TracerTypeOpt; use crate::{error::Error, types::Address}; -use super::tracing_event; - const ELEMENT_SIZE: usize = 32; const STACK_SIZE: usize = ELEMENT_SIZE * 128; @@ -20,12 +16,10 @@ pub struct Stack { begin: *mut u8, end: *mut u8, top: *mut u8, - #[cfg(not(target_os = "solana"))] - tracer: TracerTypeOpt, } impl Stack { - pub fn new(#[cfg(not(target_os = "solana"))] tracer: TracerTypeOpt) -> Self { + pub fn new() -> Self { let (begin, end) = unsafe { let layout = Layout::from_size_align_unchecked(STACK_SIZE, ELEMENT_SIZE); let begin = crate::allocator::EVM.alloc(layout); @@ -42,8 +36,6 @@ impl Stack { begin, end, top: begin, - #[cfg(not(target_os = "solana"))] - tracer, } } @@ -70,13 +62,6 @@ impl Stack { return Err(Error::StackOverflow); } - tracing_event!( - self, - super::tracing::Event::StackPush { - value: unsafe { *self.read() } - } - ); - unsafe { self.top = self.top.add(32); } @@ -315,10 +300,7 @@ impl<'de> serde::Deserialize<'de> for Stack { return Err(E::invalid_length(v.len(), &self)); } - let mut stack = Stack::new( - #[cfg(not(target_os = "solana"))] - None, - ); + let mut stack = Stack::new(); unsafe { stack.top = stack.begin.add(v.len()); diff --git a/evm_loader/program/src/evm/tracing/mod.rs b/evm_loader/program/src/evm/tracing/mod.rs index b30817cb7..aed26b2e6 100644 --- a/evm_loader/program/src/evm/tracing/mod.rs +++ b/evm_loader/program/src/evm/tracing/mod.rs @@ -49,23 +49,13 @@ pub enum Event { gas_used: u64, return_data: Option>, }, - StackPush { - value: [u8; 32], - }, - MemorySet { - offset: usize, - data: Vec, - }, - StorageSet { - index: U256, - value: [u8; 32], - }, StorageAccess { index: U256, value: [u8; 32], }, } +/// See #[derive(Debug, Clone, serde::Serialize, serde::Deserialize)] #[serde(rename_all = "camelCase")] pub struct BlockOverrides { @@ -83,6 +73,7 @@ pub struct BlockOverrides { pub base_fee: Option, // NOT SUPPORTED BY Neon EVM } +/// See #[derive(Debug, Clone, serde::Serialize, serde::Deserialize)] #[serde(rename_all = "camelCase")] pub struct AccountOverride { @@ -108,8 +99,10 @@ impl AccountOverride { } } +/// See pub type AccountOverrides = HashMap; +/// See #[derive(Debug, Clone, Default, serde::Serialize, serde::Deserialize)] #[serde(rename_all = "camelCase")] #[allow(clippy::module_name_repetitions, clippy::struct_excessive_bools)] @@ -124,9 +117,10 @@ pub struct TraceConfig { pub enable_return_data: bool, pub tracer: Option, pub timeout: Option, - pub tracer_config: Value, + pub tracer_config: Option, } +/// See #[derive(Debug, Clone, Default, serde::Serialize, serde::Deserialize)] #[serde(rename_all = "camelCase")] #[allow(clippy::module_name_repetitions)] diff --git a/evm_loader/program/src/evm/tracing/tracers/struct_logger.rs b/evm_loader/program/src/evm/tracing/tracers/struct_logger.rs index 08ebd2dc1..8687c7a17 100644 --- a/evm_loader/program/src/evm/tracing/tracers/struct_logger.rs +++ b/evm_loader/program/src/evm/tracing/tracers/struct_logger.rs @@ -12,13 +12,14 @@ use crate::types::hexbytes::HexBytes; /// `StructLoggerResult` groups all structured logs emitted by the EVM /// while replaying a transaction in debug mode as well as transaction /// execution status, the amount of gas used and the return value +/// see #[derive(Serialize, Debug, Clone)] #[serde(rename_all = "camelCase")] pub struct StructLoggerResult { - /// Is execution failed or not - pub failed: bool, /// Total used gas but include the refunded gas pub gas: u64, + /// Is execution failed or not + pub failed: bool, /// The data after execution or revert reason pub return_value: String, /// Logs emitted during execution @@ -27,6 +28,7 @@ pub struct StructLoggerResult { /// `StructLog` stores a structured log emitted by the EVM while replaying a /// transaction in debug mode +/// see #[derive(Serialize, Debug, Clone)] #[serde(rename_all = "camelCase")] pub struct StructLog { @@ -35,24 +37,34 @@ pub struct StructLog { /// Operation name op: &'static str, /// Amount of used gas - gas: Option, + gas: u64, /// Gas cost for this instruction. gas_cost: u64, /// Current depth depth: usize, - /// Snapshot of the current memory sate #[serde(skip_serializing_if = "Option::is_none")] - memory: Option>, // U256 sized chunks + error: Option, /// Snapshot of the current stack sate #[serde(skip_serializing_if = "Option::is_none")] stack: Option>, - /// Result of the step + #[serde(skip_serializing_if = "Option::is_none")] return_data: Option, - /// Snapshot of the current storage + /// Snapshot of the current memory sate #[serde(skip_serializing_if = "Option::is_none")] - storage: Option>, + memory: Option>, // chunks of 32 bytes + /// Result of the step + /// Snapshot of the current storage #[serde(skip_serializing_if = "Option::is_none")] - error: Option, + storage: Option>, + /// Refund counter + #[serde(skip_serializing_if = "is_zero")] + refund: u64, +} + +/// This is only used for serialize +#[allow(clippy::trivially_copy_pass_by_ref)] +fn is_zero(num: &u64) -> bool { + *num == 0 } impl StructLog { @@ -62,22 +74,22 @@ impl StructLog { pc: u64, gas_cost: u64, depth: usize, - memory: Option>, + memory: Option>, stack: Option>, - storage: Option>, ) -> Self { let op = OPNAMES[opcode as usize]; Self { pc, op, - gas: None, + gas: 0, gas_cost, depth, memory, stack, return_data: None, - storage, + storage: None, error: None, + refund: 0, } } } @@ -148,27 +160,13 @@ impl EventListener for StructLogger { ) }; - let memory = if !self.config.enable_memory || memory.is_empty() { - None + let memory = if self.config.enable_memory { + Some(memory.chunks(32).map(hex::encode).collect()) } else { - Some( - memory - .chunks(32) - .map(|slice| slice.to_vec().into()) - .collect(), - ) - }; - - let storage = if self.config.disable_storage { None - } else { - self.logs - .last() - .and_then(|log| log.storage.clone()) - .or(None) }; - let log = StructLog::new(opcode, pc as u64, 0, self.depth, memory, stack, storage); + let log = StructLog::new(opcode, pc as u64, 0, self.depth, memory, stack); self.logs.push(log); } Event::EndStep { @@ -179,22 +177,24 @@ impl EventListener for StructLogger { .logs .last_mut() .expect("`EndStep` event before `BeginStep`"); - last.gas = Some(gas_used); + last.gas = gas_used; if !self.config.disable_storage { if let Some((index, value)) = self.storage_access.take() { - last.storage - .get_or_insert_with(Default::default) - .insert(index, value); + last.storage.get_or_insert_with(Default::default).insert( + hex::encode(index.to_be_bytes()), + hex::encode(value.to_be_bytes()), + ); }; } if self.config.enable_return_data { last.return_data = return_data.map(Into::into); } } - Event::StorageAccess { index, value } if !self.config.disable_storage => { - self.storage_access = Some((index, U256::from_be_bytes(value))); + Event::StorageAccess { index, value } => { + if !self.config.disable_storage { + self.storage_access = Some((index, U256::from_be_bytes(value))); + } } - _ => (), }; } @@ -217,3 +217,84 @@ impl EventListener for StructLogger { serde_json::to_value(result).expect("Conversion error") } } + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn test_serialize_struct_logger_result_all_fields() { + let struct_logger_result = StructLoggerResult { + gas: 20000, + failed: false, + return_value: "000000000000000000000000000000000000000000000000000000000000001b" + .to_string(), + struct_logs: vec![StructLog { + pc: 8, + op: "PUSH2", + gas: 0, + gas_cost: 0, + depth: 1, + stack: Some(vec![U256::from(0u8), U256::from(1u8)]), + memory: Some(vec![ + "0000000000000000000000000000000000000000000000000000000000000000".to_string(), + "0000000000000000000000000000000000000000000000000000000000000000".to_string(), + "0000000000000000000000000000000000000000000000000000000000000080".to_string(), + ]), + return_data: None, + storage: None, + refund: 0, + error: None, + }], + }; + assert_eq!(serde_json::to_string(&struct_logger_result).unwrap(), "{\"gas\":20000,\"failed\":false,\"returnValue\":\"000000000000000000000000000000000000000000000000000000000000001b\",\"structLogs\":[{\"pc\":8,\"op\":\"PUSH2\",\"gas\":0,\"gasCost\":0,\"depth\":1,\"stack\":[\"0x0\",\"0x1\"],\"memory\":[\"0000000000000000000000000000000000000000000000000000000000000000\",\"0000000000000000000000000000000000000000000000000000000000000000\",\"0000000000000000000000000000000000000000000000000000000000000080\"]}]}"); + } + + #[test] + fn test_serialize_struct_logger_result_no_optional_fields() { + let struct_logger_result = StructLoggerResult { + gas: 20000, + failed: false, + return_value: "000000000000000000000000000000000000000000000000000000000000001b" + .to_string(), + struct_logs: vec![StructLog { + pc: 0, + op: "PUSH1", + gas: 0, + gas_cost: 0, + depth: 1, + stack: None, + memory: None, + return_data: None, + storage: None, + refund: 0, + error: None, + }], + }; + assert_eq!(serde_json::to_string(&struct_logger_result).unwrap(), "{\"gas\":20000,\"failed\":false,\"returnValue\":\"000000000000000000000000000000000000000000000000000000000000001b\",\"structLogs\":[{\"pc\":0,\"op\":\"PUSH1\",\"gas\":0,\"gasCost\":0,\"depth\":1}]}"); + } + + #[test] + fn test_serialize_struct_logger_result_empty_stack_empty_memory() { + let struct_logger_result = StructLoggerResult { + gas: 20000, + failed: false, + return_value: "000000000000000000000000000000000000000000000000000000000000001b" + .to_string(), + struct_logs: vec![StructLog { + pc: 0, + op: "PUSH1", + gas: 0, + gas_cost: 0, + depth: 1, + stack: Some(vec![]), + memory: Some(vec![]), + return_data: None, + storage: None, + refund: 0, + error: None, + }], + }; + assert_eq!(serde_json::to_string(&struct_logger_result).unwrap(), "{\"gas\":20000,\"failed\":false,\"returnValue\":\"000000000000000000000000000000000000000000000000000000000000001b\",\"structLogs\":[{\"pc\":0,\"op\":\"PUSH1\",\"gas\":0,\"gasCost\":0,\"depth\":1,\"stack\":[],\"memory\":[]}]}"); + } +}