Fix stack display in evmbin. (#5733)

* Fix stack display.

* Additional compatiblity fixes.

ethcore/src/evm/ext.rs

@@ -131,7 +131,7 @@ pub trait Ext {
 	fn inc_sstore_clears(&mut self);
 
 	/// Prepare to trace an operation. Passthrough for the VM trace.
-	fn trace_prepare_execute(&mut self, _pc: usize, _instruction: u8, _stack_pop: usize, _gas_cost: &U256) -> bool { false }
+	fn trace_prepare_execute(&mut self, _pc: usize, _instruction: u8, _gas_cost: &U256) -> bool { false }
 
 	/// Trace the finalised execution of a single instruction.
 	fn trace_executed(&mut self, _gas_used: U256, _stack_push: &[U256], _mem_diff: Option<(usize, &[u8])>, _store_diff: Option<(U256, U256)>) {}

ethcore/src/evm/instructions.rs

@@ -37,6 +37,15 @@ pub fn get_push_bytes(i: Instruction) -> usize {
 	(i - PUSH1 + 1) as usize
 }
 
+/// Returns number of bytes to read for `PUSHN` instruction or 0.
+pub fn push_bytes(i: Instruction) -> usize {
+	if is_push(i) {
+		get_push_bytes(i)
+	} else {
+		0
+	}
+}
+
 #[test]
 fn test_get_push_bytes() {
 	assert_eq!(get_push_bytes(PUSH1), 1);

ethcore/src/evm/interpreter/mod.rs

@@ -130,7 +130,7 @@ impl<Cost: CostType> evm::Evm for Interpreter<Cost> {
 			// Calculate gas cost
 			let requirements = gasometer.requirements(ext, instruction, info, &stack, self.mem.size())?;
 			// TODO: make compile-time removable if too much of a performance hit.
-			let trace_executed = ext.trace_prepare_execute(reader.position - 1, instruction, info.args, &requirements.gas_cost.as_u256());
+			let trace_executed = ext.trace_prepare_execute(reader.position - 1, instruction, &requirements.gas_cost.as_u256());
 
 			gasometer.verify_gas(&requirements.gas_cost)?;
 			self.mem.expand(requirements.memory_required_size);

ethcore/src/evm/mod.rs

@@ -35,6 +35,7 @@ mod benches;
 
 pub use self::evm::{Evm, Error, Finalize, FinalizationResult, GasLeft, Result, CostType, ReturnData};
 pub use self::ext::{Ext, ContractCreateResult, MessageCallResult, CreateContractAddress};
+pub use self::instructions::{InstructionInfo, INSTRUCTIONS, push_bytes};
 pub use self::vmtype::VMType;
 pub use self::factory::Factory;
 pub use self::schedule::Schedule;

ethcore/src/executive.rs

@@ -357,7 +357,7 @@ impl<'a, B: 'a + StateBackend, E: Engine + ?Sized> Executive<'a, B, E> {
 					self.exec_vm(params, &mut unconfirmed_substate, OutputPolicy::Return(output, trace_output.as_mut()), &mut subtracer, &mut subvmtracer)
 				};
 
-				vm_tracer.done_subtrace(subvmtracer);
+				vm_tracer.done_subtrace(subvmtracer, res.is_ok());
 
 				trace!(target: "executive", "res={:?}", res);
 
@@ -432,7 +432,7 @@ impl<'a, B: 'a + StateBackend, E: Engine + ?Sized> Executive<'a, B, E> {
 			self.exec_vm(params, &mut unconfirmed_substate, OutputPolicy::InitContract(trace_output.as_mut()), &mut subtracer, &mut subvmtracer)
 		};
 
-		vm_tracer.done_subtrace(subvmtracer);
+		vm_tracer.done_subtrace(subvmtracer, res.is_ok());
 
 		match res {
 			Ok(ref res) => tracer.trace_create(

ethcore/src/externalities.rs

@@ -361,8 +361,8 @@ impl<'a, T: 'a, V: 'a, B: 'a, E: 'a> Ext for Externalities<'a, T, V, B, E>
 		self.substate.sstore_clears_count = self.substate.sstore_clears_count + U256::one();
 	}
 
-	fn trace_prepare_execute(&mut self, pc: usize, instruction: u8, stack_pop: usize, gas_cost: &U256) -> bool {
-		self.vm_tracer.trace_prepare_execute(pc, instruction, stack_pop, gas_cost)
+	fn trace_prepare_execute(&mut self, pc: usize, instruction: u8, gas_cost: &U256) -> bool {
+		self.vm_tracer.trace_prepare_execute(pc, instruction, gas_cost)
 	}
 
 	fn trace_executed(&mut self, gas_used: U256, stack_push: &[U256], mem_diff: Option<(usize, &[u8])>, store_diff: Option<(U256, U256)>) {

ethcore/src/trace/executive_tracer.rs

@@ -192,7 +192,7 @@ impl ExecutiveVMTracer {
 }
 
 impl VMTracer for ExecutiveVMTracer {
-	fn trace_prepare_execute(&mut self, pc: usize, instruction: u8, _stack_pop: usize, gas_cost: &U256) -> bool {
+	fn trace_prepare_execute(&mut self, pc: usize, instruction: u8, gas_cost: &U256) -> bool {
 		self.data.operations.push(VMOperation {
 			pc: pc,
 			instruction: instruction,
@@ -221,7 +221,7 @@ impl VMTracer for ExecutiveVMTracer {
 		}}
 	}
 
-	fn done_subtrace(&mut self, sub: Self) {
+	fn done_subtrace(&mut self, sub: Self, _is_successful: bool) {
 		self.data.subs.push(sub.data);
 	}
 

ethcore/src/trace/mod.rs

@@ -89,7 +89,7 @@ pub trait Tracer: Send {
 pub trait VMTracer: Send {
 	/// Trace the preparation to execute a single instruction.
 	/// @returns true if `trace_executed` should be called.
-	fn trace_prepare_execute(&mut self, _pc: usize, _instruction: u8, _stack_pop: usize, _gas_cost: &U256) -> bool { false }
+	fn trace_prepare_execute(&mut self, _pc: usize, _instruction: u8, _gas_cost: &U256) -> bool { false }
 
 	/// Trace the finalised execution of a single instruction.
 	fn trace_executed(&mut self, _gas_used: U256, _stack_push: &[U256], _mem_diff: Option<(usize, &[u8])>, _store_diff: Option<(U256, U256)>) {}
@@ -98,7 +98,7 @@ pub trait VMTracer: Send {
 	fn prepare_subtrace(&self, code: &[u8]) -> Self where Self: Sized;
 
 	/// Finalize subtracer.
-	fn done_subtrace(&mut self, sub: Self) where Self: Sized;
+	fn done_subtrace(&mut self, sub: Self, is_successful: bool) where Self: Sized;
 
 	/// Consumes self and returns the VM trace.
 	fn drain(self) -> Option<VMTrace>;

ethcore/src/trace/noop_tracer.rs

@@ -72,7 +72,7 @@ pub struct NoopVMTracer;
 
 impl VMTracer for NoopVMTracer {
 	/// Trace the preparation to execute a single instruction.
-	fn trace_prepare_execute(&mut self, _pc: usize, _instruction: u8, _stack_pop: usize, _gas_cost: &U256) -> bool { false }
+	fn trace_prepare_execute(&mut self, _pc: usize, _instruction: u8, _gas_cost: &U256) -> bool { false }
 
 	/// Trace the finalised execution of a single instruction.
 	fn trace_executed(&mut self, _gas_used: U256, _stack_push: &[U256], _mem_diff: Option<(usize, &[u8])>, _store_diff: Option<(U256, U256)>) {}
@@ -81,7 +81,7 @@ impl VMTracer for NoopVMTracer {
 	fn prepare_subtrace(&self, _code: &[u8]) -> Self { NoopVMTracer }
 
 	/// Spawn subtracer which will be used to trace deeper levels of execution.
-	fn done_subtrace(&mut self, _sub: Self) {}
+	fn done_subtrace(&mut self, _sub: Self, _is_successful: bool) {}
 
 	/// Consumes self and returns all VM traces.
 	fn drain(self) -> Option<VMTrace> { None }

evmbin/src/display/json.rs

@@ -16,7 +16,7 @@
 
 //! JSON VM output.
 
-use ethcore::trace;
+use ethcore::{evm, trace};
 use std::collections::HashMap;
 use util::{U256, H256, ToPretty};
 
@@ -26,11 +26,14 @@ use vm;
 /// JSON formatting informant.
 #[derive(Default)]
 pub struct Informant {
+	code: Vec<u8>,
 	depth: usize,
 	pc: usize,
 	instruction: u8,
+	name: &'static str,
 	gas_cost: U256,
 	gas_used: U256,
+	stack_pop: usize,
 	stack: Vec<U256>,
 	memory: Vec<u8>,
 	storage: HashMap<H256, H256>,
@@ -55,38 +58,44 @@ impl Informant {
 }
 
 impl vm::Informant for Informant {
+	fn set_gas(&mut self, gas: U256) {
+		self.gas_used = gas;
+	}
+
 	fn finish(&mut self, result: Result<vm::Success, vm::Failure>) {
 		match result {
 			Ok(success) => println!(
-				"{{\"output\":\"0x{output}\",\"gasUsed\":\"{gas:x}\",\"time\":\"{time}\"}}",
+				"{{\"output\":\"0x{output}\",\"gasUsed\":\"{gas:x}\",\"time\":{time}}}",
 				output = success.output.to_hex(),
 				gas = success.gas_used,
-				time = display::format_time(&success.time),
+				time = display::as_micros(&success.time),
 			),
 			Err(failure) => println!(
-				"{{\"error\":\"{error}\",\"time\":\"{time}\"}}",
+				"{{\"error\":\"{error}\",\"gasUsed\":\"{gas:x}\",\"time\":{time}}}",
 				error = failure.error,
-				time = display::format_time(&failure.time),
+				gas = failure.gas_used,
+				time = display::as_micros(&failure.time),
 			),
 		}
 	}
 }
 
 impl trace::VMTracer for Informant {
-	fn trace_prepare_execute(&mut self, pc: usize, instruction: u8, stack_pop: usize, gas_cost: &U256) -> bool {
+	fn trace_prepare_execute(&mut self, pc: usize, instruction: u8, gas_cost: &U256) -> bool {
 		self.pc = pc;
 		self.instruction = instruction;
 		self.gas_cost = *gas_cost;
-		let len = self.stack.len();
-		self.stack.truncate(len - stack_pop);
 		true
 	}
 
 	fn trace_executed(&mut self, gas_used: U256, stack_push: &[U256], mem_diff: Option<(usize, &[u8])>, store_diff: Option<(U256, U256)>) {
+		let info = evm::INSTRUCTIONS[self.instruction as usize];
+
 		println!(
-			"{{\"pc\":{pc},\"op\":{op},\"gas\":{gas},\"gasCost\":{gas_cost},\"memory\":{memory},\"stack\":{stack},\"storage\":{storage},\"depth\":{depth}}}",
+			"{{\"pc\":{pc},\"op\":{op},\"opName\":\"{name}\",\"gas\":{gas},\"gasCost\":{gas_cost},\"memory\":{memory},\"stack\":{stack},\"storage\":{storage},\"depth\":{depth}}}",
 			pc = self.pc,
 			op = self.instruction,
+			name = info.name,
 			gas = display::u256_as_str(&(gas_used + self.gas_cost)),
 			gas_cost = display::u256_as_str(&self.gas_cost),
 			memory = self.memory(),
@@ -96,6 +105,9 @@ impl trace::VMTracer for Informant {
 		);
 
 		self.gas_used = gas_used;
+
+		let len = self.stack.len();
+		self.stack.truncate(len - info.args);
 		self.stack.extend_from_slice(stack_push);
 
 		if let Some((pos, data)) = mem_diff {
@@ -107,17 +119,25 @@ impl trace::VMTracer for Informant {
 		}
 	}
 
-	fn prepare_subtrace(&self, _code: &[u8]) -> Self where Self: Sized {
+	fn prepare_subtrace(&self, code: &[u8]) -> Self where Self: Sized {
 		let mut vm = Informant::default();
 		vm.depth = self.depth + 1;
+		vm.code = code.to_vec();
+		vm.gas_used = self.gas_used;
 		vm
 	}
 
-	fn done_subtrace(&mut self, mut sub: Self) where Self: Sized {
+	fn done_subtrace(&mut self, mut sub: Self, is_successful: bool) where Self: Sized {
 		if sub.depth == 1 {
 			// print last line with final state:
-			sub.pc += 1;
-			sub.instruction = 0;
+			if is_successful {
+				sub.pc += 1;
+				sub.instruction = 0;
+			} else {
+				let push_bytes = evm::push_bytes(sub.instruction);
+				sub.pc += if push_bytes > 0 { push_bytes + 1 } else { 0 };
+				sub.instruction = if sub.pc < sub.code.len() { sub.code[sub.pc] } else { 0 };
+			}
 			sub.gas_cost = 0.into();
 			let gas_used = sub.gas_used;
 			trace::VMTracer::trace_executed(&mut sub, gas_used, &[], None, None);

evmbin/src/display/mod.rs

@@ -27,6 +27,11 @@ pub fn format_time(time: &Duration) -> String {
 	format!("{}.{:.9}s", time.as_secs(), time.subsec_nanos())
 }
 
+/// Formats the time as microseconds.
+pub fn as_micros(time: &Duration) -> u64 {
+	time.as_secs() * 1_000_000 + time.subsec_nanos() as u64 / 1_000
+}
+
 /// Converts U256 into string.
 /// TODO Overcomes: https://github.com/paritytech/bigint/issues/13
 pub fn u256_as_str(v: &U256) -> String {

evmbin/src/display/simple.rs

@@ -44,6 +44,6 @@ impl vm::Informant for Informant {
 
 impl trace::VMTracer for Informant {
 	fn prepare_subtrace(&self, _code: &[u8]) -> Self where Self: Sized { Default::default() }
-	fn done_subtrace(&mut self, _sub: Self) where Self: Sized {}
+	fn done_subtrace(&mut self, _sub: Self, _is_successful: bool) where Self: Sized {}
 	fn drain(self) -> Option<trace::VMTrace> { None }
 }

evmbin/src/main.rs

@@ -81,6 +81,7 @@ fn run<T: Informant>(args: Args, mut informant: T) {
 	params.code = Some(Arc::new(code));
 	params.data = data;
 
+	informant.set_gas(gas);
 	let result = vm::run(&mut informant, spec, params);
 	informant.finish(result);
 }

evmbin/src/vm.rs

@@ -24,6 +24,8 @@ use ethcore::action_params::ActionParams;
 
 /// VM execution informant
 pub trait Informant: trace::VMTracer {
+	/// Set initial gas.
+	fn set_gas(&mut self, _gas: U256) {}
 	/// Display final result.
 	fn finish(&mut self, result: Result<Success, Failure>);
 }
@@ -40,6 +42,8 @@ pub struct Success {
 
 /// Execution failed
 pub struct Failure {
+	/// Used gas
+	pub gas_used: U256,
 	/// Internal error
 	pub error: EvmTestError,
 	/// Duration
@@ -49,6 +53,7 @@ pub struct Failure {
 /// Execute VM with given `ActionParams`
 pub fn run<T: trace::VMTracer>(vm_tracer: &mut T, spec: spec::Spec, params: ActionParams) -> Result<Success, Failure> {
 	let mut test_client = EvmTestClient::new(spec).map_err(|error| Failure {
+		gas_used: 0.into(),
 		error,
 		time: Duration::from_secs(0)
 	})?;
@@ -65,6 +70,7 @@ pub fn run<T: trace::VMTracer>(vm_tracer: &mut T, spec: spec::Spec, params: Acti
 			time: duration,
 		}),
 		Err(e) => Err(Failure {
+			gas_used: initial_gas,
 			error: e,
 			time: duration,
 		}),