Add statistics to benchmarking-cli output

Cargo.toml

@@ -147,6 +147,7 @@ members = [
 	"primitives/std",
 	"primitives/version",
 	"primitives/state-machine",
+	"primitives/stats",
 	"primitives/timestamp",
 	"primitives/test-primitives",
 	"primitives/transaction-pool",

bin/node/runtime/Cargo.toml

@@ -42,6 +42,7 @@ frame-system-rpc-runtime-api = { version = "2.0.0-alpha.4", default-features = f
 pallet-authority-discovery = { version = "2.0.0-alpha.4", default-features = false, path = "../../../frame/authority-discovery" }
 pallet-authorship = { version = "2.0.0-alpha.4", default-features = false, path = "../../../frame/authorship" }
 pallet-babe = { version = "2.0.0-alpha.4", default-features = false, path = "../../../frame/babe" }
+pallet-benchmark = { version = "2.0.0-alpha.4", default-features = false, path = "../../../frame/benchmark" }
 pallet-balances = { version = "2.0.0-alpha.4", default-features = false, path = "../../../frame/balances" }
 pallet-collective = { version = "2.0.0-alpha.4", default-features = false, path = "../../../frame/collective" }
 pallet-contracts = { version = "2.0.0-alpha.4", default-features = false, path = "../../../frame/contracts" }
@@ -97,6 +98,7 @@ std = [
 	"frame-executive/std",
 	"pallet-finality-tracker/std",
 	"pallet-grandpa/std",
+	"pallet-benchmark/std",
 	"pallet-im-online/std",
 	"pallet-indices/std",
 	"sp-inherents/std",

bin/node/runtime/src/lib.rs

@@ -622,6 +622,11 @@ impl pallet_vesting::Trait for Runtime {
 	type MinVestedTransfer = MinVestedTransfer;
 }
 
+impl pallet_benchmark::Trait for Runtime {
+	type Event = Event;
+	type Currency = Balances;
+}
+
 construct_runtime!(
 	pub enum Runtime where
 		Block = Block,
@@ -656,6 +661,7 @@ construct_runtime!(
 		Society: pallet_society::{Module, Call, Storage, Event<T>, Config<T>},
 		Recovery: pallet_recovery::{Module, Call, Storage, Event<T>},
 		Vesting: pallet_vesting::{Module, Call, Storage, Event<T>, Config<T>},
+		Benchmark: pallet_benchmark::{Module, Call, Storage, Event<T>},
 	}
 );
 

client/Cargo.toml

@@ -34,6 +34,7 @@ sp-blockchain = { version = "2.0.0-alpha.4", path = "../primitives/blockchain" }
 sp-state-machine = { version = "0.8.0-alpha.4", path = "../primitives/state-machine" }
 sc-telemetry = { version = "2.0.0-alpha.4", path = "telemetry" }
 sp-trie = { version = "2.0.0-alpha.4", path = "../primitives/trie" }
+sp-stats = { version = "2.0.0-alpha.4", path = "../primitives/stats" }
 prometheus-endpoint = { package = "substrate-prometheus-endpoint", version = "0.8.0-alpha.4", path = "../utils/prometheus" }
 tracing = "0.1.10"
 

client/db/Cargo.toml

@@ -25,6 +25,7 @@ sp-core = { version = "2.0.0-alpha.4", path = "../../primitives/core" }
 sp-runtime = { version = "2.0.0-alpha.4", path = "../../primitives/runtime" }
 sc-client = { version = "0.8.0-alpha.4", path = "../" }
 sp-state-machine = { version = "0.8.0-alpha.4", path = "../../primitives/state-machine" }
+sp-stats= { version = "2.0.0-alpha.4", path = "../../primitives/stats" }
 sc-executor = { version = "0.8.0-alpha.4", path = "../executor" }
 sc-state-db = { version = "0.8.0-alpha.4", path = "../state-db" }
 sp-trie = { version = "2.0.0-alpha.4", path = "../../primitives/trie" }

client/db/src/bench.rs

@@ -29,6 +29,7 @@ use sp_runtime::Storage;
 use sp_state_machine::{DBValue, backend::Backend as StateBackend};
 use kvdb::{KeyValueDB, DBTransaction};
 use kvdb_rocksdb::{Database, DatabaseConfig};
+use sp_stats::UsageInfo;
 
 type DbState<B> = sp_state_machine::TrieBackend<
 	Arc<dyn sp_state_machine::Storage<HashFor<B>>>, HashFor<B>
@@ -55,6 +56,7 @@ pub struct BenchmarkingState<B: BlockT> {
 	state: RefCell<Option<DbState<B>>>,
 	db: Cell<Option<Arc<dyn KeyValueDB>>>,
 	genesis: <DbState<B> as StateBackend<HashFor<B>>>::Transaction,
+	usage_info: RefCell<UsageInfo>,
 }
 
 impl<B: BlockT> BenchmarkingState<B> {
@@ -75,6 +77,7 @@ impl<B: BlockT> BenchmarkingState<B> {
 			path,
 			root: Cell::new(root),
 			genesis: Default::default(),
+			usage_info: RefCell::new(UsageInfo::empty()),
 			genesis_root: Default::default(),
 		};
 
@@ -135,7 +138,13 @@ impl<B: BlockT> StateBackend<HashFor<B>> for BenchmarkingState<B> {
 	type TrieBackendStorage = <DbState<B> as StateBackend<HashFor<B>>>::TrieBackendStorage;
 
 	fn storage(&self, key: &[u8]) -> Result<Option<Vec<u8>>, Self::Error> {
-		self.state.borrow().as_ref().ok_or_else(state_err)?.storage(key)
+		let state = self.state.borrow_mut();
+		let db_state = state.as_ref().ok_or_else(state_err)?;
+		let _ = self.usage_info.try_borrow_mut().map(|mut usage_info| {
+			usage_info.reads.ops += 1;
+			usage_info.reads.bytes += key.len() as u64;
+		});
+		db_state.storage(key)
 	}
 
 	fn storage_hash(&self, key: &[u8]) -> Result<Option<B::Hash>, Self::Error> {
@@ -257,15 +266,21 @@ impl<B: BlockT> StateBackend<HashFor<B>> for BenchmarkingState<B> {
 	{
 		if let Some(db) = self.db.take() {
 			let mut db_transaction = DBTransaction::new();
+			let mut bytes = 0;
 
 			for (key, (val, rc)) in transaction.drain() {
 				if rc > 0 {
 					db_transaction.put(0, &key, &val);
 				} else if rc < 0 {
 					db_transaction.delete(0, &key);
 				}
+				bytes += key.len() as u64;
 			}
 			db.write(db_transaction).map_err(|_| String::from("Error committing transaction"))?;
+			let _ = self.usage_info.try_borrow_mut().map(|mut usage_info| {
+				usage_info.writes.ops += 1;
+				usage_info.writes.bytes += bytes;
+			});
 			self.root.set(storage_root);
 		} else {
 			return Err("Trying to commit to a closed db".into())
@@ -279,6 +294,10 @@ impl<B: BlockT> StateBackend<HashFor<B>> for BenchmarkingState<B> {
 		self.commit(self.genesis_root.clone(), self.genesis.clone())?;
 		Ok(())
 	}
+
+	fn usage_info(&self) -> UsageInfo {
+		self.usage_info.try_borrow().map_or(UsageInfo::empty(), |info| info.clone())
+	}
 }
 
 impl<Block: BlockT> std::fmt::Debug for BenchmarkingState<Block> {

client/db/src/lib.rs

@@ -71,10 +71,11 @@ use sp_runtime::traits::{
 };
 use sc_executor::RuntimeInfo;
 use sp_state_machine::{
-	DBValue, ChangesTrieTransaction, ChangesTrieCacheAction, UsageInfo as StateUsageInfo,
+	DBValue, ChangesTrieTransaction, ChangesTrieCacheAction, 
 	StorageCollection, ChildStorageCollection,
 	backend::Backend as StateBackend,
 };
+use sp_stats::{UsageInfo as StateUsageInfo};
 use crate::utils::{DatabaseType, Meta, db_err, meta_keys, read_db, read_meta};
 use crate::changes_tries_storage::{DbChangesTrieStorage, DbChangesTrieStorageTransaction};
 use sc_client::leaves::{LeafSet, FinalizationDisplaced};

client/db/src/stats.rs

@@ -17,6 +17,7 @@
 //! Database usage statistics
 
 use std::sync::atomic::{AtomicU64, Ordering as AtomicOrdering};
+use std::time::{SystemTime, UNIX_EPOCH};
 
 /// Accumulated usage statistics for state queries.
 pub struct StateUsageStats {
@@ -77,7 +78,7 @@ impl StateUsageStats {
 	}
 
 	/// Merge state machine usage info.
-	pub fn merge_sm(&self, info: sp_state_machine::UsageInfo) {
+	pub fn merge_sm(&self, info: sp_stats::UsageInfo) {
 		self.reads.fetch_add(info.reads.ops, AtomicOrdering::Relaxed);
 		self.bytes_read.fetch_add(info.reads.bytes, AtomicOrdering::Relaxed);
 		self.writes.fetch_add(info.writes.ops, AtomicOrdering::Relaxed);
@@ -87,8 +88,8 @@ impl StateUsageStats {
 	}
 
 	/// Returns the collected `UsageInfo` and resets the internal state.
-	pub fn take(&self) -> sp_state_machine::UsageInfo {
-		use sp_state_machine::UsageUnit;
+	pub fn take(&self) -> sp_stats::UsageInfo {
+		use sp_stats::UsageUnit;
 
 		fn unit(ops: &AtomicU64, bytes: &AtomicU64) -> UsageUnit {
 			UsageUnit {
@@ -97,15 +98,16 @@ impl StateUsageStats {
 			}
 		}
 
-		sp_state_machine::UsageInfo {
+		sp_stats::UsageInfo {
 			reads: unit(&self.reads, &self.bytes_read),
 			writes: unit(&self.writes, &self.bytes_written),
 			cache_reads: unit(&self.reads_cache, &self.bytes_read_cache),
 			// TODO: Proper tracking state of memory footprint here requires
 			//       imposing `MallocSizeOf` requirement on half of the codebase,
 			//       so it is an open question how to do it better
 			memory: 0,
-			started: self.started,
+			// expect?
+			started: SystemTime::now().duration_since(UNIX_EPOCH).expect("Time went backwards"),
 			span: self.started.elapsed(),
 		}
 	}

client/db/src/storage_cache.rs

@@ -663,7 +663,7 @@ impl<S: StateBackend<HashFor<B>>, B: BlockT> StateBackend<HashFor<B>> for Cachin
 		self.state.as_trie_backend()
 	}
 
-	fn usage_info(&self) -> sp_state_machine::UsageInfo {
+	fn usage_info(&self) -> sp_stats::UsageInfo {
 		self.usage.take()
 	}
 }
@@ -852,7 +852,7 @@ impl<S: StateBackend<HashFor<B>>, B: BlockT> StateBackend<HashFor<B>> for Syncin
 			.as_trie_backend()
 	}
 
-	fn usage_info(&self) -> sp_state_machine::UsageInfo {
+	fn usage_info(&self) -> sp_stats::UsageInfo {
 		self.caching_state().usage_info()
 	}
 }

frame/benchmarking/Cargo.toml

@@ -14,10 +14,12 @@ sp-api = { version = "2.0.0-alpha.4", path = "../../primitives/api", default-fea
 sp-runtime-interface = { version = "2.0.0-alpha.4", path = "../../primitives/runtime-interface", default-features = false }
 sp-runtime = { version = "2.0.0-alpha.4", path = "../../primitives/runtime", default-features = false }
 sp-std = { version = "2.0.0-alpha.4", path = "../../primitives/std", default-features = false }
+sp-stats = { version = "2.0.0-alpha.4", path = "../../primitives/stats", default-features = false }
 sp-io = { path = "../../primitives/io", default-features = false, version = "2.0.0-alpha.4"}
 frame-support = { version = "2.0.0-alpha.4", default-features = false, path = "../support" }
 frame-system = { version = "2.0.0-alpha.4", default-features = false, path = "../system" }
 
+
 [features]
 default = [ "std" ]
 std = [

frame/benchmarking/src/lib.rs

@@ -477,7 +477,8 @@ macro_rules! impl_benchmark {
 							let finish_storage_root = $crate::benchmarking::current_time();
 							let elapsed_storage_root = finish_storage_root - start_storage_root;
 
-							results.push((c.clone(), elapsed_extrinsic, elapsed_storage_root));
+							let usage_info = $crate::benchmarking::db_usage_info();
+							results.push((c.clone(), elapsed_extrinsic, elapsed_storage_root, usage_info.reads.ops, usage_info.writes.ops, usage_info.cache_reads.ops));
 
 							// Wipe the DB back to the genesis state.
 							$crate::benchmarking::wipe_db();

frame/benchmarking/src/utils.rs

@@ -20,6 +20,7 @@ use codec::{Encode, Decode};
 use sp_std::{vec::Vec, prelude::Box};
 use sp_io::hashing::blake2_256;
 use sp_runtime::RuntimeString;
+use sp_stats::UsageInfo;
 
 /// An alphabet of possible parameters to use for benchmarking.
 #[derive(codec::Encode, codec::Decode, Clone, Copy, PartialEq, Debug)]
@@ -32,7 +33,7 @@ pub enum BenchmarkParameter {
 /// Results from running benchmarks on a FRAME pallet.
 /// Contains duration of the function call in nanoseconds along with the benchmark parameters
 /// used for that benchmark result.
-pub type BenchmarkResults = (Vec<(BenchmarkParameter, u32)>, u128, u128);
+pub type BenchmarkResults = (Vec<(BenchmarkParameter, u32)>, u128, u128, u64, u64, u64);
 
 sp_api::decl_runtime_apis! {
 	/// Runtime api for benchmarking a FRAME runtime.
@@ -67,6 +68,11 @@ pub trait Benchmarking {
 		self.wipe()
 	}
 
+	/// Wrapper function to get the usage info from the benchmarking state.
+	fn db_usage_info(&self) -> UsageInfo {
+		self.bench_usage_info()
+	}
+
 	/// Commit pending storage changes to the trie database and clear the database cache.
 	fn commit_db(&mut self) {
 		self.commit()

primitives/externalities/Cargo.toml

@@ -12,4 +12,5 @@ documentation = "https://docs.rs/sp-externalities"
 [dependencies]
 sp-storage = { version = "2.0.0-alpha.4", path = "../storage" }
 sp-std = { version = "2.0.0-alpha.4", path = "../std" }
+sp-stats = { version = "2.0.0-alpha.4", path = "../stats" }
 environmental = { version = "1.1.1" }

primitives/externalities/src/lib.rs

@@ -25,6 +25,7 @@
 use std::any::{Any, TypeId};
 
 use sp_storage::{ChildStorageKey, ChildInfo};
+use sp_stats::UsageInfo;
 
 pub use scope_limited::{set_and_run_with_externalities, with_externalities};
 pub use extensions::{Extension, Extensions, ExtensionStore};
@@ -182,6 +183,13 @@ pub trait Externalities: ExtensionStore {
 	/// The state will be reset to genesis.
 	fn wipe(&mut self);
 
+	/// !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
+	/// Benchmarking related functionality and shouldn't be used anywhere else!
+	/// !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
+	///
+	/// Returns the benchmarking usage info.
+	fn bench_usage_info(&self) -> UsageInfo;
+
 	/// !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
 	/// Benchmarking related functionality and shouldn't be used anywhere else!
 	/// !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!

primitives/runtime-interface/Cargo.toml

@@ -17,6 +17,7 @@ sp-externalities = { version = "0.8.0-alpha.4", optional = true, path = "../exte
 codec = { package = "parity-scale-codec", version = "1.2.0", default-features = false }
 static_assertions = "1.0.0"
 primitive-types = { version = "0.6.2", default-features = false }
+sp-stats = { version = "2.0.0-alpha.4", path = "../stats", default-features = false }
 
 [dev-dependencies]
 sp-runtime-interface-test-wasm = { version = "2.0.0-dev", path = "test-wasm" }
@@ -34,6 +35,7 @@ std = [
 	"codec/std",
 	"sp-externalities",
 	"primitive-types/std",
+	"sp-stats/std",
 ]
 
 # ATTENTION

primitives/runtime-interface/src/impls.rs

@@ -532,3 +532,7 @@ impl PassBy for sp_wasm_interface::ValueType {
 impl PassBy for sp_wasm_interface::Value {
 	type PassBy = Codec<sp_wasm_interface::Value>;
 }
+
+impl PassBy for sp_stats::UsageInfo {
+    type PassBy = Codec<Self>;
+}

primitives/state-machine/Cargo.toml

@@ -22,6 +22,7 @@ codec = { package = "parity-scale-codec", version = "1.2.0" }
 num-traits = "0.2.8"
 rand = "0.7.2"
 sp-externalities = { version = "0.8.0-alpha.4", path = "../externalities" }
+sp-stats = { version = "2.0.0-alpha.4", path = "../stats" }
 
 [dev-dependencies]
 hex-literal = "0.2.1"

primitives/state-machine/src/backend.rs

@@ -22,11 +22,12 @@ use codec::{Decode, Encode};
 
 use sp_core::{traits::RuntimeCode, storage::{ChildInfo, OwnedChildInfo, well_known_keys}};
 use sp_trie::{TrieMut, MemoryDB, trie_types::TrieDBMut};
+use sp_stats::UsageInfo;
 
 use crate::{
 	trie_backend::TrieBackend,
 	trie_backend_essence::TrieBackendStorage,
-	UsageInfo, StorageKey, StorageValue, StorageCollection,
+	StorageKey, StorageValue, StorageCollection,
 };
 
 /// A state backend is used to read state data and can have changes committed