Ensure any call to disable peer has a reason (#321)

* Fix warnings in libp2p

* Force a reason when you use the fatalist disable_peer

* Print more information

* Slightly more concise ref-fu

* Tracing for figuring out what's going into genesis

* Merge

* Fxi test

substrate/Cargo.lock

@@ -2975,6 +2975,7 @@ name = "substrate-runtime-primitives"
 version = "0.1.0"
 dependencies = [
  "integer-sqrt 0.1.0 (git+https://github.com/paritytech/integer-sqrt-rs.git)",
+ "log 0.3.9 (registry+https://github.com/rust-lang/crates.io-index)",
  "num-traits 0.2.4 (registry+https://github.com/rust-lang/crates.io-index)",
  "serde 1.0.70 (registry+https://github.com/rust-lang/crates.io-index)",
  "serde_derive 1.0.64 (registry+https://github.com/rust-lang/crates.io-index)",

substrate/polkadot/network/src/lib.rs

@@ -355,7 +355,7 @@ impl PolkadotProtocol {
 					};
 
 					if !info.validator {
-						ctx.disable_peer(peer_id);
+						ctx.disable_peer(peer_id, "Unknown Polkadot-protocol reason");
 						return;
 					}
 
@@ -395,7 +395,7 @@ impl PolkadotProtocol {
 				self.pending.push(req);
 				self.dispatch_pending_requests(ctx);
 			}
-			None => ctx.disable_peer(peer_id),
+			None => ctx.disable_peer(peer_id, "Unknown Polkadot-protocol reason"),
 		}
 	}
 }
@@ -415,7 +415,7 @@ impl Specialization<Block> for PolkadotProtocol {
 
 		if let Some((ref acc_id, ref para_id)) = local_status.collating_for {
 			if self.collator_peer_id(acc_id.clone()).is_some() {
-				ctx.disable_peer(peer_id);
+				ctx.disable_peer(peer_id, "Unknown Polkadot-protocol reason");
 				return
 			}
 
@@ -501,7 +501,7 @@ impl Specialization<Block> for PolkadotProtocol {
 					Ok(msg) => self.on_polkadot_message(ctx, peer_id, raw, msg),
 					Err(e) => {
 						trace!(target: "p_net", "Bad message from {}: {}", peer_id, e);
-						ctx.disable_peer(peer_id);
+						ctx.disable_peer(peer_id, "Unknown Polkadot-protocol reason");
 					}
 				}
 			}
@@ -546,13 +546,13 @@ impl PolkadotProtocol {
 		match self.peers.get(&from) {
 			None => ctx.disconnect_peer(from),
 			Some(peer_info) => match peer_info.status.collating_for {
-				None => ctx.disable_peer(from),
+				None => ctx.disable_peer(from, "Unknown Polkadot-protocol reason"),
 				Some((ref acc_id, ref para_id)) => {
 					let structurally_valid = para_id == &collation_para && acc_id == &collated_acc;
 					if structurally_valid && collation.receipt.check_signature().is_ok() {
 						self.collators.on_collation(acc_id.clone(), relay_parent, collation)
 					} else {
-						ctx.disable_peer(from)
+						ctx.disable_peer(from, "Unknown Polkadot-protocol reason")
 					};
 				}
 			},
@@ -583,7 +583,7 @@ impl PolkadotProtocol {
 	// disconnect a collator by account-id.
 	fn disconnect_bad_collator(&self, ctx: &mut Context<Block>, account_id: AccountId) {
 		if let Some(peer_id) = self.collator_peer_id(account_id) {
-			ctx.disable_peer(peer_id)
+			ctx.disable_peer(peer_id, "Unknown Polkadot-protocol reason")
 		}
 	}
 }

substrate/polkadot/network/src/tests.rs

@@ -41,7 +41,7 @@ impl Context<Block> for TestContext {
 		unimplemented!()
 	}
 
-	fn disable_peer(&mut self, peer: PeerId) {
+	fn disable_peer(&mut self, peer: PeerId, _reason: &str) {
 		self.disabled.push(peer);
 	}
 

substrate/polkadot/runtime/src/parachains.rs

@@ -216,7 +216,6 @@ impl<T: Trait> runtime_primitives::BuildStorage for GenesisConfig<T>
 {
 	fn build_storage(mut self) -> ::std::result::Result<runtime_io::TestExternalities, String> {
 		use std::collections::HashMap;
-		use runtime_io::twox_128;
 		use codec::Encode;
 
 		self.parachains.sort_unstable_by_key(|&(ref id, _)| id.clone());
@@ -225,11 +224,11 @@ impl<T: Trait> runtime_primitives::BuildStorage for GenesisConfig<T>
 		let only_ids: Vec<_> = self.parachains.iter().map(|&(ref id, _)| id).cloned().collect();
 
 		let mut map: HashMap<_, _> = map![
-			twox_128(<Parachains<T>>::key()).to_vec() => only_ids.encode()
+			Self::hash(<Parachains<T>>::key()).to_vec() => only_ids.encode()
 		];
 
 		for (id, code) in self.parachains {
-			let key = twox_128(&<Code<T>>::key_for(&id)).to_vec();
+			let key = Self::hash(&<Code<T>>::key_for(&id)).to_vec();
 			map.insert(key, code.encode());
 		}
 

substrate/substrate/executor/src/wasm_executor.rs

@@ -27,7 +27,7 @@ use state_machine::{Externalities, CodeExecutor};
 use error::{Error, ErrorKind, Result};
 use wasm_utils::UserError;
 use primitives::{blake2_256, twox_128, twox_256};
-use primitives::hexdisplay::HexDisplay;
+use primitives::hexdisplay::{HexDisplay, ascii_format};
 use primitives::sandbox as sandbox_primitives;
 use triehash::ordered_trie_root;
 use sandbox;
@@ -130,24 +130,6 @@ impl ReadPrimitive<u32> for MemoryInstance {
 	}
 }
 
-fn ascii_format(asciish: &[u8]) -> String {
-	let mut r = String::new();
-	let mut latch = false;
-	for c in asciish {
-		match (latch, *c) {
-			(false, 32...127) => r.push(*c as char),
-			_ => {
-				if !latch {
-					r.push('#');
-					latch = true;
-				}
-				r.push_str(&format!("{:02x}", *c));
-			}
-		}
-	}
-	r
-}
-
 impl_function_executor!(this: FunctionExecutor<'e, E>,
 	ext_print_utf8(utf8_data: *const u8, utf8_len: u32) => {
 		if let Ok(utf8) = this.memory.get(utf8_data, utf8_len as usize) {

substrate/substrate/network-libp2p/src/custom_proto.rs

@@ -124,7 +124,7 @@ where C: AsyncRead + AsyncWrite + 'static,		// TODO: 'static :-/
 		self,
 		socket: C,
 		protocol_version: Self::UpgradeIdentifier,
-		endpoint: Endpoint,
+		_endpoint: Endpoint,
 		remote_addr: Maf
 	) -> Self::Future {
 		let packet_count = self.supported_versions

substrate/substrate/network-libp2p/src/network_state.rs

@@ -236,6 +236,7 @@ impl NetworkState {
 
 	/// Reports the ping of the peer. Returned later by `session_info()`.
 	/// No-op if the `peer_id` is not valid/expired.
+	#[allow(dead_code)]
 	pub fn report_ping(&self, peer_id: PeerId, ping: Duration) {
 		let connections = self.connections.read();
 		let info = match connections.info_by_peer.get(&peer_id) {
@@ -610,10 +611,15 @@ impl NetworkState {
 	/// list of disabled peers, and  drops any existing connections if
 	/// necessary (ie. drops the sender that was passed to
 	/// `accept_custom_proto`).
-	pub fn disable_peer(&self, peer_id: PeerId) {
+	pub fn disable_peer(&self, peer_id: PeerId, reason: &str) {
 		// TODO: what do we do if the peer is reserved?
 		let mut connections = self.connections.write();
 		let peer_info = if let Some(peer_info) = connections.info_by_peer.remove(&peer_id) {
+			if let (&Some(ref client_version), &Some(ref remote_address)) = (&peer_info.client_version, &peer_info.remote_address) {
+				info!(target: "network", "Peer {} (version: {}, address: {}) disabled. {}", peer_id, client_version, remote_address, reason);
+			} else {
+				info!(target: "network", "Peer {} disabled. {}", peer_id, reason);
+			}
 			let old = connections.peer_by_nodeid.remove(&peer_info.id);
 			debug_assert_eq!(old, Some(peer_id));
 			peer_info
@@ -870,7 +876,7 @@ mod tests {
 			mpsc::unbounded().0
 		).unwrap();
 
-		state.disable_peer(peer_id);
+		state.disable_peer(peer_id, "Just a test");
 
 		assert!(state.accept_custom_proto(
 			example_peer.clone(),

substrate/substrate/network-libp2p/src/service.rs

@@ -328,9 +328,9 @@ impl NetworkContext for NetworkContextImpl {
 		}
 	}
 
-	fn disable_peer(&self, peer: PeerId) {
-		debug!(target: "sub-libp2p", "Request to disable peer {}", peer);
-		self.inner.network_state.disable_peer(peer);
+	fn disable_peer(&self, peer: PeerId, reason: &str) {
+		debug!(target: "sub-libp2p", "Request to disable peer {} for reason {}", peer, reason);
+		self.inner.network_state.disable_peer(peer, reason);
 	}
 
 	fn disconnect_peer(&self, peer: PeerId) {

substrate/substrate/network-libp2p/src/traits.rs

@@ -225,7 +225,7 @@ pub trait NetworkContext {
 	fn respond(&self, packet_id: PacketId, data: Vec<u8>) -> Result<(), Error>;
 
 	/// Disconnect a peer and prevent it from connecting again.
-	fn disable_peer(&self, peer: PeerId);
+	fn disable_peer(&self, peer: PeerId, reason: &str);
 
 	/// Disconnect peer. Reconnect can be attempted later.
 	fn disconnect_peer(&self, peer: PeerId);
@@ -262,8 +262,8 @@ impl<'a, T> NetworkContext for &'a T where T: ?Sized + NetworkContext {
 		(**self).respond(packet_id, data)
 	}
 
-	fn disable_peer(&self, peer: PeerId) {
-		(**self).disable_peer(peer)
+	fn disable_peer(&self, peer: PeerId, reason: &str) {
+		(**self).disable_peer(peer, reason)
 	}
 
 	fn disconnect_peer(&self, peer: PeerId) {

substrate/substrate/network-libp2p/src/transport.rs

@@ -57,6 +57,7 @@ pub fn build_transport(
 /// Specifies whether unencrypted communications are allowed or denied.
 #[derive(Debug, Copy, Clone)]
 pub enum UnencryptedAllowed {
+	#[allow(dead_code)]
 	Allowed,
 	Denied,
 }

substrate/substrate/network/src/io.rs

@@ -20,7 +20,7 @@ use network_libp2p::{NetworkContext, PeerId, Error as NetworkError, SessionInfo}
 /// Provides peer connection management and an interface to the blockchain client.
 pub trait SyncIo {
 	/// Disable a peer
-	fn disable_peer(&mut self, peer_id: PeerId);
+	fn disable_peer(&mut self, peer_id: PeerId, reason: &str);
 	/// Disconnect peer
 	fn disconnect_peer(&mut self, peer_id: PeerId);
 	/// Send a packet to a peer.
@@ -50,8 +50,8 @@ impl<'s> NetSyncIo<'s> {
 }
 
 impl<'s> SyncIo for NetSyncIo<'s> {
-	fn disable_peer(&mut self, peer_id: PeerId) {
-		self.network.disable_peer(peer_id);
+	fn disable_peer(&mut self, peer_id: PeerId, reason: &str) {
+		self.network.disable_peer(peer_id, reason);
 	}
 
 	fn disconnect_peer(&mut self, peer_id: PeerId) {

substrate/substrate/network/src/protocol.rs

@@ -110,7 +110,7 @@ pub trait Context<B: BlockT> {
 	fn client(&self) -> &::chain::Client<B>;
 
 	/// Disable a peer
-	fn disable_peer(&mut self, peer_id: PeerId);
+	fn disable_peer(&mut self, peer_id: PeerId, reason: &str);
 
 	/// Disconnect peer
 	fn disconnect_peer(&mut self, peer_id: PeerId);
@@ -141,8 +141,8 @@ impl<'a, B: BlockT + 'a> ProtocolContext<'a, B> {
 		send_message(&self.context_data.peers, self.io, peer_id, message)
 	}
 
-	pub fn disable_peer(&mut self, peer_id: PeerId) {
-		self.io.disable_peer(peer_id);
+	pub fn disable_peer(&mut self, peer_id: PeerId, reason: &str) {
+		self.io.disable_peer(peer_id, reason);
 	}
 
 	pub fn disconnect_peer(&mut self, peer_id: PeerId) {
@@ -167,8 +167,8 @@ impl<'a, B: BlockT + 'a> Context<B> for ProtocolContext<'a, B> {
 		ProtocolContext::send_message(self, peer_id, message);
 	}
 
-	fn disable_peer(&mut self, peer_id: PeerId) {
-		ProtocolContext::disable_peer(self, peer_id);
+	fn disable_peer(&mut self, peer_id: PeerId, reason: &str) {
+		ProtocolContext::disable_peer(self, peer_id, reason);
 	}
 
 	fn disconnect_peer(&mut self, peer_id: PeerId) {
@@ -237,9 +237,8 @@ impl<B: BlockT, S: Specialization<B>> Protocol<B, S> {
 		let message: Message<B> = match serde_json::from_slice(data) {
 			Ok(m) => m,
 			Err(e) => {
-				debug!(target: "sync", "Invalid packet from {}: {}", peer_id, e);
 				trace!(target: "sync", "Invalid packet: {}", String::from_utf8_lossy(data));
-				io.disable_peer(peer_id);
+				io.disable_peer(peer_id, &format!("Peer sent us a packet with invalid format ({})", e));
 				return;
 			}
 		};
@@ -255,14 +254,12 @@ impl<B: BlockT, S: Specialization<B>> Protocol<B, S> {
 						match mem::replace(&mut peer.block_request, None) {
 							Some(r) => r,
 							None => {
-								debug!(target: "sync", "Unexpected response packet from {}", peer_id);
-								io.disable_peer(peer_id);
+								io.disable_peer(peer_id, "Unexpected response packet received from peer");
 								return;
 							}
 						}
 					} else {
-						debug!(target: "sync", "Unexpected packet from {}", peer_id);
-						io.disable_peer(peer_id);
+						io.disable_peer(peer_id, "Unexpected packet received from peer");
 						return;
 					}
 				};
@@ -428,13 +425,11 @@ impl<B: BlockT, S: Specialization<B>> Protocol<B, S> {
 				return;
 			}
 			if status.genesis_hash != self.genesis_hash {
-				io.disable_peer(peer_id);
-				trace!(target: "sync", "Peer {} genesis hash mismatch (ours: {}, theirs: {})", peer_id, self.genesis_hash, status.genesis_hash);
+				io.disable_peer(peer_id, &format!("Peer is on different chain (our genesis: {} theirs: {})", self.genesis_hash, status.genesis_hash));
 				return;
 			}
 			if status.version != CURRENT_VERSION {
-				io.disable_peer(peer_id);
-				trace!(target: "sync", "Peer {} unsupported eth protocol ({})", peer_id, status.version);
+				io.disable_peer(peer_id, &format!("Peer using unsupported protocol version {}", status.version));
 				return;
 			}
 

substrate/substrate/network/src/sync.rs

@@ -118,12 +118,10 @@ impl<B: BlockT> ChainSync<B> {
 					protocol.disconnect_peer(peer_id);
 				},
 				(Ok(BlockStatus::KnownBad), _) => {
-					debug!(target:"sync", "New peer with known bad best block {} ({}).", info.best_hash, info.best_number);
-					protocol.disable_peer(peer_id);
+					protocol.disable_peer(peer_id, &format!("New peer with known bad best block {} ({}).", info.best_hash, info.best_number));
 				},
 				(Ok(BlockStatus::Unknown), b) if b == As::sa(0) => {
-					debug!(target:"sync", "New peer with unknown genesis hash {} ({}).", info.best_hash, info.best_number);
-					protocol.disable_peer(peer_id);
+					protocol.disable_peer(peer_id, &format!("New peer with unknown genesis hash {} ({}).", info.best_hash, info.best_number));
 				},
 				(Ok(BlockStatus::Unknown), _) => {
 					let our_best = self.best_queued_number;
@@ -206,7 +204,7 @@ impl<B: BlockT> ChainSync<B> {
 								},
 								Ok(_) => { // genesis mismatch
 									trace!(target:"sync", "Ancestry search: genesis mismatch for peer {}", peer_id);
-									protocol.disable_peer(peer_id);
+									protocol.disable_peer(peer_id, "Ancestry search: genesis mismatch for peer");
 									return;
 								},
 								Err(e) => {
@@ -278,8 +276,7 @@ impl<B: BlockT> ChainSync<B> {
 							return;
 						},
 						Ok(ImportResult::KnownBad) => {
-							debug!(target: "sync", "Bad block {}: {:?}", number, hash);
-							protocol.disable_peer(origin); //TODO: use persistent ID
+							protocol.disable_peer(origin, &format!("Peer gave us a bad block {}: {:?}", number, hash)); //TODO: use persistent ID
 							self.restart(protocol);
 							return;
 						}
@@ -291,13 +288,11 @@ impl<B: BlockT> ChainSync<B> {
 					}
 				},
 				(None, _) => {
-					debug!(target: "sync", "Header {} was not provided by {} ", block.hash, origin);
-					protocol.disable_peer(origin); //TODO: use persistent ID
+					protocol.disable_peer(origin, &format!("Header {} was not provided by peer ", block.hash)); //TODO: use persistent ID
 					return;
 				},
 				(_, None) => {
-					debug!(target: "sync", "Justification set for block {} was not provided by {} ", block.hash, origin);
-					protocol.disable_peer(origin); //TODO: use persistent ID
+					protocol.disable_peer(origin, &format!("Justification set for block {} was not provided by peer", block.hash)); //TODO: use persistent ID
 					return;
 				}
 			}

substrate/substrate/network/src/test/mod.rs

@@ -80,7 +80,7 @@ impl<'p> Drop for TestIo<'p> {
 }
 
 impl<'p> SyncIo for TestIo<'p> {
-	fn disable_peer(&mut self, peer_id: PeerId) {
+	fn disable_peer(&mut self, peer_id: PeerId, _reason: &str) {
 		self.disconnect_peer(peer_id);
 	}
 

substrate/substrate/primitives/src/hexdisplay.rs

@@ -62,3 +62,23 @@ macro_rules! impl_non_endians {
 impl_non_endians!([u8; 1], [u8; 2], [u8; 3], [u8; 4], [u8; 5], [u8; 6], [u8; 7], [u8; 8],
 	[u8; 10], [u8; 12], [u8; 14], [u8; 16], [u8; 20], [u8; 24], [u8; 28], [u8; 32], [u8; 40],
 	[u8; 48], [u8; 56], [u8; 64], [u8; 80], [u8; 96], [u8; 112], [u8; 128]);
+
+/// Format into ASCII + # + hex, suitable for storage key preimages.
+pub fn ascii_format(asciish: &[u8]) -> String {
+	let mut r = String::new();
+	let mut latch = false;
+	for c in asciish {
+		match (latch, *c) {
+			(false, 32...127) => r.push(*c as char),
+			_ => {
+				if !latch {
+					r.push('#');
+					latch = true;
+				}
+				r.push_str(&format!("{:02x}", *c));
+			}
+		}
+	}
+	r
+}
+

substrate/substrate/runtime/council/src/lib.rs

@@ -592,23 +592,22 @@ impl<T: Trait> primitives::BuildStorage for GenesisConfig<T>
 {
 	fn build_storage(self) -> ::std::result::Result<runtime_io::TestExternalities, String> {
 		use codec::Encode;
-		use runtime_io::twox_128;
 
 		Ok(map![
-			twox_128(<CandidacyBond<T>>::key()).to_vec() => self.candidacy_bond.encode(),
-			twox_128(<VotingBond<T>>::key()).to_vec() => self.voter_bond.encode(),
-			twox_128(<PresentSlashPerVoter<T>>::key()).to_vec() => self.present_slash_per_voter.encode(),
-			twox_128(<CarryCount<T>>::key()).to_vec() => self.carry_count.encode(),
-			twox_128(<PresentationDuration<T>>::key()).to_vec() => self.presentation_duration.encode(),
-			twox_128(<VotingPeriod<T>>::key()).to_vec() => self.approval_voting_period.encode(),
-			twox_128(<TermDuration<T>>::key()).to_vec() => self.term_duration.encode(),
-			twox_128(<DesiredSeats<T>>::key()).to_vec() => self.desired_seats.encode(),
-			twox_128(<InactiveGracePeriod<T>>::key()).to_vec() => self.inactive_grace_period.encode(),
-			twox_128(<ActiveCouncil<T>>::key()).to_vec() => self.active_council.encode(),
+			Self::hash(<CandidacyBond<T>>::key()).to_vec() => self.candidacy_bond.encode(),
+			Self::hash(<VotingBond<T>>::key()).to_vec() => self.voter_bond.encode(),
+			Self::hash(<PresentSlashPerVoter<T>>::key()).to_vec() => self.present_slash_per_voter.encode(),
+			Self::hash(<CarryCount<T>>::key()).to_vec() => self.carry_count.encode(),
+			Self::hash(<PresentationDuration<T>>::key()).to_vec() => self.presentation_duration.encode(),
+			Self::hash(<VotingPeriod<T>>::key()).to_vec() => self.approval_voting_period.encode(),
+			Self::hash(<TermDuration<T>>::key()).to_vec() => self.term_duration.encode(),
+			Self::hash(<DesiredSeats<T>>::key()).to_vec() => self.desired_seats.encode(),
+			Self::hash(<InactiveGracePeriod<T>>::key()).to_vec() => self.inactive_grace_period.encode(),
+			Self::hash(<ActiveCouncil<T>>::key()).to_vec() => self.active_council.encode(),
 
-			twox_128(<voting::CooloffPeriod<T>>::key()).to_vec() => self.cooloff_period.encode(),
-			twox_128(<voting::VotingPeriod<T>>::key()).to_vec() => self.voting_period.encode(),
-			twox_128(<voting::Proposals<T>>::key()).to_vec() => vec![0u8; 0].encode()
+			Self::hash(<voting::CooloffPeriod<T>>::key()).to_vec() => self.cooloff_period.encode(),
+			Self::hash(<voting::VotingPeriod<T>>::key()).to_vec() => self.voting_period.encode(),
+			Self::hash(<voting::Proposals<T>>::key()).to_vec() => vec![0u8; 0].encode()
 		])
 	}
 }

substrate/substrate/runtime/democracy/src/lib.rs

@@ -340,15 +340,14 @@ impl<T: Trait> primitives::BuildStorage for GenesisConfig<T>
 {
 	fn build_storage(self) -> ::std::result::Result<runtime_io::TestExternalities, String> {
 		use codec::Encode;
-		use runtime_io::twox_128;
 
 		Ok(map![
-			twox_128(<LaunchPeriod<T>>::key()).to_vec() => self.launch_period.encode(),
-			twox_128(<VotingPeriod<T>>::key()).to_vec() => self.voting_period.encode(),
-			twox_128(<MinimumDeposit<T>>::key()).to_vec() => self.minimum_deposit.encode(),
-			twox_128(<ReferendumCount<T>>::key()).to_vec() => (0 as ReferendumIndex).encode(),
-			twox_128(<NextTally<T>>::key()).to_vec() => (0 as ReferendumIndex).encode(),
-			twox_128(<PublicPropCount<T>>::key()).to_vec() => (0 as PropIndex).encode()
+			Self::hash(<LaunchPeriod<T>>::key()).to_vec() => self.launch_period.encode(),
+			Self::hash(<VotingPeriod<T>>::key()).to_vec() => self.voting_period.encode(),
+			Self::hash(<MinimumDeposit<T>>::key()).to_vec() => self.minimum_deposit.encode(),
+			Self::hash(<ReferendumCount<T>>::key()).to_vec() => (0 as ReferendumIndex).encode(),
+			Self::hash(<NextTally<T>>::key()).to_vec() => (0 as ReferendumIndex).encode(),
+			Self::hash(<PublicPropCount<T>>::key()).to_vec() => (0 as PropIndex).encode()
 		])
 	}
 }

substrate/substrate/runtime/primitives/Cargo.toml

@@ -13,6 +13,7 @@ substrate-primitives = { path = "../../primitives", default_features = false }
 substrate-runtime-std = { path = "../../runtime-std", default_features = false }
 substrate-runtime-io = { path = "../../runtime-io", default_features = false }
 substrate-runtime-support = { path = "../../runtime-support", default_features = false }
+log = {version = "0.3", optional = true }
 
 [dev-dependencies]
 serde_json = "1.0"
@@ -23,6 +24,7 @@ std = [
 	"num-traits/std",
 	"serde",
 	"serde_derive",
+	"log",
 	"substrate-runtime-std/std",
 	"substrate-runtime-io/std",
 	"substrate-runtime-support/std",

substrate/substrate/runtime/primitives/src/lib.rs

@@ -26,6 +26,10 @@ extern crate serde;
 #[macro_use]
 extern crate serde_derive;
 
+#[cfg(feature = "std")]
+#[macro_use]
+extern crate log;
+
 extern crate num_traits;
 extern crate integer_sqrt;
 extern crate substrate_runtime_std as rstd;
@@ -43,6 +47,9 @@ use std::collections::HashMap;
 use rstd::prelude::*;
 use substrate_primitives::hash::{H256, H512};
 
+#[cfg(feature = "std")]
+use substrate_primitives::hexdisplay::ascii_format;
+
 #[cfg(feature = "std")]
 pub mod testing;
 
@@ -59,6 +66,11 @@ pub type StorageMap = HashMap<Vec<u8>, Vec<u8>>;
 /// Complex storage builder stuff.
 #[cfg(feature = "std")]
 pub trait BuildStorage {
+	fn hash(data: &[u8]) -> [u8; 16] {
+		let r = runtime_io::twox_128(data);
+		trace!(target: "build_storage", "{} <= {}", substrate_primitives::hexdisplay::HexDisplay::from(&r), ascii_format(data));
+		r
+	}
 	fn build_storage(self) -> Result<StorageMap, String>;
 }
 

substrate/substrate/runtime/session/src/lib.rs

@@ -245,15 +245,14 @@ impl<T: Trait> Default for GenesisConfig<T> {
 impl<T: Trait> primitives::BuildStorage for GenesisConfig<T>
 {
 	fn build_storage(self) -> ::std::result::Result<runtime_io::TestExternalities, String> {
-		use runtime_io::twox_128;
 		use codec::Encode;
 		use primitives::traits::As;
 		Ok(map![
-			twox_128(<SessionLength<T>>::key()).to_vec() => self.session_length.encode(),
-			twox_128(<CurrentIndex<T>>::key()).to_vec() => T::BlockNumber::sa(0).encode(),
-			twox_128(<CurrentStart<T>>::key()).to_vec() => T::Moment::zero().encode(),
-			twox_128(<Validators<T>>::key()).to_vec() => self.validators.encode(),
-			twox_128(<BrokenPercentLate<T>>::key()).to_vec() => self.broken_percent_late.encode()
+			Self::hash(<SessionLength<T>>::key()).to_vec() => self.session_length.encode(),
+			Self::hash(<CurrentIndex<T>>::key()).to_vec() => T::BlockNumber::sa(0).encode(),
+			Self::hash(<CurrentStart<T>>::key()).to_vec() => T::Moment::zero().encode(),
+			Self::hash(<Validators<T>>::key()).to_vec() => self.validators.encode(),
+			Self::hash(<BrokenPercentLate<T>>::key()).to_vec() => self.broken_percent_late.encode()
 		])
 	}
 }

substrate/substrate/runtime/staking/src/genesis_config.rs

@@ -19,7 +19,6 @@
 #![cfg(feature = "std")]
 
 use rstd::prelude::*;
-use runtime_io::twox_128;
 use codec::Encode;
 use runtime_support::{StorageValue, StorageMap};
 use primitives::traits::{Zero, As};
@@ -127,31 +126,31 @@ impl<T: Trait> primitives::BuildStorage for GenesisConfig<T> {
 		let total_stake: T::Balance = self.balances.iter().fold(Zero::zero(), |acc, &(_, n)| acc + n);
 
 		let mut r: runtime_io::TestExternalities = map![
-			twox_128(<NextEnumSet<T>>::key()).to_vec() => T::AccountIndex::sa(self.balances.len() / ENUM_SET_SIZE).encode(),
-			twox_128(<Intentions<T>>::key()).to_vec() => self.intentions.encode(),
-			twox_128(<SessionsPerEra<T>>::key()).to_vec() => self.sessions_per_era.encode(),
-			twox_128(<ValidatorCount<T>>::key()).to_vec() => self.validator_count.encode(),
-			twox_128(<BondingDuration<T>>::key()).to_vec() => self.bonding_duration.encode(),
-			twox_128(<TransactionBaseFee<T>>::key()).to_vec() => self.transaction_base_fee.encode(),
-			twox_128(<TransactionByteFee<T>>::key()).to_vec() => self.transaction_byte_fee.encode(),
-			twox_128(<TransferFee<T>>::key()).to_vec() => self.transfer_fee.encode(),
-			twox_128(<CreationFee<T>>::key()).to_vec() => self.creation_fee.encode(),
-			twox_128(<ContractFee<T>>::key()).to_vec() => self.contract_fee.encode(),
-			twox_128(<ExistentialDeposit<T>>::key()).to_vec() => self.existential_deposit.encode(),
-			twox_128(<ReclaimRebate<T>>::key()).to_vec() => self.reclaim_rebate.encode(),
-			twox_128(<CurrentEra<T>>::key()).to_vec() => self.current_era.encode(),
-			twox_128(<SessionReward<T>>::key()).to_vec() => self.session_reward.encode(),
-			twox_128(<EarlyEraSlash<T>>::key()).to_vec() => self.early_era_slash.encode(),
-			twox_128(<TotalStake<T>>::key()).to_vec() => total_stake.encode()
+			Self::hash(<NextEnumSet<T>>::key()).to_vec() => T::AccountIndex::sa(self.balances.len() / ENUM_SET_SIZE).encode(),
+			Self::hash(<Intentions<T>>::key()).to_vec() => self.intentions.encode(),
+			Self::hash(<SessionsPerEra<T>>::key()).to_vec() => self.sessions_per_era.encode(),
+			Self::hash(<ValidatorCount<T>>::key()).to_vec() => self.validator_count.encode(),
+			Self::hash(<BondingDuration<T>>::key()).to_vec() => self.bonding_duration.encode(),
+			Self::hash(<TransactionBaseFee<T>>::key()).to_vec() => self.transaction_base_fee.encode(),
+			Self::hash(<TransactionByteFee<T>>::key()).to_vec() => self.transaction_byte_fee.encode(),
+			Self::hash(<TransferFee<T>>::key()).to_vec() => self.transfer_fee.encode(),
+			Self::hash(<CreationFee<T>>::key()).to_vec() => self.creation_fee.encode(),
+			Self::hash(<ContractFee<T>>::key()).to_vec() => self.contract_fee.encode(),
+			Self::hash(<ExistentialDeposit<T>>::key()).to_vec() => self.existential_deposit.encode(),
+			Self::hash(<ReclaimRebate<T>>::key()).to_vec() => self.reclaim_rebate.encode(),
+			Self::hash(<CurrentEra<T>>::key()).to_vec() => self.current_era.encode(),
+			Self::hash(<SessionReward<T>>::key()).to_vec() => self.session_reward.encode(),
+			Self::hash(<EarlyEraSlash<T>>::key()).to_vec() => self.early_era_slash.encode(),
+			Self::hash(<TotalStake<T>>::key()).to_vec() => total_stake.encode()
 		];
 
 		let ids: Vec<_> = self.balances.iter().map(|x| x.0.clone()).collect();
 		for i in 0..(ids.len() + ENUM_SET_SIZE - 1) / ENUM_SET_SIZE {
-			r.insert(twox_128(&<EnumSet<T>>::key_for(T::AccountIndex::sa(i))).to_vec(),
+			r.insert(Self::hash(&<EnumSet<T>>::key_for(T::AccountIndex::sa(i))).to_vec(),
 				ids[i * ENUM_SET_SIZE..ids.len().min((i + 1) * ENUM_SET_SIZE)].to_owned().encode());
 		}
 		for (who, value) in self.balances.into_iter() {
-			r.insert(twox_128(&<FreeBalance<T>>::key_for(who)).to_vec(), value.encode());
+			r.insert(Self::hash(&<FreeBalance<T>>::key_for(who)).to_vec(), value.encode());
 		}
 		Ok(r)
 	}

substrate/substrate/runtime/system/src/lib.rs

@@ -208,15 +208,14 @@ impl<T: Trait> Default for GenesisConfig<T> {
 impl<T: Trait> primitives::BuildStorage for GenesisConfig<T>
 {
 	fn build_storage(self) -> Result<runtime_io::TestExternalities, String> {
-		use runtime_io::twox_128;
 		use codec::Encode;
 
 		Ok(map![
-			twox_128(&<BlockHash<T>>::key_for(T::BlockNumber::zero())).to_vec() => [69u8; 32].encode(),
-			twox_128(<Number<T>>::key()).to_vec() => 1u64.encode(),
-			twox_128(<ParentHash<T>>::key()).to_vec() => [69u8; 32].encode(),
-			twox_128(<RandomSeed<T>>::key()).to_vec() => [0u8; 32].encode(),
-			twox_128(<ExtrinsicIndex<T>>::key()).to_vec() => [0u8; 4].encode()
+			Self::hash(&<BlockHash<T>>::key_for(T::BlockNumber::zero())).to_vec() => [69u8; 32].encode(),
+			Self::hash(<Number<T>>::key()).to_vec() => 1u64.encode(),
+			Self::hash(<ParentHash<T>>::key()).to_vec() => [69u8; 32].encode(),
+			Self::hash(<RandomSeed<T>>::key()).to_vec() => [0u8; 32].encode(),
+			Self::hash(<ExtrinsicIndex<T>>::key()).to_vec() => [0u8; 4].encode()
 		])
 	}
 }

substrate/substrate/runtime/timestamp/src/lib.rs

@@ -127,11 +127,10 @@ impl<T: Trait> Default for GenesisConfig<T> {
 impl<T: Trait> runtime_primitives::BuildStorage for GenesisConfig<T>
 {
 	fn build_storage(self) -> ::std::result::Result<runtime_primitives::StorageMap, String> {
-		use runtime_io::twox_128;
 		use codec::Encode;
 		Ok(map![
-			twox_128(<BlockPeriod<T>>::key()).to_vec() => self.period.encode(),
-			twox_128(<Now<T>>::key()).to_vec() => T::Moment::sa(0).encode()
+			Self::hash(<BlockPeriod<T>>::key()).to_vec() => self.period.encode(),
+			Self::hash(<Now<T>>::key()).to_vec() => T::Moment::sa(0).encode()
 		])
 	}
 }