slog-rs logging (#171)

* added global slog instance, changed all logging macro formats to include logger instance
* adding configuration to logging, allowing for multiple log outputs
* updates to test, changes to build docs
* rustfmt
* moving logging functions into util crate

chain/src/chain.rs

@@ -28,6 +28,7 @@ use pipe;
 use store;
 use sumtree;
 use types::*;
+use util::LOGGER;
 
 use core::global::{MiningParameterMode, MINING_PARAMETER_MODE};
 
@@ -69,12 +70,11 @@ impl Chain {
 	/// on the current chain head to make sure it exists and creates one based
 	/// on
 	/// the genesis block if necessary.
-	pub fn init(
-		db_root: String,
-		adapter: Arc<ChainAdapter>,
-		gen_block: Option<Block>,
-		pow_verifier: fn(&BlockHeader, u32) -> bool,
-	) -> Result<Chain, Error> {
+	pub fn init(db_root: String,
+	            adapter: Arc<ChainAdapter>,
+	            gen_block: Option<Block>,
+	            pow_verifier: fn(&BlockHeader, u32) -> bool)
+	            -> Result<Chain, Error> {
 		let chain_store = store::ChainKVStore::new(db_root.clone())?;
 
 		// check if we have a head in store, otherwise the genesis block is it
@@ -92,7 +92,7 @@ impl Chain {
 				// saving a new tip based on genesis
 				let tip = Tip::new(gen.hash());
 				chain_store.save_head(&tip)?;
-				info!("Saved genesis block with hash {}", gen.hash());
+				info!(LOGGER, "Saved genesis block with hash {}", gen.hash());
 				tip
 			}
 			Err(e) => return Err(Error::StoreErr(e)),
@@ -138,6 +138,7 @@ impl Chain {
 			}
 			Err(ref e) => {
 				info!(
+					LOGGER,
 					"Rejected block {} at {} : {:?}",
 					b.hash(),
 					b.header.height,
@@ -151,11 +152,10 @@ impl Chain {
 
 	/// Attempt to add a new header to the header chain. Only necessary during
 	/// sync.
-	pub fn process_block_header(
-		&self,
-		bh: &BlockHeader,
-		opts: Options,
-	) -> Result<Option<Tip>, Error> {
+	pub fn process_block_header(&self,
+	                            bh: &BlockHeader,
+	                            opts: Options)
+	                            -> Result<Option<Tip>, Error> {
 
 		let head = self.store.get_header_head().map_err(&Error::StoreErr)?;
 		let ctx = self.ctx_from_head(head, opts);
@@ -213,9 +213,9 @@ impl Chain {
 		let sumtrees = self.sumtrees.read().unwrap();
 		let is_unspent = sumtrees.is_unspent(output_ref)?;
 		if is_unspent {
-			self.store.get_output_by_commit(output_ref).map_err(
-				&Error::StoreErr,
-			)
+			self.store
+				.get_output_by_commit(output_ref)
+				.map_err(&Error::StoreErr)
 		} else {
 			Err(Error::OutputNotFound)
 		}
@@ -266,16 +266,15 @@ impl Chain {
 
 	/// Gets the block header at the provided height
 	pub fn get_header_by_height(&self, height: u64) -> Result<BlockHeader, Error> {
-		self.store.get_header_by_height(height).map_err(
-			&Error::StoreErr,
-		)
+		self.store
+			.get_header_by_height(height)
+			.map_err(&Error::StoreErr)
 	}
 
 	/// Gets the block header by the provided output commitment
-	pub fn get_block_header_by_output_commit(
-		&self,
-		commit: &Commitment,
-	) -> Result<BlockHeader, Error> {
+	pub fn get_block_header_by_output_commit(&self,
+	                                         commit: &Commitment)
+	                                         -> Result<BlockHeader, Error> {
 		self.store
 			.get_block_header_by_output_commit(commit)
 			.map_err(&Error::StoreErr)

chain/src/lib.rs

@@ -24,13 +24,14 @@
 extern crate bitflags;
 extern crate byteorder;
 #[macro_use]
-extern crate log;
+extern crate slog;
 extern crate serde;
 #[macro_use]
 extern crate serde_derive;
 extern crate time;
 
 extern crate grin_core as core;
+extern crate grin_util as util;
 extern crate grin_store;
 extern crate secp256k1zkp as secp;
 

chain/src/pipe.rs

@@ -27,6 +27,7 @@ use types::*;
 use store;
 use sumtree;
 use core::global;
+use util::LOGGER;
 
 /// Contextual information required to process a new block and either reject or
 /// accept it.
@@ -53,6 +54,7 @@ pub fn process_block(b: &Block, mut ctx: BlockContext) -> Result<Option<Tip>, Er
 	// spend resources reading the full block when its header is invalid
 
 	info!(
+		LOGGER,
 		"Starting validation pipeline for block {} at {} with {} inputs and {} outputs.",
 		b.hash(),
 		b.header.height,
@@ -74,6 +76,7 @@ pub fn process_block(b: &Block, mut ctx: BlockContext) -> Result<Option<Tip>, Er
 
 		validate_block(b, &mut ctx, &mut extension)?;
 		debug!(
+			LOGGER,
 			"Block at {} with hash {} is valid, going to save and append.",
 			b.header.height,
 			b.hash()
@@ -92,6 +95,7 @@ pub fn process_block(b: &Block, mut ctx: BlockContext) -> Result<Option<Tip>, Er
 pub fn process_block_header(bh: &BlockHeader, mut ctx: BlockContext) -> Result<Option<Tip>, Error> {
 
 	info!(
+		LOGGER,
 		"Starting validation pipeline for block header {} at {}.",
 		bh.hash(),
 		bh.height
@@ -135,6 +139,7 @@ fn validate_header(header: &BlockHeader, ctx: &mut BlockContext) -> Result<(), E
 	// check version, enforces scheduled hard fork
 	if !consensus::valid_header_version(header.height, header.version) {
 		error!(
+			LOGGER,
 			"Invalid block header version received ({}), maybe update Grin?",
 			header.version
 		);
@@ -142,8 +147,7 @@ fn validate_header(header: &BlockHeader, ctx: &mut BlockContext) -> Result<(), E
 	}
 
 	if header.timestamp >
-		time::now_utc() + time::Duration::seconds(12 * (consensus::BLOCK_TIME_SEC as i64))
-	{
+	   time::now_utc() + time::Duration::seconds(12 * (consensus::BLOCK_TIME_SEC as i64)) {
 		// refuse blocks more than 12 blocks intervals in future (as in bitcoin)
 		// TODO add warning in p2p code if local time is too different from peers
 		return Err(Error::InvalidBlockTime);
@@ -155,16 +159,16 @@ fn validate_header(header: &BlockHeader, ctx: &mut BlockContext) -> Result<(), E
 		} else {
 			consensus::DEFAULT_SIZESHIFT
 		};
-		debug!("Validating block with cuckoo size {}", cycle_size);
+		debug!(LOGGER, "Validating block with cuckoo size {}", cycle_size);
 		if !(ctx.pow_verifier)(header, cycle_size as u32) {
 			return Err(Error::InvalidPow);
 		}
 	}
 
 	// first I/O cost, better as late as possible
-	let prev = try!(ctx.store.get_block_header(&header.previous).map_err(
-		&Error::StoreErr,
-	));
+	let prev = try!(ctx.store
+	                    .get_block_header(&header.previous)
+	                    .map_err(&Error::StoreErr));
 
 	if header.height != prev.height + 1 {
 		return Err(Error::InvalidBlockHeight);
@@ -183,9 +187,8 @@ fn validate_header(header: &BlockHeader, ctx: &mut BlockContext) -> Result<(), E
 		}
 
 		let diff_iter = store::DifficultyIter::from(header.previous, ctx.store.clone());
-		let difficulty = consensus::next_difficulty(diff_iter).map_err(|e| {
-			Error::Other(e.to_string())
-		})?;
+		let difficulty = consensus::next_difficulty(diff_iter)
+			.map_err(|e| Error::Other(e.to_string()))?;
 		if header.difficulty < difficulty {
 			return Err(Error::DifficultyTooLow);
 		}
@@ -195,11 +198,10 @@ fn validate_header(header: &BlockHeader, ctx: &mut BlockContext) -> Result<(), E
 }
 
 /// Fully validate the block content.
-fn validate_block(
-	b: &Block,
-	ctx: &mut BlockContext,
-	ext: &mut sumtree::Extension,
-) -> Result<(), Error> {
+fn validate_block(b: &Block,
+                  ctx: &mut BlockContext,
+                  ext: &mut sumtree::Extension)
+                  -> Result<(), Error> {
 	if b.header.height > ctx.head.height + 1 {
 		return Err(Error::Orphan);
 	}
@@ -248,11 +250,7 @@ fn validate_block(
 		if forked_block.header.height > 0 {
 			let last_output = &forked_block.outputs[forked_block.outputs.len() - 1];
 			let last_kernel = &forked_block.kernels[forked_block.kernels.len() - 1];
-			ext.rewind(
-				forked_block.header.height,
-				last_output,
-				last_kernel,
-			)?;
+			ext.rewind(forked_block.header.height, last_output, last_kernel)?;
 		}
 
 		// apply all forked blocks, including this new one
@@ -265,8 +263,7 @@ fn validate_block(
 
 	let (utxo_root, rproof_root, kernel_root) = ext.roots();
 	if utxo_root.hash != b.header.utxo_root || rproof_root.hash != b.header.range_proof_root ||
-		kernel_root.hash != b.header.kernel_root
-	{
+	   kernel_root.hash != b.header.kernel_root {
 
 		return Err(Error::InvalidRoot);
 	}
@@ -276,10 +273,8 @@ fn validate_block(
 		if let Ok(output) = ctx.store.get_output_by_commit(&input.commitment()) {
 			if output.features.contains(transaction::COINBASE_OUTPUT) {
 				if let Ok(output_header) =
-					ctx.store.get_block_header_by_output_commit(
-						&input.commitment(),
-					)
-				{
+					ctx.store
+						.get_block_header_by_output_commit(&input.commitment()) {
 
 					// TODO - make sure we are not off-by-1 here vs. the equivalent tansaction
 					// validation rule
@@ -333,7 +328,12 @@ fn update_head(b: &Block, ctx: &mut BlockContext) -> Result<Option<Tip>, Error>
 		// TODO if we're switching branch, make sure to backtrack the sum trees
 
 		ctx.head = tip.clone();
-		info!("Updated head to {} at {}.", b.hash(), b.header.height);
+		info!(
+			LOGGER,
+			"Updated head to {} at {}.",
+			b.hash(),
+			b.header.height
+		);
 		Ok(Some(tip))
 	} else {
 		Ok(None)
@@ -352,6 +352,7 @@ fn update_header_head(bh: &BlockHeader, ctx: &mut BlockContext) -> Result<Option
 
 		ctx.head = tip.clone();
 		info!(
+			LOGGER,
 			"Updated block header head to {} at {}.",
 			bh.hash(),
 			bh.height

chain/src/store.rs

@@ -141,10 +141,8 @@ impl ChainStore for ChainKVStore {
 	// in this index.
 	//
 	fn get_block_header_by_output_commit(&self, commit: &Commitment) -> Result<BlockHeader, Error> {
-		let block_hash = self.db.get_ser(&to_key(
-			HEADER_BY_OUTPUT_PREFIX,
-			&mut commit.as_ref().to_vec(),
-		))?;
+		let block_hash = self.db
+			.get_ser(&to_key(HEADER_BY_OUTPUT_PREFIX, &mut commit.as_ref().to_vec()))?;
 
 		match block_hash {
 			Some(hash) => {
@@ -213,10 +211,8 @@ impl ChainStore for ChainKVStore {
 	/// that is consistent with its height (everything prior to this will be
 	/// consistent)
 	fn setup_height(&self, bh: &BlockHeader) -> Result<(), Error> {
-		self.db.put_ser(
-			&u64_to_key(HEADER_HEIGHT_PREFIX, bh.height),
-			bh,
-		)?;
+		self.db
+			.put_ser(&u64_to_key(HEADER_HEIGHT_PREFIX, bh.height), bh)?;
 		if bh.height == 0 {
 			return Ok(());
 		}

chain/src/sumtree.rs

@@ -36,16 +36,14 @@ const RANGE_PROOF_SUBDIR: &'static str = "rangeproof";
 const KERNEL_SUBDIR: &'static str = "kernel";
 
 struct PMMRHandle<T>
-where
-	T: Summable + Clone,
+	where T: Summable + Clone
 {
 	backend: PMMRBackend<T>,
 	last_pos: u64,
 }
 
 impl<T> PMMRHandle<T>
-where
-	T: Summable + Clone,
+    where T: Summable + Clone
 {
 	fn new(root_dir: String, file_name: &str) -> Result<PMMRHandle<T>, Error> {
 		let path = Path::new(&root_dir).join(SUMTREES_SUBDIR).join(file_name);
@@ -107,8 +105,7 @@ impl SumTrees {
 /// If the closure returns an error, modifications are canceled and the unit
 /// of work is abandoned. Otherwise, the unit of work is permanently applied.
 pub fn extending<'a, F, T>(trees: &'a mut SumTrees, inner: F) -> Result<T, Error>
-where
-	F: FnOnce(&mut Extension) -> Result<T, Error>,
+	where F: FnOnce(&mut Extension) -> Result<T, Error>
 {
 
 	let sizes: (u64, u64, u64);
@@ -229,9 +226,9 @@ impl<'a> Extension<'a> {
 			self.new_output_commits.insert(out.commitment(), pos);
 
 			// push range proofs in their MMR
-			self.rproof_pmmr.push(NoSum(out.proof)).map_err(
-				&Error::SumTreeErr,
-			)?;
+			self.rproof_pmmr
+				.push(NoSum(out.proof))
+				.map_err(&Error::SumTreeErr)?;
 		}
 
 		for kernel in &b.kernels {
@@ -239,9 +236,9 @@ impl<'a> Extension<'a> {
 				return Err(Error::DuplicateKernel(kernel.excess.clone()));
 			}
 			// push kernels in their MMR
-			let pos = self.kernel_pmmr.push(NoSum(kernel.clone())).map_err(
-				&Error::SumTreeErr,
-			)?;
+			let pos = self.kernel_pmmr
+				.push(NoSum(kernel.clone()))
+				.map_err(&Error::SumTreeErr)?;
 			self.new_kernel_excesses.insert(kernel.excess, pos);
 		}
 		Ok(())
@@ -277,14 +274,9 @@ impl<'a> Extension<'a> {
 
 	/// Current root hashes and sums (if applicable) for the UTXO, range proof
 	/// and kernel sum trees.
-	pub fn roots(
-		&self,
-	) -> (HashSum<SumCommit>, HashSum<NoSum<RangeProof>>, HashSum<NoSum<TxKernel>>) {
-		(
-			self.output_pmmr.root(),
-			self.rproof_pmmr.root(),
-			self.kernel_pmmr.root(),
-		)
+	pub fn roots(&self)
+	             -> (HashSum<SumCommit>, HashSum<NoSum<RangeProof>>, HashSum<NoSum<TxKernel>>) {
+		(self.output_pmmr.root(), self.rproof_pmmr.root(), self.kernel_pmmr.root())
 	}
 
 	/// Force the rollback of this extension, no matter the result
@@ -294,10 +286,8 @@ impl<'a> Extension<'a> {
 
 	// Sizes of the sum trees, used by `extending` on rollback.
 	fn sizes(&self) -> (u64, u64, u64) {
-		(
-			self.output_pmmr.unpruned_size(),
-			self.rproof_pmmr.unpruned_size(),
-			self.kernel_pmmr.unpruned_size(),
-		)
+		(self.output_pmmr.unpruned_size(),
+		 self.rproof_pmmr.unpruned_size(),
+		 self.kernel_pmmr.unpruned_size())
 	}
 }

chain/src/types.rs

@@ -209,10 +209,9 @@ pub trait ChainStore: Send + Sync {
 	fn get_output_by_commit(&self, commit: &Commitment) -> Result<Output, store::Error>;
 
 	/// Gets a block_header for the given input commit
-	fn get_block_header_by_output_commit(
-		&self,
-		commit: &Commitment,
-	) -> Result<BlockHeader, store::Error>;
+	fn get_block_header_by_output_commit(&self,
+	                                     commit: &Commitment)
+	                                     -> Result<BlockHeader, store::Error>;
 
 	/// Saves the position of an output, represented by its commitment, in the
 	/// UTXO MMR. Used as an index for spending and pruning.