added trace logging in EVM interpreter loop (#9561)

Added trace logging for each instruction to evm::run function.
solves #9575

---------

Signed-off-by: xermicus <cyrill@parity.io>
Signed-off-by: Cyrill Leutwiler <bigcyrill@hotmail.com>
Co-authored-by: pgherveou <pgherveou@gmail.com>
Co-authored-by: cmd[bot] <41898282+github-actions[bot]@users.noreply.github.com>
Co-authored-by: Robert van Eerdewijk <robert@Roberts-MacBook-Pro.local>
Co-authored-by: xermicus <cyrill@parity.io>
Co-authored-by: Alexander Theißen <alex.theissen@me.com>
Co-authored-by: Cyrill Leutwiler <bigcyrill@hotmail.com>

Author: 6 people

prdoc/pr_9561.prdoc

@@ -0,0 +1,9 @@
+title: added trace logging in EVM interpreter loop
+doc:
+- audience: Runtime Dev
+  description: |-
+    Added trace logging for each instruction to evm::run function.
+    solves https://github.com/paritytech/polkadot-sdk/issues/9575
+crates:
+- name: pallet-revive
+  bump: patch

substrate/frame/revive/src/vm/evm.rs

@@ -156,7 +156,10 @@ fn run<'a, E: Ext>(
 ) -> InterpreterResult {
 	let host = &mut DummyHost {};
 	loop {
+		#[cfg(not(feature = "std"))]
 		let action = interpreter.run_plain(table, host);
+		#[cfg(feature = "std")]
+		let action = run_plain(interpreter, table, host);
 		match action {
 			InterpreterAction::Return(result) => {
 				log::trace!(target: LOG_TARGET, "Evm return {:?}", result);
@@ -242,6 +245,52 @@ fn run_call<'a, E: Ext>(
 	}
 }
 
+/// Re-implementation of REVM run_plain function to add trace logging to our EVM interpreter loop.
+/// NB: copied directly from revm tag v82
+#[cfg(feature = "std")]
+fn run_plain<WIRE: InterpreterTypes>(
+	interpreter: &mut Interpreter<WIRE>,
+	instruction_table: &revm::interpreter::InstructionTable<WIRE, DummyHost>,
+	host: &mut DummyHost,
+) -> InterpreterAction {
+	use crate::{alloc::string::ToString, format};
+	use revm::{
+		bytecode::OpCode,
+		interpreter::{
+			instruction_context::InstructionContext,
+			interpreter_types::{Jumps, LoopControl, MemoryTr, StackTr},
+		},
+	};
+	while interpreter.bytecode.is_not_end() {
+		log::trace!(target: LOG_TARGET,
+			"[{pc}]: {opcode}, stacktop: {stacktop}, memory size: {memsize} {memory:?}",
+			pc = interpreter.bytecode.pc(),
+			opcode = OpCode::new(interpreter.bytecode.opcode())
+				.map_or("INVALID".to_string(), |x| format!("{:?}", x.info())),
+			stacktop = interpreter.stack.top().map_or("None".to_string(), |x| format!("{:#x}", x)),
+			memsize = interpreter.memory.size(),
+			// printing at most the first 32 bytes of memory
+			memory = interpreter
+				.memory
+				.slice_len(0, core::cmp::min(32, interpreter.memory.size()))
+				.to_vec(),
+		);
+		// Get current opcode.
+		let opcode = interpreter.bytecode.opcode();
+
+		// SAFETY: In analysis we are doing padding of bytecode so that we are sure that last
+		// byte instruction is STOP so we are safe to just increment program_counter bcs on last
+		// instruction it will do noop and just stop execution of this contract
+		interpreter.bytecode.relative_jump(1);
+		let context = InstructionContext { interpreter, host };
+		// Execute instruction.
+		instruction_table[opcode as usize](context);
+	}
+	interpreter.bytecode.revert_to_previous_pointer();
+
+	interpreter.take_next_action()
+}
+
 fn run_create<'a, E: Ext>(
 	interpreter: &mut Interpreter<EVMInterpreter<'a, E>>,
 	create_input: Box<CreateInputs>,