Capture reverted logs on failed tests (gakonst#289)

* capture reverted logs on failed tests * fmt * cleaner impl * fmt * cleanup fn logs * fmt
meetmangukiya · Dec 23, 2021 · 2451658 · 2451658
1 parent 2993868
commit 2451658
Show file tree

Hide file tree

Showing 9 changed files with 103 additions and 39 deletions.
diff --git a/evm-adapters/src/evmodin.rs b/evm-adapters/src/evmodin.rs
@@ -73,6 +73,10 @@ impl<S: HostExt, Tr: Tracer> Evm<S> for EvmOdin<S, Tr> {
         &self.host
     }
 
+    fn all_logs(&self) -> Vec<String> {
+        vec![]
+    }
+
     #[allow(unused)]
     fn deploy(
         &mut self,

diff --git a/evm-adapters/src/lib.rs b/evm-adapters/src/lib.rs
@@ -71,6 +71,9 @@ pub trait Evm<State> {
     /// Resets the EVM's state to the provided value
     fn reset(&mut self, state: State);
 
+    /// Gets all logs from the execution, regardless of reverts
+    fn all_logs(&self) -> Vec<String>;
+
     /// Performs a [`call_unchecked`](Self::call_unchecked), checks if execution reverted, and
     /// proceeds to return the decoded response to the user.
     fn call<D: Detokenize, T: Tokenize, F: IntoFunction>(

diff --git a/evm-adapters/src/sputnik/cheatcodes/cheatcode_handler.rs b/evm-adapters/src/sputnik/cheatcodes/cheatcode_handler.rs
@@ -69,6 +69,41 @@ pub struct CheatcodeHandler<H> {
     console_logs: Vec<String>,
 }
 
+pub(crate) fn convert_log(log: Log) -> Option<String> {
+    use HevmConsoleEvents::*;
+    let log = RawLog { topics: log.topics, data: log.data };
+    let event = HevmConsoleEvents::decode_log(&log).ok()?;
+    let ret = match event {
+        LogsFilter(inner) => format!("{}", inner.0),
+        LogBytesFilter(inner) => format!("{}", inner.0),
+        LogNamedAddressFilter(inner) => format!("{}: {:?}", inner.key, inner.val),
+        LogNamedBytes32Filter(inner) => {
+            format!("{}: 0x{}", inner.key, hex::encode(inner.val))
+        }
+        LogNamedDecimalIntFilter(inner) => format!(
+            "{}: {:?}",
+            inner.key,
+            ethers::utils::parse_units(inner.val, inner.decimals.as_u32()).unwrap()
+        ),
+        LogNamedDecimalUintFilter(inner) => {
+            format!(
+                "{}: {:?}",
+                inner.key,
+                ethers::utils::parse_units(inner.val, inner.decimals.as_u32()).unwrap()
+            )
+        }
+        LogNamedIntFilter(inner) => format!("{}: {:?}", inner.key, inner.val),
+        LogNamedUintFilter(inner) => format!("{}: {:?}", inner.key, inner.val),
+        LogNamedBytesFilter(inner) => {
+            format!("{}: 0x{}", inner.key, hex::encode(inner.val))
+        }
+        LogNamedStringFilter(inner) => format!("{}: {}", inner.key, inner.val),
+
+        e => e.to_string(),
+    };
+    Some(ret)
+}
+
 // Forwards everything internally except for the transact_call which is overwritten.
 // TODO: Maybe we can pull this functionality up to the `Evm` trait to avoid having so many traits?
 impl<'a, 'b, B: Backend, P: PrecompileSet> SputnikExecutor<CheatcodeStackState<'a, B>>
@@ -95,6 +130,10 @@ impl<'a, 'b, B: Backend, P: PrecompileSet> SputnikExecutor<CheatcodeStackState<'
         U256::from(self.state().metadata().gasometer().gas())
     }
 
+    fn all_logs(&self) -> Vec<String> {
+        self.handler.state().all_logs.clone()
+    }
+
     fn transact_call(
         &mut self,
         caller: H160,
@@ -104,6 +143,9 @@ impl<'a, 'b, B: Backend, P: PrecompileSet> SputnikExecutor<CheatcodeStackState<'
         gas_limit: u64,
         access_list: Vec<(H160, Vec<H256>)>,
     ) -> (ExitReason, Vec<u8>) {
+        // reset all_logs because its a new call
+        self.state_mut().all_logs = vec![];
+
         let transaction_cost = gasometer::call_transaction_cost(&data, &access_list);
         match self.state_mut().metadata_mut().gasometer_mut().record_transaction(transaction_cost) {
             Ok(()) => (),
@@ -146,6 +188,9 @@ impl<'a, 'b, B: Backend, P: PrecompileSet> SputnikExecutor<CheatcodeStackState<'
         gas_limit: u64,
         access_list: Vec<(H160, Vec<H256>)>,
     ) -> ExitReason {
+        // reset all_logs because its a new call
+        self.state_mut().all_logs = vec![];
+
         let transaction_cost = gasometer::create_transaction_cost(&init_code, &access_list);
         match self.state_mut().metadata_mut().gasometer_mut().record_transaction(transaction_cost) {
             Ok(()) => (),
@@ -176,45 +221,7 @@ impl<'a, 'b, B: Backend, P: PrecompileSet> SputnikExecutor<CheatcodeStackState<'
 
     fn logs(&self) -> Vec<String> {
         let logs = self.state().substate.logs().to_vec();
-        logs.into_iter()
-            .filter_map(|log| {
-                // convert to the ethers type
-                let log = RawLog { topics: log.topics, data: log.data };
-                HevmConsoleEvents::decode_log(&log).ok()
-            })
-            .map(|event| {
-                use HevmConsoleEvents::*;
-                match event {
-                    LogsFilter(inner) => format!("{}", inner.0),
-                    LogBytesFilter(inner) => format!("{}", inner.0),
-                    LogNamedAddressFilter(inner) => format!("{}: {:?}", inner.key, inner.val),
-                    LogNamedBytes32Filter(inner) => {
-                        format!("{}: 0x{}", inner.key, hex::encode(inner.val))
-                    }
-                    LogNamedDecimalIntFilter(inner) => format!(
-                        "{}: {:?}",
-                        inner.key,
-                        ethers::utils::parse_units(inner.val, inner.decimals.as_u32()).unwrap()
-                    ),
-                    LogNamedDecimalUintFilter(inner) => {
-                        format!(
-                            "{}: {:?}",
-                            inner.key,
-                            ethers::utils::parse_units(inner.val, inner.decimals.as_u32()).unwrap()
-                        )
-                    }
-                    LogNamedIntFilter(inner) => format!("{}: {:?}", inner.key, inner.val),
-                    LogNamedUintFilter(inner) => format!("{}: {:?}", inner.key, inner.val),
-                    LogNamedBytesFilter(inner) => {
-                        format!("{}: 0x{}", inner.key, hex::encode(inner.val))
-                    }
-                    LogNamedStringFilter(inner) => format!("{}: {}", inner.key, inner.val),
-
-                    e => e.to_string(),
-                }
-            })
-            .chain(self.console_logs.clone())
-            .collect()
+        logs.into_iter().filter_map(convert_log).chain(self.console_logs.clone()).collect()
     }
 }
 
@@ -581,6 +588,7 @@ impl<'a, 'b, B: Backend, P: PrecompileSet> CheatcodeStackExecutor<'a, 'b, B, P>
         let reason = self.execute(&mut runtime);
         // // log::debug!(target: "evm", "Call execution using address {}: {:?}", code_address,
         // reason);
+
         match reason {
             ExitReason::Succeed(s) => {
                 let _ = self.handler.exit_substate(StackExitKind::Succeeded);
@@ -966,6 +974,12 @@ impl<'a, 'b, B: Backend, P: PrecompileSet> Handler for CheatcodeStackExecutor<'a
     }
 
     fn log(&mut self, address: H160, topics: Vec<H256>, data: Vec<u8>) -> Result<(), ExitError> {
+        if let Some(decoded) =
+            convert_log(Log { address, topics: topics.clone(), data: data.clone() })
+        {
+            self.state_mut().all_logs.push(decoded);
+        }
+
         self.handler.log(address, topics, data)
     }
 

diff --git a/evm-adapters/src/sputnik/cheatcodes/memory_stackstate_owned.rs b/evm-adapters/src/sputnik/cheatcodes/memory_stackstate_owned.rs
@@ -18,6 +18,7 @@ pub struct MemoryStackStateOwned<'config, B> {
     pub expected_revert: Option<Vec<u8>>,
     pub next_msg_sender: Option<H160>,
     pub msg_sender: Option<(H160, H160, usize)>,
+    pub all_logs: Vec<String>,
 }
 
 impl<'config, B: Backend> MemoryStackStateOwned<'config, B> {
@@ -34,6 +35,7 @@ impl<'config, B: Backend> MemoryStackStateOwned<'config, B> {
             expected_revert: None,
             next_msg_sender: None,
             msg_sender: None,
+            all_logs: Default::default(),
         }
     }
 }

diff --git a/evm-adapters/src/sputnik/evm.rs b/evm-adapters/src/sputnik/evm.rs
@@ -104,6 +104,10 @@ where
         self.executor.state()
     }
 
+    fn all_logs(&self) -> Vec<String> {
+        self.executor.all_logs()
+    }
+
     /// Deploys the provided contract bytecode
     fn deploy(
         &mut self,

diff --git a/evm-adapters/src/sputnik/mod.rs b/evm-adapters/src/sputnik/mod.rs
@@ -60,6 +60,7 @@ pub trait SputnikExecutor<S> {
     fn state(&self) -> &S;
     fn state_mut(&mut self) -> &mut S;
     fn expected_revert(&self) -> Option<&[u8]>;
+    fn all_logs(&self) -> Vec<String>;
     fn gas_left(&self) -> U256;
     fn transact_call(
         &mut self,
@@ -111,6 +112,10 @@ impl<'a, 'b, S: StackState<'a>, P: PrecompileSet> SputnikExecutor<S>
         None
     }
 
+    fn all_logs(&self) -> Vec<String> {
+        vec![]
+    }
+
     fn gas_left(&self) -> U256 {
         // NB: We do this to avoid `function cannot return without recursing`
         U256::from(self.state().metadata().gasometer().gas())

diff --git a/forge/src/multi_runner.rs b/forge/src/multi_runner.rs
@@ -245,6 +245,19 @@ mod tests {
                 reasons[&"test2()".to_owned()],
                 vec!["constructor".to_owned(), "setUp".to_owned(), "two".to_owned()]
             );
+            assert_eq!(
+                reasons[&"testFailWithRevert()".to_owned()],
+                vec![
+                    "constructor".to_owned(),
+                    "setUp".to_owned(),
+                    "three".to_owned(),
+                    "failure".to_owned()
+                ]
+            );
+            assert_eq!(
+                reasons[&"testFailWithRequire()".to_owned()],
+                vec!["constructor".to_owned(), "setUp".to_owned(), "four".to_owned()]
+            );
         }
 
         #[test]

diff --git a/forge/src/runner.rs b/forge/src/runner.rs
@@ -250,6 +250,8 @@ impl<'a, S: Clone, E: Evm<S>> ContractRunner<'a, S, E> {
             Err(err) => match err {
                 EvmError::Execution { reason, gas_used, logs: execution_logs } => {
                     logs.extend(execution_logs);
+                    // add reverted logs
+                    logs.extend(self.evm.all_logs());
                     (E::revert(), Some(reason), gas_used, logs)
                 }
                 err => {

diff --git a/forge/testdata/DebugLogsTest.sol b/forge/testdata/DebugLogsTest.sol
@@ -19,4 +19,21 @@ contract DebugLogsTest is DSTest {
         emit log("two");
     }
 
+    function testFailWithRevert() public {
+        Fails fails = new Fails();
+        emit log("three");
+        fails.failure();
+    }
+
+    function testFailWithRequire() public {
+        emit log("four");
+        require(false);
+    }
 }
+
+contract Fails is DSTest {
+    function failure() public {
+        emit log("failure");
+        revert();
+    }
+}