diff --git a/bencher/Cargo.toml b/bencher/Cargo.toml index 1ff95e31f..c56b795c6 100644 --- a/bencher/Cargo.toml +++ b/bencher/Cargo.toml @@ -8,18 +8,21 @@ authors = ["Laminar Developers "] edition = "2021" [dependencies] -paste = "1.0" +paste = "1.0.6" build-helper = { version = "0.1.1", optional = true } -cargo_metadata = { version = "0.13.1", optional = true } -tempfile = { version = "3.1.0", optional = true } -toml = { version = "0.5.4", optional = true } +cargo_metadata = { version = "0.14.1", optional = true } +tempfile = { version = "3.2.0", optional = true } +toml = { version = "0.5.8", optional = true } walkdir = { version = "2.3.1", optional = true } ansi_term = { version = "0.12.1", optional = true } wasm-gc-api = { version = "0.1.11", optional = true } rand = {version = "0.8.3", optional = true } linregress = { version = "0.4.4", optional = true } -serde = { version = "1.0.119", optional = true, features = ['derive'] } -serde_json = {version = "1.0.64", optional = true } +parking_lot = { version = "0.11.2", optional = true } +serde = { version = "1.0.124", optional = true, features = ['derive'] } +serde_json = {version = "1.0.68", optional = true } +hash-db = { version = "0.15.2", default-features = false, optional = true } +bencher-procedural = { path = "bencher-procedural", default-features = false } codec = { package = "parity-scale-codec", version = "2.3.1", features = ["derive"], default-features = false } sp-core = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false } sp-std = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false } @@ -31,10 +34,13 @@ sc-executor-common = { git = "https://github.com/paritytech/substrate", branch = sc-client-db = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false, features = ["with-kvdb-rocksdb"], optional = true } sp-maybe-compressed-blob = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false, optional = true } frame-benchmarking = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false } +sp-externalities = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false } +sp-storage = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false, optional = true } [features] default = ["std"] std = [ + "bencher-procedural/std", "build-helper", "cargo_metadata", "tempfile", @@ -44,8 +50,10 @@ std = [ "wasm-gc-api", "rand", "linregress", + "parking_lot", "serde/std", "serde_json/std", + "hash-db/std", "codec/std", "sp-core/std", "sp-std/std", @@ -57,7 +65,9 @@ std = [ "sc-client-db", "sp-maybe-compressed-blob", "frame-benchmarking/std", + "sp-externalities/std", + "sp-storage/std", ] bench = [ - "sp-io/disable_panic_handler" + "sp-io/disable_panic_handler", ] diff --git a/bencher/bencher-procedural/Cargo.toml b/bencher/bencher-procedural/Cargo.toml new file mode 100644 index 000000000..b25c0620e --- /dev/null +++ b/bencher/bencher-procedural/Cargo.toml @@ -0,0 +1,18 @@ +[package] +name = "bencher-procedural" +version = "0.1.0" +license = "Apache-2.0" +authors = ["Laminar Developers "] +edition = "2021" + +[lib] +proc-macro = true + +[dependencies] +proc-macro2 = "1.0.6" +quote = "1.0.3" +syn = { version = "1.0.58", features = ["full"] } + +[features] +default = ["std"] +std = [] diff --git a/bencher/bencher-procedural/src/lib.rs b/bencher/bencher-procedural/src/lib.rs new file mode 100644 index 000000000..07bc2ae28 --- /dev/null +++ b/bencher/bencher-procedural/src/lib.rs @@ -0,0 +1,18 @@ +use proc_macro::TokenStream; + +#[proc_macro_attribute] +pub fn benchmarkable(_attr: TokenStream, item: TokenStream) -> TokenStream { + let syn::ItemFn { attrs, vis, sig, block } = syn::parse(item).unwrap(); + (quote::quote! { + #(#attrs)* + #vis #sig { + #[cfg(not(feature = "std"))] + ::orml_bencher::bench::before_block(); + let result = #block; + #[cfg(not(feature = "std"))] + ::orml_bencher::bench::after_block(); + result + } + }) + .into() +} diff --git a/bencher/src/bench_runner.rs b/bencher/src/bench_runner.rs index 09811477f..b6274b1a2 100644 --- a/bencher/src/bench_runner.rs +++ b/bencher/src/bench_runner.rs @@ -1,19 +1,32 @@ +use super::{ + ext::BenchExt, + tracker::{BenchTracker, BenchTrackerExt}, +}; use frame_benchmarking::frame_support::sp_runtime::traits::Block; use sc_executor::{sp_wasm_interface::HostFunctions, WasmExecutionMethod, WasmExecutor}; use sc_executor_common::runtime_blob::RuntimeBlob; +use sp_externalities::Extensions; use sp_state_machine::{Ext, OverlayedChanges, StorageTransactionCache}; +use sp_std::sync::Arc; /// Run benches pub fn run(wasm_code: Vec) -> std::result::Result, String> { let mut overlay = OverlayedChanges::default(); let mut cache = StorageTransactionCache::default(); - let state = - sc_client_db::BenchmarkingState::::new(Default::default(), Default::default(), false, false).unwrap(); - let mut ext = Ext::new(&mut overlay, &mut cache, &state, None); + let state = sc_client_db::BenchmarkingState::::new(Default::default(), Default::default(), false, true).unwrap(); + + let tracker = Arc::new(BenchTracker::new()); + let tracker_ext = BenchTrackerExt(Arc::clone(&tracker)); + + let mut extensions = Extensions::default(); + extensions.register(tracker_ext); + + let ext = Ext::<_, _>::new(&mut overlay, &mut cache, &state, Some(&mut extensions)); + let mut bench_ext = BenchExt::new(ext, tracker); let mut host_functions = sp_io::SubstrateHostFunctions::host_functions(); host_functions.append(&mut frame_benchmarking::benchmarking::HostFunctions::host_functions()); - host_functions.append(&mut super::bencher::HostFunctions::host_functions()); + host_functions.append(&mut super::bench::HostFunctions::host_functions()); let executor = WasmExecutor::new( WasmExecutionMethod::Compiled, @@ -25,5 +38,5 @@ pub fn run(wasm_code: Vec) -> std::result::Result, String> let blob = RuntimeBlob::uncompress_if_needed(&wasm_code[..]).unwrap(); - executor.uncached_call(blob, &mut ext, true, "run_benches", &[]) + executor.uncached_call(blob, &mut bench_ext, false, "run_benches", &[]) } diff --git a/bencher/src/bencher.rs b/bencher/src/bencher.rs new file mode 100644 index 000000000..11f1ca113 --- /dev/null +++ b/bencher/src/bencher.rs @@ -0,0 +1,86 @@ +use codec::{Decode, Encode}; +use sp_std::prelude::Vec; + +#[derive(Encode, Decode, Default, Clone, PartialEq, Debug)] +pub struct BenchResult { + pub method: Vec, + pub elapses: Vec, + pub reads: u32, + pub writes: u32, + pub keys: Vec, +} + +impl BenchResult { + pub fn with_name(name: &str) -> Self { + Self { + method: name.as_bytes().to_vec(), + ..Default::default() + } + } +} + +#[derive(Default)] +pub struct Bencher { + pub current: BenchResult, + pub results: Vec, +} + +#[inline] +fn black_box(dummy: T) -> T { + let ret = unsafe { sp_std::ptr::read_volatile(&dummy) }; + sp_std::mem::forget(dummy); + ret +} + +#[allow(unused_variables, clippy::let_and_return)] +impl Bencher { + pub fn whitelist(&mut self, key: Vec, read: bool, write: bool) { + #[cfg(not(feature = "std"))] + crate::bench::whitelist(key, read, write); + } + + pub fn prepare(&self) { + #[cfg(not(feature = "std"))] + { + frame_benchmarking::benchmarking::commit_db(); + frame_benchmarking::benchmarking::wipe_db(); + } + } + + pub fn bench(&mut self, mut inner: F) -> T + where + F: FnMut() -> T, + { + #[cfg(not(feature = "std"))] + { + frame_benchmarking::benchmarking::commit_db(); + frame_benchmarking::benchmarking::reset_read_write_count(); + crate::bench::prepare(); + crate::bench::instant(); + } + + let ret = black_box(inner()); + + #[cfg(not(feature = "std"))] + { + let elapsed = crate::bench::elapsed().saturating_sub(crate::bench::redundant_time()); + self.current.elapses.push(elapsed); + + frame_benchmarking::benchmarking::commit_db(); + let (reads, _, written, _) = frame_benchmarking::benchmarking::read_write_count(); + + self.current.reads = reads; + self.current.writes = written; + + // changed keys + self.current.keys = crate::bench::read_written_keys(); + } + + ret + } + + pub fn print_warnings(&self, name: &str) { + #[cfg(not(feature = "std"))] + crate::bench::print_warnings(name.encode()); + } +} diff --git a/bencher/src/build_wasm/wasm_project.rs b/bencher/src/build_wasm/wasm_project.rs index 0468eed10..8158529a7 100644 --- a/bencher/src/build_wasm/wasm_project.rs +++ b/bencher/src/build_wasm/wasm_project.rs @@ -34,8 +34,6 @@ use std::{ use toml::value::Table; -use build_helper::rerun_if_changed; - use cargo_metadata::{Metadata, MetadataCommand}; /// Environment variable that tells us to skip building the wasm binary. @@ -57,17 +55,6 @@ const WASM_BUILD_RUSTFLAGS_ENV: &str = "WASM_BUILD_RUSTFLAGS"; /// The directory needs to be an absolute path. const WASM_TARGET_DIRECTORY: &str = "WASM_TARGET_DIRECTORY"; -/// Colorize an info message. -/// -/// Returns the colorized message. -fn colorize_info_message(message: &str) -> String { - if color_output_enabled() { - ansi_term::Color::Yellow.bold().paint(message).to_string() - } else { - message.into() - } -} - /// Holds the path to the bloaty WASM binary. pub struct WasmBinaryBloaty(PathBuf); @@ -153,8 +140,6 @@ pub fn create_and_compile( .as_ref() .map(|wasm_binary_compressed| copy_wasm_to_target_directory(project_cargo_toml, wasm_binary_compressed)); - generate_rerun_if_changed_instructions(project_cargo_toml, &project, &wasm_workspace); - (wasm_binary_compressed.or(wasm_binary), bloaty) } @@ -461,17 +446,6 @@ fn build_project(project: &Path, default_rustflags: &str, cargo_cmd: CargoComman build_cmd.arg("--release"); }; - println!( - "{}", - colorize_info_message("Information that should be included in a bug report.") - ); - println!("{} {:?}", colorize_info_message("Executing build command:"), build_cmd); - println!( - "{} {}", - colorize_info_message("Using rustc version:"), - cargo_cmd.rustc_version() - ); - match build_cmd.status().map(|s| s.success()) { Ok(true) => {} // Use `process.exit(1)` to have a clean error output. @@ -594,94 +568,6 @@ impl<'a> Deref for DeduplicatePackage<'a> { } } -/// Generate the `rerun-if-changed` instructions for cargo to make sure that the -/// WASM binary is rebuilt when needed. -fn generate_rerun_if_changed_instructions(cargo_manifest: &Path, project_folder: &Path, wasm_workspace: &Path) { - // Rerun `build.rs` if the `Cargo.lock` changes - if let Some(cargo_lock) = find_cargo_lock(cargo_manifest) { - rerun_if_changed(cargo_lock); - } - - let metadata = MetadataCommand::new() - .manifest_path(project_folder.join("Cargo.toml")) - .exec() - .expect("`cargo metadata` can not fail!"); - - let package = metadata - .packages - .iter() - .find(|p| p.manifest_path == cargo_manifest) - .expect("The crate package is contained in its own metadata; qed"); - - // Start with the dependencies of the crate we want to compile for wasm. - let mut dependencies = package.dependencies.iter().collect::>(); - - // Collect all packages by follow the dependencies of all packages we find. - let mut packages = HashSet::new(); - packages.insert(DeduplicatePackage::from(package)); - - while let Some(dependency) = dependencies.pop() { - let path_or_git_dep = dependency - .source - .as_ref() - .map(|s| s.starts_with("git+")) - .unwrap_or(true); - - let package = metadata - .packages - .iter() - .filter(|p| !p.manifest_path.starts_with(wasm_workspace)) - .find(|p| { - // Check that the name matches and that the version matches or this is - // a git or path dep. A git or path dependency can only occur once, so we don't - // need to check the version. - (path_or_git_dep || dependency.req.matches(&p.version)) && dependency.name == p.name - }); - - if let Some(package) = package { - if packages.insert(DeduplicatePackage::from(package)) { - dependencies.extend(package.dependencies.iter()); - } - } - } - - // Make sure that if any file/folder of a dependency change, we need to rerun - // the `build.rs` - packages.iter().for_each(package_rerun_if_changed); - - // Register our env variables - println!("cargo:rerun-if-env-changed={}", SKIP_BUILD_ENV); - println!("cargo:rerun-if-env-changed={}", WASM_BUILD_TYPE_ENV); - println!("cargo:rerun-if-env-changed={}", WASM_BUILD_RUSTFLAGS_ENV); - println!("cargo:rerun-if-env-changed={}", WASM_TARGET_DIRECTORY); - println!( - "cargo:rerun-if-env-changed={}", - super::prerequisites::WASM_BUILD_TOOLCHAIN - ); -} - -/// Track files and paths related to the given package to rerun `build.rs` on -/// any relevant change. -fn package_rerun_if_changed(package: &DeduplicatePackage) { - let mut manifest_path = package.manifest_path.clone(); - if manifest_path.ends_with("Cargo.toml") { - manifest_path.pop(); - } - - walkdir::WalkDir::new(&manifest_path) - .into_iter() - .filter_entry(|p| { - // Ignore this entry if it is a directory that contains a `Cargo.toml` that is - // not the `Cargo.toml` related to the current package. This is done to ignore - // sub-crates of a crate. If such a sub-crate is a dependency, it will be - // processed independently anyway. - p.path() == manifest_path || !p.path().is_dir() || !p.path().join("Cargo.toml").exists() - }) - .filter_map(|p| p.ok().map(|p| p.into_path())) - .filter(|p| p.is_dir() || p.extension().map(|e| e == "rs" || e == "toml").unwrap_or_default()) - .for_each(rerun_if_changed); -} - /// Copy the WASM binary to the target directory set in `WASM_TARGET_DIRECTORY` /// environment variable. If the variable is not set, this is a no-op. fn copy_wasm_to_target_directory(cargo_manifest: &Path, wasm_binary: &WasmBinary) { @@ -690,13 +576,12 @@ fn copy_wasm_to_target_directory(cargo_manifest: &Path, wasm_binary: &WasmBinary Err(_) => return, }; - if !target_dir.is_absolute() { - panic!( - "Environment variable `{}` with `{}` is not an absolute path!", - WASM_TARGET_DIRECTORY, - target_dir.display(), - ); - } + assert!( + target_dir.is_absolute(), + "Environment variable `{}` with `{}` is not an absolute path!", + WASM_TARGET_DIRECTORY, + target_dir.display() + ); fs::create_dir_all(&target_dir).expect("Creates `WASM_TARGET_DIRECTORY`."); diff --git a/bencher/src/ext.rs b/bencher/src/ext.rs new file mode 100644 index 000000000..56cb34eb6 --- /dev/null +++ b/bencher/src/ext.rs @@ -0,0 +1,180 @@ +use core::any::{Any, TypeId}; +use hash_db::Hasher; +use sp_externalities::{Extension, ExtensionStore, Externalities}; +use sp_state_machine::{Backend, Ext}; +use sp_std::sync::Arc; +use sp_storage::{ChildInfo, TrackedStorageKey}; + +use super::tracker::BenchTracker; + +pub struct BenchExt<'a, H, B> +where + H: Hasher, + B: 'a + Backend, +{ + ext: Ext<'a, H, B>, + tracker: Arc, +} + +impl<'a, H, B> BenchExt<'a, H, B> +where + H: Hasher, + B: 'a + Backend, +{ + pub fn new(ext: Ext<'a, H, B>, tracker: Arc) -> Self { + BenchExt { ext, tracker } + } +} + +impl<'a, H, B> Externalities for BenchExt<'a, H, B> +where + H: Hasher, + B: 'a + Backend, + H::Out: Ord + 'static + codec::Codec, +{ + fn set_offchain_storage(&mut self, key: &[u8], value: Option<&[u8]>) { + self.ext.set_offchain_storage(key, value); + } + + fn storage(&self, key: &[u8]) -> Option> { + self.tracker.reading_key(key.to_vec()); + self.ext.storage(key) + } + + fn storage_hash(&self, key: &[u8]) -> Option> { + self.tracker.reading_key(key.to_vec()); + self.ext.storage_hash(key) + } + + fn child_storage_hash(&self, child_info: &ChildInfo, key: &[u8]) -> Option> { + self.tracker.reading_child_key(child_info, key.to_vec()); + self.ext.child_storage_hash(child_info, key) + } + + fn child_storage(&self, child_info: &ChildInfo, key: &[u8]) -> Option> { + self.tracker.reading_child_key(child_info, key.to_vec()); + self.ext.child_storage(child_info, key) + } + + fn next_storage_key(&self, key: &[u8]) -> Option> { + self.tracker.reading_key(key.to_vec()); + self.ext.next_storage_key(key) + } + + fn next_child_storage_key(&self, child_info: &ChildInfo, key: &[u8]) -> Option> { + self.tracker.reading_child_key(child_info, key.to_vec()); + self.ext.next_child_storage_key(child_info, key) + } + + fn kill_child_storage(&mut self, child_info: &ChildInfo, limit: Option) -> (bool, u32) { + self.tracker.warn_child_prefix_removal(); + self.ext.kill_child_storage(child_info, limit) + } + + fn clear_prefix(&mut self, prefix: &[u8], limit: Option) -> (bool, u32) { + self.tracker.warn_child_prefix_removal(); + self.ext.clear_prefix(prefix, limit) + } + + fn clear_child_prefix(&mut self, child_info: &ChildInfo, prefix: &[u8], limit: Option) -> (bool, u32) { + self.tracker.warn_child_prefix_removal(); + self.ext.clear_child_prefix(child_info, prefix, limit) + } + + fn place_storage(&mut self, key: Vec, value: Option>) { + self.tracker.changing_key(key.clone()); + self.ext.place_storage(key, value); + } + + fn place_child_storage(&mut self, child_info: &ChildInfo, key: Vec, value: Option>) { + self.tracker.changing_child_key(child_info, key.clone()); + self.ext.place_child_storage(child_info, key, value); + } + + fn storage_root(&mut self) -> Vec { + self.ext.storage_root() + } + + fn child_storage_root(&mut self, child_info: &ChildInfo) -> Vec { + self.ext.child_storage_root(child_info) + } + + fn storage_append(&mut self, key: Vec, value: Vec) { + self.tracker.changing_key(key.clone()); + self.ext.storage_append(key, value); + } + + fn storage_start_transaction(&mut self) { + self.ext.storage_start_transaction(); + } + + fn storage_rollback_transaction(&mut self) -> Result<(), ()> { + self.ext.storage_rollback_transaction() + } + + fn storage_commit_transaction(&mut self) -> Result<(), ()> { + self.ext.storage_commit_transaction() + } + + fn storage_index_transaction(&mut self, index: u32, hash: &[u8], size: u32) { + self.ext.storage_index_transaction(index, hash, size); + } + + fn storage_renew_transaction_index(&mut self, index: u32, hash: &[u8]) { + self.ext.storage_renew_transaction_index(index, hash); + } + + fn wipe(&mut self) { + self.ext.wipe(); + } + + fn commit(&mut self) { + self.ext.commit(); + } + + fn read_write_count(&self) -> (u32, u32, u32, u32) { + self.ext.read_write_count() + } + + fn reset_read_write_count(&mut self) { + self.ext.reset_read_write_count(); + } + + fn get_whitelist(&self) -> Vec { + self.ext.get_whitelist() + } + + fn set_whitelist(&mut self, new: Vec) { + self.ext.set_whitelist(new); + } + + fn proof_size(&self) -> Option { + self.ext.proof_size() + } + + fn get_read_and_written_keys(&self) -> Vec<(Vec, u32, u32, bool)> { + self.ext.get_read_and_written_keys() + } +} + +impl<'a, H, B> ExtensionStore for BenchExt<'a, H, B> +where + H: Hasher, + B: 'a + Backend, +{ + fn extension_by_type_id(&mut self, type_id: TypeId) -> Option<&mut dyn Any> { + self.ext.extension_by_type_id(type_id) + } + + fn register_extension_with_type_id( + &mut self, + type_id: TypeId, + extension: Box, + ) -> Result<(), sp_externalities::Error> { + self.ext.register_extension_with_type_id(type_id, extension) + } + + fn deregister_extension_by_type_id(&mut self, type_id: TypeId) -> Result<(), sp_externalities::Error> { + self.ext.deregister_extension_by_type_id(type_id) + } +} diff --git a/bencher/src/handler.rs b/bencher/src/handler.rs index 065908f92..92ef083a3 100644 --- a/bencher/src/handler.rs +++ b/bencher/src/handler.rs @@ -3,6 +3,7 @@ use crate::{ BenchResult, }; use codec::Decode; +use frame_benchmarking::frame_support::traits::StorageInfo; use linregress::{FormulaRegressionBuilder, RegressionDataBuilder}; use serde::{Deserialize, Serialize}; use std::io::Write; @@ -11,15 +12,14 @@ use std::time::Duration; #[derive(Serialize, Deserialize, Default, Debug, Clone)] struct BenchData { pub name: String, - pub base_weight: u64, - pub base_reads: u32, - pub base_repeat_reads: u32, - pub base_writes: u32, - pub base_repeat_writes: u32, + pub weight: u64, + pub reads: u32, + pub writes: u32, + pub comments: Vec, } /// Handle bench results -pub fn handle(output: Vec) { +pub fn handle(output: Vec, storage_infos: Vec) { println!(); let pkg_name = std::env::var("CARGO_PKG_NAME").unwrap_or_default().replace("-", "_"); @@ -42,37 +42,55 @@ pub fn handle(output: Vec) { .fit() .unwrap(); + let mut total_reads = 0u32; + let mut total_writes = 0u32; + let mut comments = Vec::::new(); + let keys = , u32, u32)> as Decode>::decode(&mut &result.keys[..]).unwrap(); + keys.iter().for_each(|(prefix, reads, writes)| { + total_reads += reads; + total_writes += writes; + if let Some(info) = storage_infos.iter().find(|x| x.prefix.eq(prefix)) { + let pallet = String::from_utf8(info.pallet_name.clone()).unwrap(); + let name = String::from_utf8(info.storage_name.clone()).unwrap(); + let comment = format!("{}::{} (r: {}, w: {})", pallet, name, reads, writes); + comments.push(comment); + } + }); + println!( - "{} {:<60} {:>20} {:<20} {:<20}", + "{} {:<40} {:>20} {:<20} {:<20}", green_bold("Bench"), - cyan(&format!("{}::{}", pkg_name, name)), + cyan(&name), green_bold(&format!( "{:?}", Duration::from_nanos(model.parameters.intercept_value as u64) )), - format!("reads: {}", green_bold(&result.reads.to_string())), - format!("writes: {}", green_bold(&result.writes.to_string())) + format!( + "tracked: [r: {}, w: {}]", + green_bold(&total_reads.to_string()), + green_bold(&total_writes.to_string()) + ), + format!("total: [r: {}, w: {}]", result.reads, result.writes) ); BenchData { name, - base_weight: model.parameters.intercept_value as u64 * 1_000, - base_reads: result.reads, - base_repeat_reads: result.repeat_reads, - base_writes: result.writes, - base_repeat_writes: result.repeat_writes, + weight: model.parameters.intercept_value as u64 * 1_000, + reads: total_reads, + writes: total_writes, + comments, } }) .collect(); println!(); - if let Ok(json) = serde_json::to_string(&data) { - let stdout = ::std::io::stdout(); - let mut handle = stdout.lock(); + let outdir = std::env::var("CARGO_MANIFEST_DIR").unwrap(); + let json_path = format!("{}/target/{}_bench_data.json", outdir, pkg_name); + let mut writer = std::io::BufWriter::new(std::fs::File::create(std::path::Path::new(&json_path)).unwrap()); + serde_json::to_writer_pretty(&mut writer, &data).unwrap(); + writer.write_all(b"\n").unwrap(); + writer.flush().unwrap(); - handle.write_all(json.as_bytes()).unwrap(); - } else { - eprintln!("Could not write benchdata to JSON"); - } + std::io::stdout().lock().write_all(json_path.as_bytes()).unwrap(); } diff --git a/bencher/src/lib.rs b/bencher/src/lib.rs index 746f4e62f..a4e45f51f 100644 --- a/bencher/src/lib.rs +++ b/bencher/src/lib.rs @@ -11,184 +11,25 @@ pub extern crate sp_io; #[doc(hidden)] pub extern crate sp_std; +mod bencher; mod macros; +mod utils; + +pub use bencher::*; +pub use utils::*; #[cfg(feature = "std")] pub mod bench_runner; #[cfg(feature = "std")] pub mod build_wasm; #[cfg(feature = "std")] -mod colorize; -#[cfg(feature = "std")] pub mod handler; -#[cfg(feature = "std")] -mod redundant_meter; - -use codec::{Decode, Encode}; -use sp_std::prelude::{Box, Vec}; - -#[derive(Encode, Decode, Default, Clone, PartialEq, Debug)] -pub struct BenchResult { - pub method: Vec, - pub elapses: Vec, - pub reads: u32, - pub repeat_reads: u32, - pub writes: u32, - pub repeat_writes: u32, -} - -pub struct Bencher { - pub name: Vec, - pub results: Vec, - pub prepare: Box, - pub bench: Box, - pub verify: Box, -} - -impl Default for Bencher { - fn default() -> Self { - Bencher { - name: Vec::new(), - results: Vec::new(), - prepare: Box::new(|| {}), - bench: Box::new(|| {}), - verify: Box::new(|| {}), - } - } -} - -impl Bencher { - /// Reset name and blocks - pub fn reset(&mut self) { - self.name = Vec::new(); - self.prepare = Box::new(|| {}); - self.bench = Box::new(|| {}); - self.verify = Box::new(|| {}); - } - - /// Set bench name - pub fn name(&mut self, name: &str) -> &mut Self { - self.name = name.as_bytes().to_vec(); - self - } - - /// Set prepare block - pub fn prepare(&mut self, prepare: impl Fn() + 'static) -> &mut Self { - self.prepare = Box::new(prepare); - self - } - - /// Set verify block - pub fn verify(&mut self, verify: impl Fn() + 'static) -> &mut Self { - self.verify = Box::new(verify); - self - } - - /// Set bench block - pub fn bench(&mut self, bench: impl Fn() + 'static) -> &mut Self { - self.bench = Box::new(bench); - self - } - - /// Run benchmark for tests - #[cfg(feature = "std")] - pub fn run(&mut self) { - // Execute prepare block - (self.prepare)(); - // Execute bench block - (self.bench)(); - // Execute verify block - (self.verify)(); - } - - /// Run benchmark - #[cfg(not(feature = "std"))] - pub fn run(&mut self) { - assert!(self.name.len() > 0, "bench name not defined"); - // Warm up the DB - frame_benchmarking::benchmarking::commit_db(); - frame_benchmarking::benchmarking::wipe_db(); - - let mut result = BenchResult { - method: self.name.clone(), - ..Default::default() - }; - - for _ in 0..50 { - // Execute prepare block - (self.prepare)(); - - frame_benchmarking::benchmarking::commit_db(); - frame_benchmarking::benchmarking::reset_read_write_count(); - bencher::reset(); - - let start_time = frame_benchmarking::benchmarking::current_time(); - // Execute bench block - (self.bench)(); - let end_time = frame_benchmarking::benchmarking::current_time(); - frame_benchmarking::benchmarking::commit_db(); - - let (elapsed, reads, repeat_reads, writes, repeat_writes) = - bencher::finalized_results(end_time - start_time); - - // Execute verify block - (self.verify)(); - - // Reset the DB - frame_benchmarking::benchmarking::wipe_db(); - - result.elapses.push(elapsed); - - result.reads = sp_std::cmp::max(result.reads, reads); - result.repeat_reads = sp_std::cmp::max(result.repeat_reads, repeat_reads); - result.writes = sp_std::cmp::max(result.writes, writes); - result.repeat_writes = sp_std::cmp::max(result.repeat_writes, repeat_writes); - } - self.results.push(result); - } -} #[cfg(feature = "std")] -thread_local! { - static REDUNDANT_METER: std::cell::RefCell = std::cell::RefCell::new(redundant_meter::RedundantMeter::default()); -} - -#[sp_runtime_interface::runtime_interface] -pub trait Bencher { - fn panic(str: Vec) { - let msg = String::from_utf8_lossy(&str); - eprintln!("{}", colorize::red_bold(&msg)); - std::process::exit(-1); - } - - fn entering_method() -> Vec { - REDUNDANT_METER.with(|x| x.borrow_mut().entering_method()) - } - - fn leaving_method(identifier: Vec) { - REDUNDANT_METER.with(|x| { - x.borrow_mut().leaving_method(identifier); - }); - } - - fn finalized_results(elapsed: u128) -> (u128, u32, u32, u32, u32) { - let (reads, repeat_reads, writes, repeat_writes) = frame_benchmarking::benchmarking::read_write_count(); - - let (redundant_elapsed, redundant_reads, redundant_repeat_reads, redundant_writes, redundant_repeat_writes) = - REDUNDANT_METER.with(|x| x.borrow_mut().take_results()); - - let elapsed = elapsed - redundant_elapsed; - let reads = reads - redundant_reads; - let repeat_reads = repeat_reads - redundant_repeat_reads; - let writes = writes - redundant_writes; - let repeat_writes = repeat_writes - redundant_repeat_writes; - - (elapsed, reads, repeat_reads, writes, repeat_writes) - } +mod colorize; +#[cfg(feature = "std")] +mod ext; +#[cfg(feature = "std")] +mod tracker; - fn reset() { - REDUNDANT_METER.with(|x| { - x.borrow_mut().reset(); - }); - } -} +pub use bencher_procedural::benchmarkable; diff --git a/bencher/src/macros.rs b/bencher/src/macros.rs index e8b183156..6988473f3 100644 --- a/bencher/src/macros.rs +++ b/bencher/src/macros.rs @@ -7,9 +7,8 @@ /// name = "your-module" /// .. /// [[bench]] -/// name = 'your-module-benches' +/// name = 'module_benches' /// harness = false -/// path = 'src/benches.rs' /// required-features = ['bench'] /// /// [features] @@ -20,68 +19,71 @@ /// .. /// ``` /// +/// Create a file `benches/module_benches.rs` must be the same as bench name. +/// ```.ignore +/// use your_module::mock::{AllPalletsWithSystem, Block}; +/// orml_bencher::run_benches!(AllPalletsWithSystem, Block); +/// ``` +/// /// Define benches /// -/// Create a file `src/benches.rs`: -/// ```.ignore -/// #![allow(dead_code)] +/// Create a file `src/benches.rs` +/// ```ignore +/// #!#[cfg(feature = "bench")] /// -/// use orml_bencher::{Bencher, bench}; -/// use your_module::mock::{Block, YourModule}; +/// use orml_bencher::{Bencher, benches}; +/// use crate::mock::*; /// /// fn foo(b: &mut Bencher) { -/// b.prepare(|| { -/// // optional. prepare block, runs before bench -/// }) -/// .bench(|| { -/// // foo must have macro `[orml_weight_meter::weight(..)]` -/// YourModule::foo(); -/// }) -/// .verify(|| { -/// // optional. verify block, runs before bench +/// // Run any before code here +/// let ret = b.bench(|| { +/// // foo must have macro `[orml_weight_meter::weight(..)]` to measure correct redundant info +/// YourModule::foo() /// }); +/// // Run any after code here /// } /// /// fn bar(b: &mut Bencher) { /// // optional. method name is used by default i.e: `bar` /// b.name("bench_name") /// .bench(|| { -/// // bar must have macro `[orml_weight_meter::weight(..)]` +/// // bar must have macro `[orml_weight_meter::weight(..)]` to measure correct redundant info /// YourModule::bar(); /// }); /// } /// -/// bench!(Block, foo, bar); // Tests are generated automatically +/// benches!(foo, bar); // Tests are generated automatically /// ``` -/// Update `src/lib.rs`: -/// ```.ignore +/// Update `src/lib.rs` +/// ```ignore /// #[cfg(any(feature = "bench", test))] /// pub mod mock; /* mock runtime needs to be compiled into wasm */ -/// #[cfg(any(feature = "bench", test))] /// pub mod benches; -/// -/// extern crate self as your_module; /// ``` /// /// Run benchmarking: `cargo bench --features=bench` #[macro_export] -macro_rules! bench { - ( - $block:tt, - $($method:path),+ - ) => { +macro_rules! benches { + ($($method:path),+) => { #[cfg(feature = "bench")] $crate::sp_core::wasm_export_functions! { fn run_benches() -> $crate::sp_std::vec::Vec<$crate::BenchResult> { + $crate::bench::print_info("\nRunning benches ...\n".as_bytes().to_vec()); let mut bencher = $crate::Bencher::default(); $( - bencher.reset(); - $method(&mut bencher); - if bencher.name.len() == 0 { - // use method name as default bench name - bencher.name(stringify!($method)); + $crate::bench::reset(); + + let name = stringify!($method); + bencher.current = $crate::BenchResult::with_name(name); + + for _ in 0..1_000 { + bencher.prepare(); + $method(&mut bencher); } - bencher.run(); + + bencher.print_warnings(name); + + bencher.results.push(bencher.current); )+ bencher.results } @@ -91,36 +93,51 @@ macro_rules! bench { #[panic_handler] #[no_mangle] fn panic_handler(info: &::core::panic::PanicInfo) -> ! { - unsafe { - let message = $crate::sp_std::alloc::format!("{}", info); - $crate::bencher::panic(message.as_bytes().to_vec()); - core::arch::wasm32::unreachable(); - } - } - - #[cfg(all(feature = "std", feature = "bench"))] - pub fn main() -> std::io::Result<()> { - let wasm = $crate::build_wasm::build()?; - match $crate::bench_runner::run::<$block>(wasm) { - Ok(output) => { $crate::handler::handle(output); } - Err(e) => { eprintln!("{:?}", e); } - }; - Ok(()) + let message = $crate::sp_std::alloc::format!("{}", info); + $crate::bench::print_error(message.as_bytes().to_vec()); + unsafe {core::arch::wasm32::unreachable(); } } // Tests - $( - $crate::paste::item! { - #[test] - fn [] () { - $crate::sp_io::TestExternalities::new_empty().execute_with(|| { - let mut bencher = $crate::Bencher::default(); - $method(&mut bencher); - bencher.run(); - }); + #[cfg(test)] + mod tests { + $( + $crate::paste::item! { + #[test] + fn [] () { + $crate::sp_io::TestExternalities::new_empty().execute_with(|| { + let mut bencher = $crate::Bencher::default(); + super::$method(&mut bencher); + }); + } } - } - )+ + )+ + } } } + +#[macro_export] +macro_rules! run_benches { + ( + $all_pallets_with_system:ident, + $block:tt + ) => { + #[cfg(all(feature = "std", feature = "bench"))] + #[main] + pub fn main() -> std::io::Result<()> { + use $crate::frame_benchmarking::frame_support::traits::StorageInfoTrait; + let wasm = $crate::build_wasm::build()?; + let storage_info = $all_pallets_with_system::storage_info(); + match $crate::bench_runner::run::<$block>(wasm) { + Ok(output) => { + $crate::handler::handle(output, storage_info); + } + Err(e) => { + eprintln!("{:?}", e); + } + }; + Ok(()) + } + }; +} diff --git a/bencher/src/redundant_meter.rs b/bencher/src/redundant_meter.rs deleted file mode 100644 index a09ca75dc..000000000 --- a/bencher/src/redundant_meter.rs +++ /dev/null @@ -1,109 +0,0 @@ -use codec::{Decode, Encode}; -use rand::{distributions::Alphanumeric, thread_rng, Rng}; - -#[derive(Encode, Decode, Default, Clone, PartialEq, Debug)] -struct RedundantResult { - identifier: Vec, - timestamp: u128, - reads: u32, - repeat_reads: u32, - writes: u32, - repeat_writes: u32, -} - -/// RedundantMeter is used to measure resources been used by methods that -/// already been benchmarked and have `[orml_weight_meter::weight(..)] macro -/// defined. First method with that macro will be skipped and after that every -/// method with macro defined will be measured as redundant result. -#[derive(Default)] -pub struct RedundantMeter { - started: bool, - results: Vec, - current: Option, -} - -impl RedundantMeter { - /// Entering method with `[orml_weight_meter::weight(..)]` macro - pub fn entering_method(&mut self) -> Vec { - if !self.started { - self.started = true; - return Vec::new(); - } - - if self.current.is_some() { - return Vec::new(); - } - - let timestamp = frame_benchmarking::benchmarking::current_time(); - let (reads, repeat_reads, writes, repeat_writes) = frame_benchmarking::benchmarking::read_write_count(); - - let identifier: Vec = thread_rng() - .sample_iter(&Alphanumeric) - .take(10) - .map(char::from) - .collect::() - .encode(); - - self.current = Some(RedundantResult { - identifier: identifier.to_owned(), - timestamp, - reads, - repeat_reads, - writes, - repeat_writes, - }); - - identifier - } - - /// Leaving method with `[orml_weight_meter::weight(..)]` macro - pub fn leaving_method(&mut self, identifier: Vec) { - if let Some(current) = &self.current { - if current.identifier.eq(&identifier) { - let (reads, repeat_reads, writes, repeat_writes) = frame_benchmarking::benchmarking::read_write_count(); - let timestamp = frame_benchmarking::benchmarking::current_time(); - - self.results.push(RedundantResult { - identifier, - timestamp: timestamp - current.timestamp, - reads: reads - current.reads, - repeat_reads: repeat_reads - current.repeat_reads, - writes: writes - current.writes, - repeat_writes: repeat_writes - current.repeat_writes, - }); - - // reset current - self.current = None; - } - } - } - - /// Take bench results and reset for next measurement - pub fn take_results(&mut self) -> (u128, u32, u32, u32, u32) { - assert!(self.current == None, "benchmark in progress"); - - let mut elapsed = 0u128; - let mut reads = 0u32; - let mut repeat_reads = 0u32; - let mut writes = 0u32; - let mut repeat_writes = 0u32; - - self.results.iter().for_each(|x| { - elapsed += x.timestamp; - reads += x.reads; - repeat_reads += x.repeat_reads; - writes += x.writes; - repeat_writes += x.repeat_writes; - }); - - self.reset(); - - (elapsed, reads, repeat_reads, writes, repeat_writes) - } - - pub fn reset(&mut self) { - self.started = false; - self.results = Vec::new(); - self.current = None; - } -} diff --git a/bencher/src/tracker.rs b/bencher/src/tracker.rs new file mode 100644 index 000000000..44032eafb --- /dev/null +++ b/bencher/src/tracker.rs @@ -0,0 +1,351 @@ +use codec::Encode; +use parking_lot::RwLock; +use sp_state_machine::StorageKey; +use sp_storage::ChildInfo; +use std::{collections::HashMap, sync::Arc, time::Instant}; + +#[derive(PartialEq, Eq)] +enum AccessType { + None, + Redundant, + Important, + Whitelisted, +} + +impl Default for AccessType { + fn default() -> Self { + AccessType::None + } +} + +impl AccessType { + fn is_important(&self) -> bool { + *self == AccessType::Important + } + fn mark_important(&mut self) { + if *self != AccessType::Whitelisted { + *self = AccessType::Important; + } + } +} + +#[derive(Default)] +struct AccessInfo { + pub read: AccessType, + pub written: AccessType, +} + +impl AccessInfo { + fn read(redundant: bool) -> Self { + let read = if redundant { + AccessType::Redundant + } else { + AccessType::Important + }; + Self { + read, + written: AccessType::None, + } + } + + fn written(redundant: bool) -> Self { + let written = if redundant { + AccessType::Redundant + } else { + AccessType::Important + }; + Self { + read: AccessType::Redundant, + written, + } + } + + fn whitelisted(read: bool, write: bool) -> Self { + Self { + read: if read { + AccessType::Whitelisted + } else { + AccessType::None + }, + written: if write { + AccessType::Whitelisted + } else { + AccessType::None + }, + } + } +} + +#[derive(Default, Debug)] +struct AccessReport { + pub read: u32, + pub written: u32, +} + +pub struct BenchTracker { + instant: RwLock, + depth: RwLock, + redundant: RwLock, + results: RwLock>, + main_keys: RwLock>, + child_keys: RwLock>>, + warn_child_prefix_remove: RwLock, + whitelisted_keys: RwLock>, +} + +impl BenchTracker { + pub fn new() -> Self { + BenchTracker { + instant: RwLock::new(Instant::now()), + depth: RwLock::new(0), + redundant: RwLock::new(Instant::now()), + results: RwLock::new(Vec::new()), + main_keys: RwLock::new(HashMap::new()), + child_keys: RwLock::new(HashMap::new()), + warn_child_prefix_remove: RwLock::new(false), + whitelisted_keys: RwLock::new(HashMap::new()), + } + } + + pub fn has_warn_child_prefix_removal(&self) -> bool { + *self.warn_child_prefix_remove.read() + } + + pub fn instant(&self) { + *self.instant.write() = Instant::now(); + } + + pub fn elapsed(&self) -> u128 { + self.instant.read().elapsed().as_nanos() + } + + pub fn is_redundant(&self) -> bool { + *self.depth.read() > 1 + } + + pub fn reading_key(&self, key: StorageKey) { + let redundant = self.is_redundant(); + let main_keys = &mut *self.main_keys.write(); + match main_keys.get_mut(&key) { + Some(info) => { + if redundant { + return; + } + if info.written.is_important() { + return; + } + info.read.mark_important(); + } + None => { + main_keys.insert(key, AccessInfo::read(redundant)); + } + }; + } + + pub fn reading_child_key(&self, child_info: &ChildInfo, key: StorageKey) { + let redundant = self.is_redundant(); + let child_keys = &mut *self.child_keys.write(); + let storage_key = child_info.storage_key().to_vec(); + match child_keys.get_mut(&storage_key) { + Some(reads) => { + match reads.get_mut(&key) { + Some(info) => { + if redundant { + return; + } + if info.written.is_important() { + return; + } + info.read.mark_important(); + } + None => { + reads.insert(key, AccessInfo::read(redundant)); + } + }; + } + None => { + let mut reads = HashMap::::new(); + reads.insert(key, AccessInfo::read(redundant)); + child_keys.insert(storage_key, reads); + } + }; + } + + pub fn changing_key(&self, key: StorageKey) { + let redundant = self.is_redundant(); + let main_keys = &mut *self.main_keys.write(); + match main_keys.get_mut(&key) { + Some(info) => { + if redundant { + return; + } + info.written.mark_important(); + } + None => { + main_keys.insert(key, AccessInfo::written(redundant)); + } + }; + } + + pub fn changing_child_key(&self, child_info: &ChildInfo, key: StorageKey) { + let redundant = self.is_redundant(); + let child_keys = &mut *self.child_keys.write(); + let storage_key = child_info.storage_key().to_vec(); + match child_keys.get_mut(&storage_key) { + Some(changes) => { + match changes.get_mut(&key) { + Some(info) => { + if redundant { + return; + } + info.written.mark_important(); + } + None => { + changes.insert(key, AccessInfo::written(redundant)); + } + }; + } + None => { + let mut changes = HashMap::::new(); + changes.insert(key, AccessInfo::written(redundant)); + child_keys.insert(storage_key, changes); + } + }; + } + + pub fn read_written_keys(&self) -> Vec { + let mut summary = HashMap::::new(); + + self.main_keys.read().iter().for_each(|(key, info)| { + let prefix = key[0..32].to_vec(); + if let Some(report) = summary.get_mut(&prefix) { + if info.read.is_important() { + report.read += 1; + } + if info.written.is_important() { + report.written += 1; + } + } else { + let mut report = AccessReport::default(); + if info.read.is_important() { + report.read += 1; + } + if info.written.is_important() { + report.written += 1; + } + if report.read + report.written > 0 { + summary.insert(prefix, report); + } + } + }); + + self.child_keys.read().iter().for_each(|(prefix, keys)| { + keys.iter().for_each(|(key, info)| { + let prefix = [prefix.clone(), key.clone()].concat()[0..32].to_vec(); + if let Some(report) = summary.get_mut(&prefix) { + if info.read.is_important() { + report.read += 1; + } + if info.written.is_important() { + report.written += 1; + } + } else { + let mut report = AccessReport::default(); + if info.read.is_important() { + report.read += 1; + } + if info.written.is_important() { + report.written += 1; + } + if report.read + report.written > 0 { + summary.insert(prefix, report); + } + } + }); + }); + + summary + .into_iter() + .map(|(prefix, report)| (prefix, report.read, report.written)) + .collect::>() + .encode() + } + + pub fn before_block(&self) { + let timestamp = Instant::now(); + + let mut depth = self.depth.write(); + + if *depth == 0 { + *depth = 1; + return; + } + + if *depth == 1 { + *self.redundant.write() = timestamp; + } + + *depth += 1; + } + + pub fn after_block(&self) { + let mut depth = self.depth.write(); + if *depth == 2 { + let redundant = self.redundant.read(); + let elapsed = redundant.elapsed().as_nanos(); + self.results.write().push(elapsed); + } + *depth -= 1; + } + + pub fn warn_child_prefix_removal(&self) { + *self.warn_child_prefix_remove.write() = true; + } + + pub fn redundant_time(&self) -> u128 { + assert_eq!(*self.depth.read(), 0, "benchmark in progress"); + + let mut elapsed = 0u128; + + self.results.read().iter().for_each(|x| { + elapsed = elapsed.saturating_add(*x); + }); + + elapsed + } + + pub fn prepare(&self) { + *self.depth.write() = 0; + self.results.write().clear(); + + self.child_keys.write().clear(); + *self.warn_child_prefix_remove.write() = false; + + let main_keys = &mut self.main_keys.write(); + main_keys.clear(); + + let keys = self.whitelisted_keys.read(); + for (key, (read, write)) in keys.iter() { + main_keys.insert(key.clone(), AccessInfo::whitelisted(*read, *write)); + } + } + + pub fn whitelist(&self, key: Vec, read: bool, write: bool) { + let whitelisted = &mut self.whitelisted_keys.write(); + whitelisted.insert(key, (read, write)); + } + + pub fn reset(&self) { + *self.depth.write() = 0; + *self.redundant.write() = Instant::now(); + self.results.write().clear(); + self.main_keys.write().clear(); + self.child_keys.write().clear(); + *self.warn_child_prefix_remove.write() = false; + self.whitelisted_keys.write().clear(); + } +} + +sp_externalities::decl_extension! { + pub struct BenchTrackerExt(Arc); +} diff --git a/bencher/src/utils.rs b/bencher/src/utils.rs new file mode 100644 index 000000000..792cd4c94 --- /dev/null +++ b/bencher/src/utils.rs @@ -0,0 +1,100 @@ +use sp_std::vec::Vec; + +#[cfg(feature = "std")] +use super::colorize::{cyan, red_bold, yellow_bold}; +#[cfg(feature = "std")] +use super::tracker::BenchTrackerExt; +#[cfg(feature = "std")] +use codec::Decode; +#[cfg(feature = "std")] +use sp_externalities::ExternalitiesExt; + +#[sp_runtime_interface::runtime_interface] +pub trait Bench { + fn print_error(message: Vec) { + let msg = String::from_utf8_lossy(&message); + eprintln!("{}", red_bold(&msg)); + } + + fn print_warnings(&mut self, method: Vec) { + let tracker = &***self + .extension::() + .expect("No `bench_tracker` associated for the current context!"); + if tracker.has_warn_child_prefix_removal() { + let method_name = ::decode(&mut &method[..]).unwrap(); + println!( + "{} {} kills prefix and/or child storage which are ignored.", + yellow_bold("WARNING:"), + cyan(&method_name) + ); + } + } + + fn print_info(&mut self, message: Vec) { + let msg = String::from_utf8_lossy(&message); + println!("{}", msg); + } + + fn instant(&mut self) { + let tracker = &***self + .extension::() + .expect("No `bench_tracker` associated for the current context!"); + tracker.instant(); + } + + fn elapsed(&mut self) -> u128 { + let tracker = &***self + .extension::() + .expect("No `bench_tracker` associated for the current context!"); + tracker.elapsed() + } + + fn before_block(&mut self) { + let tracker = &***self + .extension::() + .expect("No `bench_tracker` associated for the current context!"); + tracker.before_block(); + } + + fn after_block(&mut self) { + let tracker = &***self + .extension::() + .expect("No `bench_tracker` associated for the current context!"); + tracker.after_block(); + } + + fn redundant_time(&mut self) -> u128 { + let tracker = &***self + .extension::() + .expect("No `bench_tracker` associated for the current context!"); + tracker.redundant_time() + } + + fn prepare(&mut self) { + let tracker = &***self + .extension::() + .expect("No `bench_tracker` associated for the current context!"); + tracker.prepare(); + } + + fn read_written_keys(&mut self) -> Vec { + let tracker = &***self + .extension::() + .expect("No `bench_tracker` associated for the current context!"); + tracker.read_written_keys() + } + + fn whitelist(&mut self, key: Vec, read: bool, write: bool) { + let tracker = &***self + .extension::() + .expect("No `bench_tracker` associated for the current context!"); + tracker.whitelist(key, read, write); + } + + fn reset(&mut self) { + let tracker = &***self + .extension::() + .expect("No `bench_tracker` associated for the current context!"); + tracker.reset(); + } +} diff --git a/bencher/test/Cargo.toml b/bencher/test/Cargo.toml new file mode 100644 index 000000000..34349c97d --- /dev/null +++ b/bencher/test/Cargo.toml @@ -0,0 +1,49 @@ +[package] +name = "orml-bencher-test" +repository = "https://github.com/open-web3-stack/open-runtime-module-library/tree/master/bencher/test" +license = "Apache-2.0" +version = "0.4.1-dev" +authors = ["Laminar Developers "] +edition = "2021" + +[[bench]] +name = "foo" +harness = false +required-features = ["bench"] + +[dependencies] +serde = { version = "1.0.124", optional = true } +scale-info = { version = "1.0", default-features = false, features = ["derive"] } +codec = { package = "parity-scale-codec", version = "2.3.1", features = ["derive"], default-features = false } +frame-support = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false } +frame-system = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false } +sp-runtime = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false } +sp-core = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false } +sp-std = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false } +orml-bencher = { path = "..", default-features = false } +orml-weight-meter = { path = "../../weight-meter", default-features = false } + +[dev-dependencies] +sp-io = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13" } + +[features] +default = ["std"] +std = [ + "serde", + "scale-info/std", + "codec/std", + "orml-bencher/std", + "frame-support/std", + "frame-system/std", + "sp-runtime/std", + "sp-std/std", + "sp-core/std", + "orml-weight-meter/std", +] +bench = [ + "orml-bencher/bench", + "orml-weight-meter/bench", + "frame-support/runtime-benchmarks", + "sp-runtime/runtime-benchmarks", + "frame-system/runtime-benchmarks", +] diff --git a/bencher/test/benches/foo.rs b/bencher/test/benches/foo.rs new file mode 100644 index 000000000..d1a1082c9 --- /dev/null +++ b/bencher/test/benches/foo.rs @@ -0,0 +1,2 @@ +use orml_bencher_test::mock::{AllPalletsWithSystem, Block}; +orml_bencher::run_benches!(AllPalletsWithSystem, Block); diff --git a/bencher/test/src/benches.rs b/bencher/test/src/benches.rs new file mode 100644 index 000000000..5f05ec60c --- /dev/null +++ b/bencher/test/src/benches.rs @@ -0,0 +1,37 @@ +#![cfg(feature = "bench")] +#![allow(dead_code)] + +use crate::{mock::*, pallet::*}; +use frame_support::assert_ok; +use orml_bencher::{benches, Bencher}; + +fn set_value(b: &mut Bencher) { + let result = b.bench(|| Test::set_value(Origin::signed(1), 1)); + assert_ok!(result); + assert_eq!(Test::value(), Some(1 + 1)); +} + +fn set_foo(b: &mut Bencher) { + b.bench(|| { + let _ = Test::set_foo(); + }); +} + +fn remove_all_bar(b: &mut Bencher) { + Bar::::insert(1, 1); + b.bench(|| { + Test::remove_all_bar(); + }); +} + +fn whitelist(b: &mut Bencher) { + b.whitelist(Bar::::hashed_key_for(1), true, true); + b.whitelist(Bar::::hashed_key_for(2), true, false); + b.whitelist(Foo::::hashed_key().to_vec(), true, true); + b.whitelist(Value::::hashed_key().to_vec(), true, true); + b.bench(|| { + let _ = Test::set_foo(); + }); +} + +benches!(whitelist, set_value, set_foo, remove_all_bar); diff --git a/bencher/test/src/lib.rs b/bencher/test/src/lib.rs new file mode 100644 index 000000000..7bb2ef9e7 --- /dev/null +++ b/bencher/test/src/lib.rs @@ -0,0 +1,84 @@ +#![cfg_attr(not(feature = "std"), no_std)] + +pub mod benches; +pub mod mock; +mod tests; +mod weights; + +#[frame_support::pallet] +pub mod pallet { + use crate::weights::ModuleWeights; + use frame_support::{ + dispatch::{DispatchResult, DispatchResultWithPostInfo}, + pallet_prelude::*, + transactional, + }; + use frame_system::pallet_prelude::*; + + #[pallet::config] + pub trait Config: frame_system::Config {} + + #[pallet::hooks] + impl Hooks for Pallet {} + #[pallet::pallet] + #[pallet::generate_store(pub(super) trait Store)] + pub struct Pallet(PhantomData); + + #[pallet::storage] + #[pallet::getter(fn foo)] + pub type Foo = StorageValue<_, u32, OptionQuery>; + + #[pallet::storage] + #[pallet::getter(fn value)] + pub type Value = StorageValue<_, u32, OptionQuery>; + + #[pallet::storage] + #[pallet::getter(fn bar)] + pub type Bar = StorageMap<_, Twox64Concat, u32, u32>; + + #[pallet::call] + impl Pallet { + #[pallet::weight(0)] + #[orml_weight_meter::start(ModuleWeights::::set_value())] + pub fn set_value(origin: OriginFor, n: u32) -> DispatchResultWithPostInfo { + let _sender = frame_system::ensure_signed(origin)?; + Value::::get(); + Value::::put(n); + Value::::put(n + 1); + let _ = Self::set_foo(); + Ok(Some(orml_weight_meter::used_weight()).into()) + } + + #[pallet::weight(0)] + pub fn dummy(origin: OriginFor, _n: u32) -> DispatchResult { + let _sender = frame_system::ensure_none(origin)?; + Foo::::put(1); + Ok(()) + } + } + + impl Pallet { + #[transactional] + #[orml_weight_meter::weight(ModuleWeights::::set_foo())] + pub(crate) fn set_foo() -> frame_support::dispatch::DispatchResult { + Value::::put(2); + + Foo::::put(1); + Foo::::get(); + + Bar::::mutate(1, |v| { + *v = Some(1); + }); + Bar::::insert(1, 1); + + Bar::::insert(2, 2); + Bar::::get(1); + Ok(()) + } + + #[orml_weight_meter::weight(0)] + pub(crate) fn remove_all_bar() { + Bar::::remove_all(None); + } + } +} diff --git a/bencher/test/src/mock.rs b/bencher/test/src/mock.rs new file mode 100644 index 000000000..4a2346d42 --- /dev/null +++ b/bencher/test/src/mock.rs @@ -0,0 +1,80 @@ +#![cfg(any(test, feature = "bench"))] + +use sp_core::H256; +use sp_runtime::{ + traits::{BlakeTwo256, IdentityLookup}, + MultiSignature, +}; +use sp_std::prelude::*; + +pub type Signature = MultiSignature; +pub type BlockNumber = u64; +pub type AccountId = u32; +pub type Address = sp_runtime::MultiAddress; +pub type Header = sp_runtime::generic::Header; + +pub type SignedExtra = (frame_system::CheckWeight,); + +pub type UncheckedExtrinsic = sp_runtime::generic::UncheckedExtrinsic; + +pub type Block = sp_runtime::generic::Block; + +frame_support::construct_runtime!( + pub enum Runtime where + Block = Block, + NodeBlock = Block, + UncheckedExtrinsic = UncheckedExtrinsic, + { + System: frame_system::{Pallet, Call, Config, Storage, Event}, + Test: crate::pallet::{Pallet, Call, Storage}, + } +); + +impl frame_system::Config for Runtime { + type BaseCallFilter = frame_support::traits::Everything; + type BlockWeights = (); + type BlockLength = (); + type DbWeight = (); + type Origin = Origin; + type Index = u64; + type BlockNumber = u64; + type Hash = H256; + type Call = Call; + type Hashing = BlakeTwo256; + type AccountId = AccountId; + type Lookup = IdentityLookup; + type Header = Header; + type Event = Event; + type BlockHashCount = (); + type Version = (); + type PalletInfo = PalletInfo; + type AccountData = (); + type OnNewAccount = (); + type OnKilledAccount = (); + type SystemWeightInfo = (); + type SS58Prefix = (); + type OnSetCode = (); +} + +impl crate::pallet::Config for Runtime {} + +#[cfg(test)] +pub struct ExtBuilder; + +#[cfg(test)] +impl Default for ExtBuilder { + fn default() -> Self { + Self {} + } +} + +#[cfg(test)] +impl ExtBuilder { + pub fn build(self) -> sp_io::TestExternalities { + let t = frame_system::GenesisConfig::default() + .build_storage::() + .unwrap(); + + t.into() + } +} diff --git a/bencher/test/src/tests.rs b/bencher/test/src/tests.rs new file mode 100644 index 000000000..03dfec30b --- /dev/null +++ b/bencher/test/src/tests.rs @@ -0,0 +1,19 @@ +#![cfg(test)] + +use super::mock::*; +use super::weights::ModuleWeights; +use frame_support::dispatch::PostDispatchInfo; + +#[test] +fn set_value() { + let weight = ModuleWeights::::set_value() + ModuleWeights::::set_foo(); + ExtBuilder::default().build().execute_with(|| { + assert_eq!( + Test::set_value(Origin::signed(1), 1), + Ok(PostDispatchInfo { + actual_weight: Some(weight), + ..Default::default() + }) + ); + }); +} diff --git a/bencher/test/src/weights.rs b/bencher/test/src/weights.rs new file mode 100644 index 000000000..bc946b082 --- /dev/null +++ b/bencher/test/src/weights.rs @@ -0,0 +1,36 @@ + + +#![cfg_attr(rustfmt, rustfmt_skip)] +#![allow(unused_parens)] +#![allow(unused_imports)] +#![allow(dead_code)] + +use frame_support::{traits::Get, weights::Weight}; +use sp_std::marker::PhantomData; + +pub struct ModuleWeights(PhantomData); +impl ModuleWeights { + // Storage access info + // + // Test::Value (r: 1, w: 1) + pub fn set_value() -> Weight { + (5_236_000 as Weight) + .saturating_add(T::DbWeight::get().reads(1 as Weight)) + .saturating_add(T::DbWeight::get().writes(1 as Weight)) + } + // Storage access info + // + // Test::Bar (r: 1, w: 2) + // Test::Foo (r: 0, w: 1) + // Test::Value (r: 0, w: 1) + pub fn set_foo() -> Weight { + (13_274_000 as Weight) + .saturating_add(T::DbWeight::get().reads(1 as Weight)) + .saturating_add(T::DbWeight::get().writes(4 as Weight)) + } + // Storage access info + // + pub fn remove_all_bar() -> Weight { + (3_449_000 as Weight) + } +} diff --git a/weight-gen/Cargo.toml b/weight-gen/Cargo.toml index 8d92187fc..d5ba9e4ba 100644 --- a/weight-gen/Cargo.toml +++ b/weight-gen/Cargo.toml @@ -9,8 +9,8 @@ edition = "2021" [dependencies] serde = { version = "1.0.119", features = ["derive"] } serde_json = "1.0" -clap = { version = "3.0.0-rc.0", features = ["derive"] } -handlebars = { version = "3.5.2" } +clap = "2.33.3" +handlebars = { version = "4.1.0" } [features] default = ["std"] diff --git a/weight-gen/src/main.rs b/weight-gen/src/main.rs index f252b1a44..b6c61f670 100644 --- a/weight-gen/src/main.rs +++ b/weight-gen/src/main.rs @@ -1,25 +1,14 @@ -use clap::Parser; +use clap::{App, Arg}; use serde::{Deserialize, Serialize}; use std::io::Read; -#[derive(Parser)] -#[clap(version = "01.0", author = "Laminar Developers ")] -struct Opts { - input: Option, - #[clap(short, long)] - template: Option, - #[clap(short, long)] - header: Option, - #[clap(short, long)] - out: Option, -} - #[derive(Serialize, Deserialize, Default, Debug, Clone)] pub struct BenchData { pub name: String, - pub base_weight: u64, - pub base_reads: u32, - pub base_writes: u32, + pub weight: u64, + pub reads: u32, + pub writes: u32, + pub comments: Vec, } #[derive(Serialize, Default, Debug, Clone)] @@ -100,34 +89,70 @@ impl handlebars::HelperDef for JoinHelper { fn parse_stdio() -> Option> { let mut buffer = String::new(); - let stdin = std::io::stdin(); - let mut handle = stdin.lock(); - - handle.read_to_string(&mut buffer).expect("Unable to read from stdin"); - - let lines: Vec<&str> = buffer.split('\n').collect(); - for line in lines { - let json = serde_json::from_str(line); - - if let Ok(data) = json { - return Some(data); - } - } - - None + std::io::stdin() + .read_to_string(&mut buffer) + .expect("Unable to read from stdin"); + + let file_path = buffer + .split_ascii_whitespace() + .last() + .expect("Last line must be JOSN file path."); + let reader = std::fs::File::open(std::path::Path::new(file_path)).unwrap(); + serde_json::from_reader(&reader).ok() } fn main() { - let opts: Opts = Opts::parse(); - - let benchmarks: Vec = { - if let Some(data) = opts.input { - serde_json::from_str(&data).expect("Could not parse JSON data") + let matches = App::new("Weight Generator") + .version("1.0") + .author("Laminar Developers ") + .about("Generate rust weight info source file from JSON data generated by ORML bencher") + .arg( + Arg::with_name("input") + .short("i") + .long("input") + .value_name("PATH") + .help("Input JSON data file") + .takes_value(true), + ) + .arg( + Arg::with_name("template") + .short("t") + .long("template") + .value_name("PATH") + .help("Handlebars template file") + .takes_value(true), + ) + .arg( + Arg::with_name("header") + .long("header") + .value_name("PATH") + .help("Header file path") + .takes_value(true), + ) + .arg( + Arg::with_name("output") + .short("o") + .long("output") + .value_name("PATH") + .help("Output file path") + .takes_value(true), + ) + .get_matches(); + + let mut benchmarks: Vec = { + if let Some(input_path) = matches.value_of("input") { + let reader = std::fs::File::open(std::path::Path::new(&input_path.trim())).unwrap(); + serde_json::from_reader(&reader).expect("Could not parse JSON data") } else { parse_stdio().expect("Could not parse JSON data") } }; + // Sort comments + benchmarks.iter_mut().for_each(|x| { + x.comments.sort(); + }); + let mut handlebars = handlebars::Handlebars::new(); handlebars.register_helper("underscore", Box::new(UnderscoreHelper)); handlebars.register_helper("join", Box::new(JoinHelper)); @@ -136,7 +161,7 @@ fn main() { // Use empty header if a header path is not given. let header = { - if let Some(path) = opts.header { + if let Some(path) = matches.value_of("header") { ::std::fs::read_to_string(&path).expect("Header file not found") } else { String::from("") @@ -149,7 +174,7 @@ fn main() { // Use default template if template path is not given. let template = { - if let Some(path) = opts.template { + if let Some(path) = matches.value_of("template") { ::std::fs::read_to_string(&path).expect("Template file not found") } else { String::from(DEFAULT_TEMPLATE) @@ -157,12 +182,14 @@ fn main() { }; // Write benchmark to file or print to terminal if output path is not given. - if let Some(path) = opts.out { + if let Some(path) = matches.value_of("output") { let mut output_file = ::std::fs::File::create(&path).expect("Could not create output file"); handlebars .render_template_to_write(&template, &hbs_data, &mut output_file) .expect("Unable to render template"); + println!(); + println!("Weights file `{}` was generated.", path); } else { let template_string = handlebars .render_template(&template, &hbs_data) diff --git a/weight-gen/src/template.hbs b/weight-gen/src/template.hbs index 3ad2b7881..20003b1a4 100644 --- a/weight-gen/src/template.hbs +++ b/weight-gen/src/template.hbs @@ -1,5 +1,6 @@ {{header}} +#![cfg_attr(rustfmt, rustfmt_skip)] #![allow(unused_parens)] #![allow(unused_imports)] #![allow(dead_code)] @@ -9,15 +10,20 @@ use sp_std::marker::PhantomData; pub struct ModuleWeights(PhantomData); impl ModuleWeights { - {{~#each benchmarks as |benchmark|}} + {{#each benchmarks as |benchmark|}} + // Storage access info + // + {{#each benchmark.comments as |c|}} + // {{c}} + {{/each}} pub fn {{benchmark.name~}} () -> Weight { - ({{underscore benchmark.base_weight}} as Weight) - {{~#if (ne benchmark.base_reads 0)}} - .saturating_add(T::DbWeight::get().reads({{benchmark.base_reads}} as Weight)) - {{~/if}} - {{~#if (ne benchmark.base_writes 0)}} - .saturating_add(T::DbWeight::get().writes({{benchmark.base_writes}} as Weight)) - {{~/if}} + ({{underscore benchmark.weight}} as Weight) + {{#if (ne benchmark.reads 0)}} + .saturating_add(T::DbWeight::get().reads({{benchmark.reads}} as Weight)) + {{/if}} + {{#if (ne benchmark.writes 0)}} + .saturating_add(T::DbWeight::get().writes({{benchmark.writes}} as Weight)) + {{/if}} } - {{~/each}} + {{/each}} } diff --git a/weight-meter/Cargo.toml b/weight-meter/Cargo.toml index c21393f43..355f15efc 100644 --- a/weight-meter/Cargo.toml +++ b/weight-meter/Cargo.toml @@ -9,11 +9,9 @@ edition = "2021" targets = ["x86_64-unknown-linux-gnu"] [dependencies] -spin = "0.7.1" scale-info = { version = "1.0", default-features = false, features = ["derive"] } frame-support = { git = "https://github.com/paritytech/substrate", branch = "polkadot-v0.9.13", default-features = false } weight-meter-procedural = { path = "weight-meter-procedural", default-features = false } -orml-bencher = { path = "../bencher", default-features = false, optional = true } [dev-dependencies] serde = { version = "1.0.124" } @@ -32,9 +30,7 @@ std = [ "scale-info/std", "frame-support/std", "weight-meter-procedural/std", - "orml-bencher/std", ] bench = [ "weight-meter-procedural/bench", - "orml-bencher", ] diff --git a/weight-meter/src/lib.rs b/weight-meter/src/lib.rs index 84d20cd44..a1d519a62 100644 --- a/weight-meter/src/lib.rs +++ b/weight-meter/src/lib.rs @@ -10,9 +10,8 @@ //! ``` //! Start with `0` and after the weights is generated then it can be replaced //! with generated weight. Macro will inject callable methods that wraps inner -//! methods. Generated call will start with prefix `method_` followed by method -//! name. This only works for methods with `orml_weight_meter::weight` attribute -//! and only when running benchmarks. +//! methods. This only works for methods with `orml_weight_meter::start` and +//! `orml_weight_meter::weight` attribute, and only when running benchmarks. //! //! 2. Create benchmarks using orml_bencher and generate the weights with //! orml_weight_gen @@ -23,17 +22,17 @@ //! ``` //! with //!```ignore -//! #[orml_weight_meter::weight(T::WeightInfo::method_inner_do_something())] +//! #[orml_weight_meter::weight(ModuleWeights::::inner_do_something())] //! ``` //! //! 3. Use WeightMeter on your calls by adding macro -//! `#[orml_weight_meter::start]` and at the end use -//! `orml_weight_meter::used_weight()` to get used weight. -//!```ignore +//! `#[orml_weight_meter::start(weight)]` or `#[orml_weight_meter::start]` if +//! starts with zero and at the end use `orml_weight_meter::used_weight()` to +//! get used weight. ```ignore //! #[pallet::call] //! impl Pallet { //! #[pallet::weight(T::WeightInfo::do_something())] -//! #[orml_weight_meter::start] +//! #[orml_weight_meter::start(ModuleWeights::::do_something())] //! pub fn do_something(origin: OriginFor, something: u32) -> //! DispatchResultWithPostInfo { //! let who = ensure_signed(origin)?; diff --git a/weight-meter/src/meter_no_std.rs b/weight-meter/src/meter_no_std.rs index 32b129363..60492fa6c 100644 --- a/weight-meter/src/meter_no_std.rs +++ b/weight-meter/src/meter_no_std.rs @@ -8,10 +8,10 @@ static mut METER: Meter = Meter { depth: 0, }; -pub fn start() { +pub fn start(weight: Weight) { unsafe { if METER.depth == 0 { - METER.used_weight = 0; + METER.used_weight = weight; } METER.depth = METER.depth.saturating_add(1); } diff --git a/weight-meter/src/meter_std.rs b/weight-meter/src/meter_std.rs index 1e6c4687e..79b8693c7 100644 --- a/weight-meter/src/meter_std.rs +++ b/weight-meter/src/meter_std.rs @@ -12,11 +12,11 @@ thread_local! { } /// Start weight meter with base weight -pub fn start() { +pub fn start(weight: Weight) { METER.with(|v| { let mut meter = v.borrow_mut(); if meter.depth == 0 { - meter.used_weight = 0; + meter.used_weight = weight; } meter.depth = meter.depth.saturating_add(1); }); diff --git a/weight-meter/weight-meter-procedural/src/lib.rs b/weight-meter/weight-meter-procedural/src/lib.rs index 953d7e689..40abdf1e8 100644 --- a/weight-meter/weight-meter-procedural/src/lib.rs +++ b/weight-meter/weight-meter-procedural/src/lib.rs @@ -1,14 +1,20 @@ use proc_macro::TokenStream; use quote::quote; -use syn::ItemFn; +use syn::{parse, Expr, ItemFn}; #[proc_macro_attribute] -pub fn start(_attr: TokenStream, item: TokenStream) -> TokenStream { - let ItemFn { attrs, vis, sig, block } = syn::parse(item).unwrap(); +pub fn start(attr: TokenStream, item: TokenStream) -> TokenStream { + let weight: Expr = if attr.is_empty() { + parse((quote! { 0 }).into()).unwrap() + } else { + parse(attr).unwrap() + }; + let ItemFn { attrs, vis, sig, block } = parse(item).unwrap(); (quote! { #(#attrs)* + #[cfg_attr(feature = "bench", ::orml_bencher::benchmarkable)] #vis #sig { - ::orml_weight_meter::start(); + ::orml_weight_meter::start(#weight); let result = #block; ::orml_weight_meter::finish(); result @@ -17,13 +23,13 @@ pub fn start(_attr: TokenStream, item: TokenStream) -> TokenStream { .into() } -#[cfg(not(feature = "bench"))] #[proc_macro_attribute] pub fn weight(attr: TokenStream, item: TokenStream) -> TokenStream { - let weight: syn::Expr = syn::parse(attr).unwrap(); - let ItemFn { attrs, vis, sig, block } = syn::parse(item).unwrap(); + let weight: Expr = parse(attr).unwrap(); + let ItemFn { attrs, vis, sig, block } = parse(item).unwrap(); (quote! { #(#attrs)* + #[cfg_attr(feature = "bench", ::orml_bencher::benchmarkable)] #vis #sig { ::orml_weight_meter::using(#weight); #block @@ -31,19 +37,3 @@ pub fn weight(attr: TokenStream, item: TokenStream) -> TokenStream { }) .into() } - -#[cfg(feature = "bench")] -#[proc_macro_attribute] -pub fn weight(_attr: TokenStream, item: TokenStream) -> TokenStream { - let ItemFn { attrs, sig, block, .. } = syn::parse(item).unwrap(); - (quote! { - #(#attrs)* - pub #sig { - let identifier: ::sp_std::vec::Vec = ::orml_bencher::bencher::entering_method(); - let result = #block; - ::orml_bencher::bencher::leaving_method(identifier); - result - } - }) - .into() -}