From 41bb2193a267805e2093a081bc3e2aaccc64283a Mon Sep 17 00:00:00 2001
From: Shawn Tabrizi <shawntabrizi@gmail.com>
Date: Mon, 24 Feb 2020 18:07:38 +0100
Subject: [PATCH] Add storage root recalculation time to benchmarks (#5035)

---
 frame/benchmarking/src/lib.rs           | 17 ++++++++++++-----
 frame/benchmarking/src/utils.rs         |  2 +-
 utils/frame/benchmarking-cli/src/lib.rs |  5 +++--
 3 files changed, 16 insertions(+), 8 deletions(-)

diff --git a/frame/benchmarking/src/lib.rs b/frame/benchmarking/src/lib.rs
index a78d59ef33959..3ad4a9a8a0736 100644
--- a/frame/benchmarking/src/lib.rs
+++ b/frame/benchmarking/src/lib.rs
@@ -20,6 +20,8 @@
 
 mod utils;
 pub use utils::*;
+#[doc(hidden)]
+pub use sp_io::storage::root as storage_root;
 
 /// Construct pallet benchmarks for weighing dispatchables.
 ///
@@ -177,12 +179,17 @@ macro_rules! impl_benchmark {
 							// Commit the externalities to the database, flushing the DB cache.
 							// This will enable worst case scenario for reading from the database.
 							$crate::benchmarking::commit_db();
-							// Run the benchmark.
-							let start = $crate::benchmarking::current_time();
+							// Time the extrinsic logic.
+							let start_extrinsic = $crate::benchmarking::current_time();
 							call.dispatch(caller.into())?;
-							let finish = $crate::benchmarking::current_time();
-							let elapsed = finish - start;
-							results.push((c.clone(), elapsed));
+							let finish_extrinsic = $crate::benchmarking::current_time();
+							let elapsed_extrinsic = finish_extrinsic - start_extrinsic;
+							// Time the storage root recalculation.
+							let start_storage_root = $crate::benchmarking::current_time();
+							$crate::storage_root();
+							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));
 							// Wipe the DB back to the genesis state.
 							$crate::benchmarking::wipe_db();
 						}
diff --git a/frame/benchmarking/src/utils.rs b/frame/benchmarking/src/utils.rs
index 81e87a45f890d..5a67ea6943181 100644
--- a/frame/benchmarking/src/utils.rs
+++ b/frame/benchmarking/src/utils.rs
@@ -31,7 +31,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);
+pub type BenchmarkResults = (Vec<(BenchmarkParameter, u32)>, u128, u128);
 
 sp_api::decl_runtime_apis! {
 	/// Runtime api for benchmarking a FRAME runtime.
diff --git a/utils/frame/benchmarking-cli/src/lib.rs b/utils/frame/benchmarking-cli/src/lib.rs
index b515e490131f6..816ce52131081 100644
--- a/utils/frame/benchmarking-cli/src/lib.rs
+++ b/utils/frame/benchmarking-cli/src/lib.rs
@@ -124,12 +124,13 @@ impl BenchmarkCmd {
 			// Print the table header
 			results[0].0.iter().for_each(|param| print!("{:?},", param.0));
 
-			print!("time\n");
+			print!("extrinsic_time,storage_root_time\n");
 			// Print the values
 			results.iter().for_each(|result| {
 				let parameters = &result.0;
 				parameters.iter().for_each(|param| print!("{:?},", param.1));
-				print!("{:?}\n", result.1);
+				// Print extrinsic time and storage root time
+				print!("{:?},{:?}\n", result.1, result.2);
 			});
 
 			eprintln!("Done.");