Merge pull request #791 from ethcore/tracing

Comprehensive tests for tracing transactions

ethcore/src/executive.rs

@@ -261,16 +261,14 @@ impl<'a> Executive<'a> {
 
 			// if there's tracing, make up trace_info's result with trace_output and some arithmetic.
 			if let Some((TraceAction::Call(ref mut c), _)) = trace_info {
-				if let Some(output) = trace_output {
+				c.result = res.as_ref().ok().map(|gas_left| (c.gas - *gas_left, trace_output.expect("trace_info is Some: qed")));
-					c.result = res.as_ref().ok().map(|gas_left| (c.gas - *gas_left, output));
-				}
 			}
 
-			trace!("exec: sstore-clears={}\n", unconfirmed_substate.sstore_clears_count);
+			trace!(target: "executive", "sstore-clears={}\n", unconfirmed_substate.sstore_clears_count);
-			trace!("exec: substate={:?}; unconfirmed_substate={:?}\n", substate, unconfirmed_substate);
+			trace!(target: "executive", "substate={:?}; unconfirmed_substate={:?}\n", substate, unconfirmed_substate);
 
 			self.enact_result(&res, substate, unconfirmed_substate, trace_info);
-			trace!("exec: new substate={:?}\n", substate);
+			trace!(target: "executive", "enacted: substate={:?}\n", substate);
 			res
 		} else {
 			// otherwise, nothing
@@ -307,11 +305,11 @@ impl<'a> Executive<'a> {
 		};
 
 		if let Some((TraceAction::Create(ref mut c), _)) = trace_info {
-			if let Some(output) = trace_output {
+			c.result = res.as_ref().ok().map(|gas_left| (c.gas - *gas_left, created, trace_output.expect("trace_info is Some: qed")));
-				c.result = res.as_ref().ok().map(|gas_left| (c.gas - *gas_left, created, output));
-			}
 		}
 
+		trace!(target: "executive", "trace_info={:?}", trace_info);
+
 		self.enact_result(&res, substate, unconfirmed_substate, trace_info);
 		res
 	}
@@ -348,6 +346,8 @@ impl<'a> Executive<'a> {
 			self.state.kill_account(address);
 		}
 
+		let trace = substate.subtraces.and_then(|mut v| v.pop());
+
 		match result {
 			Err(evm::Error::Internal) => Err(ExecutionError::Internal),
 			Err(_) => {
@@ -359,7 +359,7 @@ impl<'a> Executive<'a> {
 					logs: vec![],
 					contracts_created: vec![],
 					output: output,
-					trace: None,
+					trace: trace,
 				})
 			},
 			_ => {
@@ -371,7 +371,7 @@ impl<'a> Executive<'a> {
 					logs: substate.logs,
 					contracts_created: substate.contracts_created,
 					output: output,
-					trace: substate.subtraces.and_then(|mut v| v.pop()),
+					trace: trace,
 				})
 			},
 		}
@@ -385,6 +385,7 @@ impl<'a> Executive<'a> {
 				| Err(evm::Error::StackUnderflow {..})
 				| Err(evm::Error::OutOfStack {..}) => {
 				self.state.revert_snapshot();
+				substate.accrue_trace(un_substate.subtraces, maybe_info)
 			},
 			Ok(_) | Err(evm::Error::Internal) => {
 				self.state.clear_snapshot();

ethcore/src/externalities.rs

@@ -159,7 +159,9 @@ impl<'a> Ext for Externalities<'a> {
 		value: Option<U256>,
 		data: &[u8],
 		code_address: &Address,
-			output: &mut [u8]) -> MessageCallResult {
+		output: &mut [u8]
+	) -> MessageCallResult {
+		trace!(target: "externalities", "call");
 
 		let mut params = ActionParams {
 			sender: sender_address.clone(),

ethcore/src/state.rs

@@ -349,6 +349,456 @@ use util::rlp::*;
 use account::*;
 use tests::helpers::*;
 use devtools::*;
+use evm::factory::*;
+use env_info::*;
+use spec::*;
+use transaction::*;
+use util::log::init_log;
+use trace::*;
+
+#[test]
+fn should_apply_create_transaction() {
+	init_log();
+
+	let temp = RandomTempPath::new();
+	let mut state = get_temp_state_in(temp.as_path());
+
+	let mut info = EnvInfo::default();
+	info.gas_limit = x!(1_000_000);
+	let engine = TestEngine::new(5, Factory::default());
+
+	let t = Transaction {
+		nonce: x!(0),
+		gas_price: x!(0),
+		gas: x!(100_000),
+		action: Action::Create,
+		value: x!(100),
+		data: FromHex::from_hex("601080600c6000396000f3006000355415600957005b60203560003555").unwrap(),
+	}.sign(&"".sha3());
+
+	state.add_balance(t.sender().as_ref().unwrap(), &x!(100));
+	let result = state.apply(&info, &engine, &t, true).unwrap();
+	let expected_trace = Some(Trace {
+		depth: 0,
+		action: TraceAction::Create(TraceCreate {
+			from: x!("9cce34f7ab185c7aba1b7c8140d620b4bda941d6"),
+			value: x!(100),
+			gas: x!(77412),
+			init: vec![96, 16, 128, 96, 12, 96, 0, 57, 96, 0, 243, 0, 96, 0, 53, 84, 21, 96, 9, 87, 0, 91, 96, 32, 53, 96, 0, 53, 85],
+			result: Some((x!(3224), x!("8988167e088c87cd314df6d3c2b83da5acb93ace"), vec![96, 0, 53, 84, 21, 96, 9, 87, 0, 91, 96, 32, 53, 96, 0, 53]))
+		}),
+		subs: vec![]
+	});
+
+	assert_eq!(result.trace, expected_trace);
+}
+
+#[test]
+fn should_trace_failed_create_transaction() {
+	init_log();
+
+	let temp = RandomTempPath::new();
+	let mut state = get_temp_state_in(temp.as_path());
+
+	let mut info = EnvInfo::default();
+	info.gas_limit = x!(1_000_000);
+	let engine = TestEngine::new(5, Factory::default());
+
+	let t = Transaction {
+		nonce: x!(0),
+		gas_price: x!(0),
+		gas: x!(100_000),
+		action: Action::Create,
+		value: x!(100),
+		data: FromHex::from_hex("5b600056").unwrap(),
+	}.sign(&"".sha3());
+
+	state.add_balance(t.sender().as_ref().unwrap(), &x!(100));
+	let result = state.apply(&info, &engine, &t, true).unwrap();
+	let expected_trace = Some(Trace {
+		depth: 0,
+		action: TraceAction::Create(TraceCreate {
+			from: x!("9cce34f7ab185c7aba1b7c8140d620b4bda941d6"),
+			value: x!(100),
+			gas: x!(78792),
+			init: vec![91, 96, 0, 86],
+			result: None
+		}),
+		subs: vec![]
+	});
+
+	assert_eq!(result.trace, expected_trace);
+}
+
+#[test]
+fn should_trace_call_transaction() {
+	init_log();
+
+	let temp = RandomTempPath::new();
+	let mut state = get_temp_state_in(temp.as_path());
+
+	let mut info = EnvInfo::default();
+	info.gas_limit = x!(1_000_000);
+	let engine = TestEngine::new(5, Factory::default());
+
+	let t = Transaction {
+		nonce: x!(0),
+		gas_price: x!(0),
+		gas: x!(100_000),
+		action: Action::Call(x!(0xa)),
+		value: x!(100),
+		data: vec![],
+	}.sign(&"".sha3());
+
+	state.init_code(&x!(0xa), FromHex::from_hex("6000").unwrap());
+	state.add_balance(t.sender().as_ref().unwrap(), &x!(100));
+	let result = state.apply(&info, &engine, &t, true).unwrap();
+	let expected_trace = Some(Trace {
+		depth: 0,
+		action: TraceAction::Call(TraceCall {
+			from: x!("9cce34f7ab185c7aba1b7c8140d620b4bda941d6"),
+			to: x!(0xa),
+			value: x!(100),
+			gas: x!(79000),
+			input: vec![],
+			result: Some((x!(3), vec![]))
+		}),
+		subs: vec![]
+	});
+
+	assert_eq!(result.trace, expected_trace);
+}
+
+#[test]
+fn should_not_trace_call_transaction_to_builtin() {
+	init_log();
+
+	let temp = RandomTempPath::new();
+	let mut state = get_temp_state_in(temp.as_path());
+
+	let mut info = EnvInfo::default();
+	info.gas_limit = x!(1_000_000);
+	let engine = Spec::new_test().to_engine().unwrap();
+
+	let t = Transaction {
+		nonce: x!(0),
+		gas_price: x!(0),
+		gas: x!(100_000),
+		action: Action::Call(x!(0x1)),
+		value: x!(0),
+		data: vec![],
+	}.sign(&"".sha3());
+
+	let result = state.apply(&info, engine.deref(), &t, true).unwrap();
+
+	assert_eq!(result.trace, None);
+}
+
+#[test]
+fn should_not_trace_subcall_transaction_to_builtin() {
+	init_log();
+
+	let temp = RandomTempPath::new();
+	let mut state = get_temp_state_in(temp.as_path());
+
+	let mut info = EnvInfo::default();
+	info.gas_limit = x!(1_000_000);
+	let engine = Spec::new_test().to_engine().unwrap();
+
+	let t = Transaction {
+		nonce: x!(0),
+		gas_price: x!(0),
+		gas: x!(100_000),
+		action: Action::Call(x!(0xa)),
+		value: x!(0),
+		data: vec![],
+	}.sign(&"".sha3());
+
+	state.init_code(&x!(0xa), FromHex::from_hex("600060006000600060006001610be0f1").unwrap());
+	let result = state.apply(&info, engine.deref(), &t, true).unwrap();
+
+	let expected_trace = Some(Trace {
+		depth: 0,
+		action: TraceAction::Call(TraceCall {
+			from: x!("9cce34f7ab185c7aba1b7c8140d620b4bda941d6"),
+			to: x!(0xa),
+			value: x!(0),
+			gas: x!(79000),
+			input: vec![],
+			result: Some((x!(28061), vec![]))
+		}),
+		subs: vec![]
+	});
+	assert_eq!(result.trace, expected_trace);
+}
+
+#[test]
+fn should_trace_failed_call_transaction() {
+	init_log();
+
+	let temp = RandomTempPath::new();
+	let mut state = get_temp_state_in(temp.as_path());
+
+	let mut info = EnvInfo::default();
+	info.gas_limit = x!(1_000_000);
+	let engine = TestEngine::new(5, Factory::default());
+
+	let t = Transaction {
+		nonce: x!(0),
+		gas_price: x!(0),
+		gas: x!(100_000),
+		action: Action::Call(x!(0xa)),
+		value: x!(100),
+		data: vec![],
+	}.sign(&"".sha3());
+
+	state.init_code(&x!(0xa), FromHex::from_hex("5b600056").unwrap());
+	state.add_balance(t.sender().as_ref().unwrap(), &x!(100));
+	let result = state.apply(&info, &engine, &t, true).unwrap();
+	let expected_trace = Some(Trace {
+		depth: 0,
+		action: TraceAction::Call(TraceCall {
+			from: x!("9cce34f7ab185c7aba1b7c8140d620b4bda941d6"),
+			to: x!(0xa),
+			value: x!(100),
+			gas: x!(79000),
+			input: vec![],
+			result: None
+		}),
+		subs: vec![]
+	});
+
+	println!("trace: {:?}", result.trace);
+
+	assert_eq!(result.trace, expected_trace);
+}
+#[test]
+fn should_trace_call_with_subcall_transaction() {
+	init_log();
+
+	let temp = RandomTempPath::new();
+	let mut state = get_temp_state_in(temp.as_path());
+
+	let mut info = EnvInfo::default();
+	info.gas_limit = x!(1_000_000);
+	let engine = TestEngine::new(5, Factory::default());
+
+	let t = Transaction {
+		nonce: x!(0),
+		gas_price: x!(0),
+		gas: x!(100_000),
+		action: Action::Call(x!(0xa)),
+		value: x!(100),
+		data: vec![],
+	}.sign(&"".sha3());
+
+	state.init_code(&x!(0xa), FromHex::from_hex("60006000600060006000600b602b5a03f1").unwrap());
+	state.init_code(&x!(0xb), FromHex::from_hex("6000").unwrap());
+	state.add_balance(t.sender().as_ref().unwrap(), &x!(100));
+	let result = state.apply(&info, &engine, &t, true).unwrap();
+	let expected_trace = Some(Trace {
+		depth: 0,
+		action: TraceAction::Call(TraceCall {
+			from: x!("9cce34f7ab185c7aba1b7c8140d620b4bda941d6"),
+			to: x!(0xa),
+			value: x!(100),
+			gas: x!(79000),
+			input: vec![],
+			result: Some((x!(69), vec![]))
+		}),
+		subs: vec![Trace {
+			depth: 1,
+			action: TraceAction::Call(TraceCall {
+				from: x!(0xa),
+				to: x!(0xb),
+				value: x!(0),
+				gas: x!(78934),
+				input: vec![],
+				result: Some((x!(3), vec![]))
+			}),
+			subs: vec![]
+		}]
+	});
+
+	assert_eq!(result.trace, expected_trace);
+}
+
+#[test]
+fn should_trace_failed_subcall_transaction() {
+	init_log();
+
+	let temp = RandomTempPath::new();
+	let mut state = get_temp_state_in(temp.as_path());
+
+	let mut info = EnvInfo::default();
+	info.gas_limit = x!(1_000_000);
+	let engine = TestEngine::new(5, Factory::default());
+
+	let t = Transaction {
+		nonce: x!(0),
+		gas_price: x!(0),
+		gas: x!(100_000),
+		action: Action::Call(x!(0xa)),
+		value: x!(100),
+		data: vec![],//600480600b6000396000f35b600056
+	}.sign(&"".sha3());
+
+	state.init_code(&x!(0xa), FromHex::from_hex("60006000600060006000600b602b5a03f1").unwrap());
+	state.init_code(&x!(0xb), FromHex::from_hex("5b600056").unwrap());
+	state.add_balance(t.sender().as_ref().unwrap(), &x!(100));
+	let result = state.apply(&info, &engine, &t, true).unwrap();
+	let expected_trace = Some(Trace {
+		depth: 0,
+		action: TraceAction::Call(TraceCall {
+			from: x!("9cce34f7ab185c7aba1b7c8140d620b4bda941d6"),
+			to: x!(0xa),
+			value: x!(100),
+			gas: x!(79000),
+			input: vec![],
+			result: Some((x!(79000), vec![]))
+		}),
+		subs: vec![Trace {
+			depth: 1,
+			action: TraceAction::Call(TraceCall {
+				from: x!(0xa),
+				to: x!(0xb),
+				value: x!(0),
+				gas: x!(78934),
+				input: vec![],
+				result: None
+			}),
+			subs: vec![]
+		}]
+	});
+
+	assert_eq!(result.trace, expected_trace);
+}
+
+#[test]
+fn should_trace_call_with_subcall_with_subcall_transaction() {
+	init_log();
+
+	let temp = RandomTempPath::new();
+	let mut state = get_temp_state_in(temp.as_path());
+
+	let mut info = EnvInfo::default();
+	info.gas_limit = x!(1_000_000);
+	let engine = TestEngine::new(5, Factory::default());
+
+	let t = Transaction {
+		nonce: x!(0),
+		gas_price: x!(0),
+		gas: x!(100_000),
+		action: Action::Call(x!(0xa)),
+		value: x!(100),
+		data: vec![],
+	}.sign(&"".sha3());
+
+	state.init_code(&x!(0xa), FromHex::from_hex("60006000600060006000600b602b5a03f1").unwrap());
+	state.init_code(&x!(0xb), FromHex::from_hex("60006000600060006000600c602b5a03f1").unwrap());
+	state.init_code(&x!(0xc), FromHex::from_hex("6000").unwrap());
+	state.add_balance(t.sender().as_ref().unwrap(), &x!(100));
+	let result = state.apply(&info, &engine, &t, true).unwrap();
+	let expected_trace = Some(Trace {
+		depth: 0,
+		action: TraceAction::Call(TraceCall {
+			from: x!("9cce34f7ab185c7aba1b7c8140d620b4bda941d6"),
+			to: x!(0xa),
+			value: x!(100),
+			gas: x!(79000),
+			input: vec![],
+			result: Some((x!(135), vec![]))
+		}),
+		subs: vec![Trace {
+			depth: 1,
+			action: TraceAction::Call(TraceCall {
+				from: x!(0xa),
+				to: x!(0xb),
+				value: x!(0),
+				gas: x!(78934),
+				input: vec![],
+				result: Some((x!(69), vec![]))
+			}),
+			subs: vec![Trace {
+				depth: 2,
+				action: TraceAction::Call(TraceCall {
+					from: x!(0xb),
+					to: x!(0xc),
+					value: x!(0),
+					gas: x!(78868),
+					input: vec![],
+					result: Some((x!(3), vec![]))
+				}),
+				subs: vec![]
+			}]
+		}]
+	});
+
+	assert_eq!(result.trace, expected_trace);
+}
+
+#[test]
+fn should_trace_failed_subcall_with_subcall_transaction() {
+	init_log();
+
+	let temp = RandomTempPath::new();
+	let mut state = get_temp_state_in(temp.as_path());
+
+	let mut info = EnvInfo::default();
+	info.gas_limit = x!(1_000_000);
+	let engine = TestEngine::new(5, Factory::default());
+
+	let t = Transaction {
+		nonce: x!(0),
+		gas_price: x!(0),
+		gas: x!(100_000),
+		action: Action::Call(x!(0xa)),
+		value: x!(100),
+		data: vec![],//600480600b6000396000f35b600056
+	}.sign(&"".sha3());
+
+	state.init_code(&x!(0xa), FromHex::from_hex("60006000600060006000600b602b5a03f1").unwrap());
+	state.init_code(&x!(0xb), FromHex::from_hex("60006000600060006000600c602b5a03f1505b601256").unwrap());
+	state.init_code(&x!(0xc), FromHex::from_hex("6000").unwrap());
+	state.add_balance(t.sender().as_ref().unwrap(), &x!(100));
+	let result = state.apply(&info, &engine, &t, true).unwrap();
+	let expected_trace = Some(Trace {
+		depth: 0,
+		action: TraceAction::Call(TraceCall {
+			from: x!("9cce34f7ab185c7aba1b7c8140d620b4bda941d6"),
+			to: x!(0xa),
+			value: x!(100),
+			gas: x!(79000),
+			input: vec![],
+			result: Some((x!(79000), vec![]))
+		}),
+		subs: vec![Trace {
+			depth: 1,
+			action: TraceAction::Call(TraceCall {
+				from: x!(0xa),
+				to: x!(0xb),
+				value: x!(0),
+				gas: x!(78934),
+				input: vec![],
+				result: None
+			}),
+			subs: vec![Trace {
+				depth: 2,
+				action: TraceAction::Call(TraceCall {
+					from: x!(0xb),
+					to: x!(0xc),
+					value: x!(0),
+					gas: x!(78868),
+					input: vec![],
+					result: Some((x!(3), vec![])),
+				}),
+				subs: vec![]
+			}]
+		}]
+	});
+
+	assert_eq!(result.trace, expected_trace);
+}
 
 #[test]
 fn code_from_database() {

ethcore/src/substate.rs

@@ -49,19 +49,27 @@ impl Substate {
 		}
 	}
 
-	/// Merge secondary substate `s` into self, accruing each element correspondingly.
+	/// Merge tracing information from substate `s` if enabled.
+	pub fn accrue_trace(&mut self, subs: Option<Vec<Trace>>, maybe_info: Option<(TraceAction, usize)>) {
+		// it failed, so we don't bother accrueing any protocol-level stuff, only the
+		// trace info.
+		if let Some(info) = maybe_info {
+			self.subtraces.as_mut().expect("maybe_action is Some: so we must be tracing: qed").push(Trace {
+				action: info.0,
+				depth: info.1,
+				subs: subs.expect("maybe_action is Some: so we must be tracing: qed"),
+			});
+		}
+	}
+
+	/// Merge secondary substate `s` into self, accruing each element correspondingly; will merge
+	/// tracing information too, if enabled.
 	pub fn accrue(&mut self, s: Substate, maybe_info: Option<(TraceAction, usize)>) {
 		self.suicides.extend(s.suicides.into_iter());
 		self.logs.extend(s.logs.into_iter());
 		self.sstore_clears_count = self.sstore_clears_count + s.sstore_clears_count;
 		self.contracts_created.extend(s.contracts_created.into_iter());
-		if let Some(info) = maybe_info {
+		self.accrue_trace(s.subtraces, maybe_info);
-			self.subtraces.as_mut().expect("maybe_action is Some: so we must be tracing: qed").push(Trace {
-				action: info.0,
-				depth: info.1,
-				subs: s.subtraces.expect("maybe_action is Some: so we must be tracing: qed"),
-			});
-		}
 	}
 }