Test multiple blocks/txs per block.

Better debug tracing.

substrate/executor/src/native_executor.rs

@@ -145,8 +145,6 @@ mod tests {
 
 	fn construct_block(number: BlockNumber, parent_hash: Hash, state_root: Hash, txs: Vec<Transaction>) -> (Vec<u8>, Hash) {
 		use triehash::ordered_trie_root;
-		let one = one();
-		let two = two();
 
 		let transactions = txs.into_iter().map(|transaction| {
 			let signature = secret_for(&transaction.signed).unwrap()
@@ -169,36 +167,85 @@ mod tests {
 		(Block { header, transactions }.to_vec(), hash)
 	}
 
-	fn block1() -> Vec<u8> {
-		construct_block(1, [69u8; 32], hex!("2481853da20b9f4322f34650fea5f240dcbfb266d02db94bfa0153c31f4a29db"), vec![Transaction {
-			signed: one(),
-			nonce: 0,
-			function: Function::StakingTransfer,
-			input_data: vec![].join(&two()).join(&69u64),
-		}]).0
+	fn block1() -> (Vec<u8>, Hash) {
+		construct_block(
+			1,
+			[69u8; 32],
+			hex!("2481853da20b9f4322f34650fea5f240dcbfb266d02db94bfa0153c31f4a29db"),
+			vec![Transaction {
+				signed: one(),
+				nonce: 0,
+				function: Function::StakingTransfer,
+				input_data: vec![].join(&two()).join(&69u64),
+			}]
+		)
+	}
+
+	fn block2() -> (Vec<u8>, Hash) {
+		construct_block(
+			2,
+			block1().1,
+			hex!("244289aaa48ad6aa39db860d8ec09295ee7f06d1addac3dc02aa993db8644008"),
+			vec![
+				Transaction {
+					signed: two(),
+					nonce: 0,
+					function: Function::StakingTransfer,
+					input_data: vec![].join(&one()).join(&5u64),
+				},
+				Transaction {
+					signed: one(),
+					nonce: 1,
+					function: Function::StakingTransfer,
+					input_data: vec![].join(&two()).join(&15u64),
+				}
+			]
+		)
+	}
+
+	#[test]
+	fn test_execution_works() {
+		let mut t = new_test_ext();
+		println!("Testing Wasm...");
+		let r = WasmExecutor.call(&mut t, COMPACT_CODE, "run_tests", &CallData(block2().0));
+		assert!(r.is_ok());
 	}
 
 	#[test]
 	fn full_native_block_import_works() {
 		let mut t = new_test_ext();
 
-		NativeExecutor.call(&mut t, COMPACT_CODE, "execute_block", &CallData(block1())).unwrap();
+		NativeExecutor.call(&mut t, COMPACT_CODE, "execute_block", &CallData(block1().0)).unwrap();
 
 		runtime_std::with_externalities(&mut t, || {
 			assert_eq!(balance(&one()), 42);
 			assert_eq!(balance(&two()), 69);
 		});
+
+		NativeExecutor.call(&mut t, COMPACT_CODE, "execute_block", &CallData(block2().0)).unwrap();
+
+		runtime_std::with_externalities(&mut t, || {
+			assert_eq!(balance(&one()), 32);
+			assert_eq!(balance(&two()), 79);
+		});
 	}
 
 	#[test]
 	fn full_wasm_block_import_works() {
 		let mut t = new_test_ext();
 
-		WasmExecutor.call(&mut t, COMPACT_CODE, "execute_block", &CallData(block1())).unwrap();
+		WasmExecutor.call(&mut t, COMPACT_CODE, "execute_block", &CallData(block1().0)).unwrap();
 
 		runtime_std::with_externalities(&mut t, || {
 			assert_eq!(balance(&one()), 42);
 			assert_eq!(balance(&two()), 69);
 		});
+
+		WasmExecutor.call(&mut t, COMPACT_CODE, "execute_block", &CallData(block2().0)).unwrap();
+
+		runtime_std::with_externalities(&mut t, || {
+			assert_eq!(balance(&one()), 32);
+			assert_eq!(balance(&two()), 79);
+		});
 	}
 }

substrate/executor/src/wasm_executor.rs

@@ -38,7 +38,7 @@ struct Heap {
 impl Heap {
 	fn new() -> Self {
 		Heap {
-			end: 1024,
+			end: 32768,
 		}
 	}
 	fn allocate(&mut self, size: u32) -> u32 {
@@ -118,34 +118,35 @@ impl_function_executor!(this: FunctionExecutor<'e, E>,
 	ext_memcpy(dest: *mut u8, src: *const u8, count: usize) -> *mut u8 => {
 		this.memory.copy_nonoverlapping(src as usize, dest as usize, count as usize)
 			.map_err(|_| DummyUserError)?;
-		println!("memcpy {} from {}, {} bytes", dest, src, count);
+//		println!("memcpy {} from {}, {} bytes", dest, src, count);
 		dest
 	},
 	ext_memmove(dest: *mut u8, src: *const u8, count: usize) -> *mut u8 => {
 		this.memory.copy(src as usize, dest as usize, count as usize)
 			.map_err(|_| DummyUserError)?;
-		println!("memmove {} from {}, {} bytes", dest, src, count);
+//		println!("memmove {} from {}, {} bytes", dest, src, count);
 		dest
 	},
 	ext_memset(dest: *mut u8, val: u32, count: usize) -> *mut u8 => {
 		this.memory.clear(dest as usize, val as u8, count as usize)
 			.map_err(|_| DummyUserError)?;
-		println!("memset {} with {}, {} bytes", dest, val, count);
+//		println!("memset {} with {}, {} bytes", dest, val, count);
 		dest
 	},
 	ext_malloc(size: usize) -> *mut u8 => {
 		let r = this.heap.allocate(size);
-		println!("malloc {} bytes at {}", size, r);
+//		println!("malloc {} bytes at {}", size, r);
 		r
 	},
 	ext_free(addr: *mut u8) => {
 		this.heap.deallocate(addr);
-		println!("free {}", addr)
+//		println!("free {}", addr)
 	},
 	ext_set_storage(key_data: *const u8, key_len: u32, value_data: *const u8, value_len: u32) => {
-		if let (Ok(key), Ok(value)) = (this.memory.get(key_data, key_len as usize), this.memory.get(value_data, value_len as usize)) {
-			this.ext.set_storage(key, value);
-		}
+		let key = this.memory.get(key_data, key_len as usize).map_err(|_| DummyUserError)?;
+		let value = this.memory.get(value_data, value_len as usize).map_err(|_| DummyUserError)?;
+		println!("Runtime: Setting storage: {} -> {}", HexDisplay::from(&key), HexDisplay::from(&value));
+		this.ext.set_storage(key, value);
 	},
 	ext_get_allocated_storage(key_data: *const u8, key_len: u32, written_out: *mut u32) -> *mut u8 => {
 		let key = this.memory.get(key_data, key_len as usize).map_err(|_| DummyUserError)?;
@@ -160,6 +161,7 @@ impl_function_executor!(this: FunctionExecutor<'e, E>,
 	ext_get_storage_into(key_data: *const u8, key_len: u32, value_data: *mut u8, value_len: u32, value_offset: u32) -> u32 => {
 		let key = this.memory.get(key_data, key_len as usize).map_err(|_| DummyUserError)?;
 		let value = this.ext.storage(&key).map_err(|_| DummyUserError)?;
+		println!("Runtime: Getting storage: {} ( -> {})", HexDisplay::from(&key), HexDisplay::from(&value));
 		let value = &value[value_offset as usize..];
 		let written = ::std::cmp::min(value_len as usize, value.len());
 		this.memory.set(value_data, &value[..written]).map_err(|_| DummyUserError)?;
@@ -188,9 +190,17 @@ impl_function_executor!(this: FunctionExecutor<'e, E>,
 	},
 	ext_twox_128(data: *const u8, len: u32, out: *mut u8) => {
 		let result = if len == 0 {
+			println!("Runtime: XXhash: ''");
 			twox_128(&[0u8; 0])
 		} else {
-			twox_128(&this.memory.get(data, len as usize).map_err(|_| DummyUserError)?)
+			let key = this.memory.get(data, len as usize).map_err(|_| DummyUserError)?;
+			let hashed_key = twox_128(&key);
+			if let Ok(skey) = ::std::str::from_utf8(&key) {
+				println!("Runtime: XXhash: {} -> {}", skey, HexDisplay::from(&hashed_key));
+			} else {
+				println!("Runtime: XXhash: {} -> {}", HexDisplay::from(&key), HexDisplay::from(&hashed_key));
+			}
+			hashed_key
 		};
 		this.memory.set(out, &result).map_err(|_| DummyUserError)?;
 	},

substrate/wasm-runtime/polkadot/src/codec/slicable.rs

@@ -84,7 +84,8 @@ impl Slicable for Vec<u8> {
 	fn set_as_slice<F: Fn(&mut [u8], usize) -> bool>(fill_slice: &F) -> Option<Self> {
 		u32::set_as_slice(fill_slice).and_then(|len| {
 			let mut v = Vec::with_capacity(len as usize);
-			unsafe { v.set_len(len as usize); }
+			v.resize(len as usize, 0);
+//			unsafe { v.set_len(len as usize); }
 			if fill_slice(&mut v, 4) {
 				Some(v)
 			} else {
@@ -106,7 +107,7 @@ impl<T: Slicable> NonTrivialSlicable for Vec<T> where Vec<T>: Slicable {}
 
 impl<T: NonTrivialSlicable> Slicable for Vec<T> {
 	fn from_slice(value: &[u8]) -> Option<Self> {
-		let len = Self::size_of(&value[0..4])?;
+		let len = Self::size_of(value)?;
 		let mut off = 4;
 		let mut r = Vec::new();
 		while off < len {

substrate/wasm-runtime/polkadot/src/lib.rs

@@ -37,6 +37,7 @@ pub mod runtime;
 
 use runtime_std::prelude::*;
 use codec::Slicable;
+use runtime_std::print;
 use primitives::{Block, UncheckedTransaction};
 
 /// Execute a block, with `input` being the canonical serialisation of the block. Returns the
@@ -53,4 +54,14 @@ pub fn execute_transaction(input: &[u8]) -> Vec<u8> {
 	Vec::new()
 }
 
-impl_stubs!(execute_block, execute_transaction);
+/// Run whatever tests we have.
+pub fn run_tests(input: &[u8]) -> Vec<u8> {
+	print("run_tests...");
+	let block = Block::from_slice(input).unwrap();
+	print("deserialised block.");
+	let stxs = block.transactions.iter().map(Slicable::to_vec).collect::<Vec<_>>();
+	print("reserialised transactions.");
+	[stxs.len() as u8].to_vec()
+}
+
+impl_stubs!(execute_block, execute_transaction, run_tests);

substrate/wasm-runtime/polkadot/src/runtime/staking.rs

@@ -18,6 +18,7 @@
 
 use runtime_std::prelude::*;
 use runtime_std::cell::RefCell;
+use runtime_std::print;
 use codec::KeyedVec;
 use support::{storage, StorageVec};
 use primitives::{BlockNumber, AccountID};

substrate/wasm-runtime/polkadot/src/runtime/system.rs

@@ -18,7 +18,7 @@
 //! and depositing logs.
 
 use runtime_std::prelude::*;
-use runtime_std::{mem, print, storage_root, enumerated_trie_root};
+use runtime_std::{mem, storage_root, enumerated_trie_root};
 use codec::{KeyedVec, Slicable};
 use support::{Hashable, storage, with_env};
 use primitives::{Block, BlockNumber, Hash, UncheckedTransaction, TxOrder};
@@ -76,12 +76,14 @@ pub mod internal {
 
 		// check transaction trie root represents the transactions.
 		let txs = block.transactions.iter().map(Slicable::to_vec).collect::<Vec<_>>();
-		let txs_root = enumerated_trie_root(&txs.iter().map(Vec::as_slice).collect::<Vec<_>>());
-//		println!("TR: {}", ::support::HexDisplay::from(&txs_root));
+		let txs = txs.iter().map(Vec::as_slice).collect::<Vec<_>>();
+		let txs_root = enumerated_trie_root(&txs);
 		assert!(header.transaction_root == txs_root, "Transaction trie root must be valid.");
 
 		// execute transactions
-		block.transactions.iter().for_each(execute_transaction);
+		for tx in &block.transactions {
+			execute_transaction(tx);
+		}
 
 		staking::internal::check_new_era();
 		session::internal::check_rotate_session();
@@ -89,9 +91,10 @@ pub mod internal {
 		// any final checks
 		final_checks(&block);
 
-
 		// check storage root.
-		assert!(header.state_root == storage_root(), "Storage root must match that calculated.");
+		let storage_root = storage_root();
+		debug_assert_hash(&header.state_root, &storage_root);
+		assert!(header.state_root == storage_root, "Storage root must match that calculated.");
 
 		// store the header hash in storage; we can't do it before otherwise there would be a
 		// cyclic dependency.
@@ -117,6 +120,17 @@ pub mod internal {
 		// decode parameters and dispatch
 		tx.function.dispatch(&tx.signed, &tx.input_data);
 	}
+
+	#[cfg(feature = "with-std")]
+	fn debug_assert_hash(given: &Hash, expected: &Hash) {
+		use support::HexDisplay;
+		if given != expected {
+			println!("Hash: given={}, expected={}", HexDisplay::from(given), HexDisplay::from(expected));
+		}
+	}
+
+	#[cfg(not(feature = "with-std"))]
+	fn debug_assert_hash(_given: &Hash, _expected: &Hash) {}
 }
 
 fn final_checks(_block: &Block) {

substrate/wasm-runtime/std/src/lib.rs

@@ -4,6 +4,8 @@
 #![feature(alloc)]
 #![cfg_attr(feature = "strict", deny(warnings))]
 
+#[macro_use]
+#[macro_export]
 extern crate alloc;
 
 pub use alloc::vec;