diff --git a/Cargo.lock b/Cargo.lock index 1b478fcc18a78..1731ded2906cf 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2129,6 +2129,7 @@ dependencies = [ "clap 3.1.6", "frame-benchmarking", "frame-support", + "frame-system", "handlebars", "hash-db", "hex", @@ -2160,6 +2161,7 @@ dependencies = [ "sp-std", "sp-storage", "sp-trie", + "thousands", ] [[package]] diff --git a/bin/node/cli/src/cli.rs b/bin/node/cli/src/cli.rs index a911cc26ef87c..952c6311f8b38 100644 --- a/bin/node/cli/src/cli.rs +++ b/bin/node/cli/src/cli.rs @@ -42,6 +42,13 @@ pub enum Subcommand { #[clap(name = "benchmark", about = "Benchmark runtime pallets.")] Benchmark(frame_benchmarking_cli::BenchmarkCmd), + /// Benchmark the execution time of historic blocks and compare it to their consumed weight. + #[clap( + name = "benchmark-block", + about = "Benchmark the execution time of historic blocks and compare it to their consumed weight." + )] + BenchmarkBlock(frame_benchmarking_cli::BlockCmd), + /// Sub command for benchmarking the per-block and per-extrinsic execution overhead. #[clap( name = "benchmark-overhead", diff --git a/bin/node/cli/src/command.rs b/bin/node/cli/src/command.rs index 3c2039fde4757..bd324b20fb019 100644 --- a/bin/node/cli/src/command.rs +++ b/bin/node/cli/src/command.rs @@ -98,6 +98,13 @@ pub fn run() -> Result<()> { You can enable it with `--features runtime-benchmarks`." .into()) }, + Some(Subcommand::BenchmarkBlock(cmd)) => { + let runner = cli.create_runner(cmd)?; + runner.async_run(|config| { + let PartialComponents { client, task_manager, .. } = new_partial(&config)?; + Ok((cmd.run(client), task_manager)) + }) + }, Some(Subcommand::BenchmarkOverhead(cmd)) => { let runner = cli.create_runner(cmd)?; runner.async_run(|mut config| { diff --git a/utils/frame/benchmarking-cli/Cargo.toml b/utils/frame/benchmarking-cli/Cargo.toml index b28fe195a2f31..11bba2b37957f 100644 --- a/utils/frame/benchmarking-cli/Cargo.toml +++ b/utils/frame/benchmarking-cli/Cargo.toml @@ -15,6 +15,7 @@ targets = ["x86_64-unknown-linux-gnu"] [dependencies] frame-benchmarking = { version = "4.0.0-dev", path = "../../../frame/benchmarking" } frame-support = { version = "4.0.0-dev", path = "../../../frame/support" } +frame-system = { version = "4.0.0-dev", path = "../../../frame/system" } sp-core = { version = "6.0.0", path = "../../../primitives/core" } sc-block-builder = { version = "0.10.0-dev", path = "../../../client/block-builder" } sc-service = { version = "0.10.0-dev", default-features = false, path = "../../../client/service" } @@ -50,6 +51,7 @@ hash-db = "0.15.2" hex = "0.4.3" memory-db = "0.29.0" rand = { version = "0.8.4", features = ["small_rng"] } +thousands = "0.2.0" [features] default = ["db", "sc-client-db/runtime-benchmarks"] diff --git a/utils/frame/benchmarking-cli/src/block/bench.rs b/utils/frame/benchmarking-cli/src/block/bench.rs new file mode 100644 index 0000000000000..d3c1c97b04ab2 --- /dev/null +++ b/utils/frame/benchmarking-cli/src/block/bench.rs @@ -0,0 +1,176 @@ +// This file is part of Substrate. + +// Copyright (C) 2022 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: Apache-2.0 + +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Contains the core benchmarking logic. + +use codec::DecodeAll; +use frame_support::weights::constants::WEIGHT_PER_NANOS; +use frame_system::ConsumedWeight; +use sc_block_builder::{BlockBuilderApi, BlockBuilderProvider}; +use sc_cli::{Error, Result}; +use sc_client_api::{Backend as ClientBackend, BlockBackend, StorageProvider, UsageProvider}; +use sp_api::{ApiExt, Core, HeaderT, ProvideRuntimeApi}; +use sp_blockchain::Error::RuntimeApiError; +use sp_runtime::{generic::BlockId, traits::Block as BlockT, DigestItem, OpaqueExtrinsic}; +use sp_storage::StorageKey; + +use clap::Args; +use log::{info, warn}; +use serde::Serialize; +use std::{fmt::Debug, marker::PhantomData, sync::Arc, time::Instant}; +use thousands::Separable; + +use crate::storage::record::{StatSelect, Stats}; + +/// Log target for printing block weight info. +const LOG_TARGET: &'static str = "benchmark::block::weight"; + +/// Parameters for modifying the benchmark behaviour. +#[derive(Debug, Default, Serialize, Clone, PartialEq, Args)] +pub struct BenchmarkParams { + /// Number of the first block to consider. + #[clap(long)] + pub from: u32, + + /// Last block number to consider. + #[clap(long)] + pub to: u32, + + /// Number of times that the benchmark should be repeated for each block. + #[clap(long, default_value = "10")] + pub repeat: u32, +} + +/// Convenience closure for the [`Benchmark::run()`] function. +pub struct Benchmark { + client: Arc, + params: BenchmarkParams, + _p: PhantomData<(Block, BA, C)>, +} + +/// Helper for nano seconds. +type NanoSeconds = u64; + +impl Benchmark +where + Block: BlockT, + BA: ClientBackend, + C: BlockBuilderProvider + + ProvideRuntimeApi + + StorageProvider + + UsageProvider + + BlockBackend, + C::Api: ApiExt + BlockBuilderApi, +{ + /// Returns a new [`Self`] from the arguments. + pub fn new(client: Arc, params: BenchmarkParams) -> Self { + Self { client, params, _p: PhantomData } + } + + /// Benchmark the execution speed of historic blocks and log the results. + pub fn run(&self) -> Result<()> { + if self.params.from == 0 { + return Err("Cannot benchmark the genesis block".into()) + } + + for i in self.params.from..=self.params.to { + let block_num = BlockId::Number(i.into()); + let parent_num = BlockId::Number(((i - 1) as u32).into()); + let consumed = self.consumed_weight(&block_num)?; + + let block = + self.client.block(&block_num)?.ok_or(format!("Block {} not found", block_num))?; + let block = self.unsealed(block.block); + let took = self.measure_block(&block, &parent_num)?; + + self.log_weight(i, block.extrinsics().len(), consumed, took); + } + + Ok(()) + } + + /// Return the average *execution* aka. *import* time of the block. + fn measure_block(&self, block: &Block, parent_num: &BlockId) -> Result { + let mut record = Vec::::default(); + // Interesting part here: + // Execute the block multiple times and collect stats about its execution time. + for _ in 0..self.params.repeat { + let block = block.clone(); + let runtime_api = self.client.runtime_api(); + let start = Instant::now(); + + runtime_api + .execute_block(&parent_num, block) + .map_err(|e| Error::Client(RuntimeApiError(e)))?; + + record.push(start.elapsed().as_nanos() as NanoSeconds); + } + + let took = Stats::new(&record)?.select(StatSelect::Average); + Ok(took) + } + + /// Returns the total nanoseconds of a [`frame_system::ConsumedWeight`] for a block number. + /// + /// This is the post-dispatch corrected weight and is only available + /// after executing the block. + fn consumed_weight(&self, block: &BlockId) -> Result { + // Hard-coded key for System::BlockWeight. It could also be passed in as argument + // for the benchmark, but I think this should work as well. + let hash = hex::decode("26aa394eea5630e07c48ae0c9558cef734abf5cb34d6244378cddbf18e849d96")?; + let key = StorageKey(hash); + + let mut raw_weight = &self + .client + .storage(&block, &key)? + .ok_or(format!("Could not find System::BlockWeight for block: {}", block))? + .0[..]; + + let weight = ConsumedWeight::decode_all(&mut raw_weight)?; + // Should be divisible, but still use floats in case we ever change that. + Ok((weight.total() as f64 / WEIGHT_PER_NANOS as f64).floor() as NanoSeconds) + } + + /// Prints the weight info of a block to the console. + fn log_weight(&self, num: u32, num_ext: usize, consumed: NanoSeconds, took: NanoSeconds) { + // The ratio of weight that the block used vs what it consumed. + // This should in general not exceed 100% (minus outliers). + let percent = (took as f64 / consumed as f64) * 100.0; + + let msg = format!( + "Block {} with {: >5} tx used {: >6.2}% of its weight ({: >14} of {: >14} ns)", + num, + num_ext, + percent, + took.separate_with_commas(), + consumed.separate_with_commas() + ); + + if took <= consumed { + info!(target: LOG_TARGET, "{}", msg); + } else { + warn!(target: LOG_TARGET, "{} - OVER WEIGHT!", msg); + } + } + + /// Removes the consensus seal from the block. + fn unsealed(&self, block: Block) -> Block { + let (mut header, exts) = block.deconstruct(); + header.digest_mut().logs.retain(|item| !matches!(item, DigestItem::Seal(_, _))); + Block::new(header, exts) + } +} diff --git a/utils/frame/benchmarking-cli/src/block/cmd.rs b/utils/frame/benchmarking-cli/src/block/cmd.rs new file mode 100644 index 0000000000000..4618c1dd894e1 --- /dev/null +++ b/utils/frame/benchmarking-cli/src/block/cmd.rs @@ -0,0 +1,101 @@ +// This file is part of Substrate. + +// Copyright (C) 2022 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: Apache-2.0 + +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Contains the [`BlockCmd`] as entry point for the CLI to execute +//! the *block* benchmark. + +use sc_block_builder::{BlockBuilderApi, BlockBuilderProvider}; +use sc_cli::{CliConfiguration, ImportParams, Result, SharedParams}; +use sc_client_api::{Backend as ClientBackend, BlockBackend, StorageProvider, UsageProvider}; +use sp_api::{ApiExt, ProvideRuntimeApi}; +use sp_runtime::{traits::Block as BlockT, OpaqueExtrinsic}; + +use clap::Parser; +use std::{fmt::Debug, sync::Arc}; + +use super::bench::{Benchmark, BenchmarkParams}; + +/// Benchmark the execution time historic blocks. +/// +/// This can be used to verify that blocks do not use more weight than they consumed +/// in their `WeightInfo`. Example: +/// +/// Let's say you are on a Substrate chain and want to verify that the first 3 blocks +/// did not use more weight than declared which would otherwise be an issue. +/// To test this with a dev node, first create one with a temp directory: +/// +/// $ substrate --dev -d /tmp/my-dev --execution wasm --wasm-execution compiled +/// +/// And wait some time to let it produce 3 blocks. Then benchmark them with: +/// +/// $ substrate benchmark-block --from 1 --to 3 --dev -d /tmp/my-dev +/// --execution wasm --wasm-execution compiled --pruning archive +/// +/// The output will be similar to this: +/// +/// Block 1 with 1 tx used 77.34% of its weight ( 5,308,964 of 6,864,645 ns) +/// Block 2 with 1 tx used 77.99% of its weight ( 5,353,992 of 6,864,645 ns) +/// Block 3 with 1 tx used 75.91% of its weight ( 5,305,938 of 6,989,645 ns) +/// +/// The percent number is important and indicates how much weight +/// was used as compared to the consumed weight. +/// This number should be below 100% for reference hardware. +#[derive(Debug, Parser)] +pub struct BlockCmd { + #[allow(missing_docs)] + #[clap(flatten)] + pub shared_params: SharedParams, + + #[allow(missing_docs)] + #[clap(flatten)] + pub import_params: ImportParams, + + #[allow(missing_docs)] + #[clap(flatten)] + pub params: BenchmarkParams, +} + +impl BlockCmd { + /// Benchmark the execution time of historic blocks and compare it to their consumed weight. + /// + /// Output will be printed to console. + pub async fn run(&self, client: Arc) -> Result<()> + where + Block: BlockT, + BA: ClientBackend, + C: BlockBuilderProvider + + BlockBackend + + ProvideRuntimeApi + + StorageProvider + + UsageProvider, + C::Api: ApiExt + BlockBuilderApi, + { + // Put everything in the benchmark type to have the generic types handy. + Benchmark::new(client, self.params.clone()).run() + } +} + +// Boilerplate +impl CliConfiguration for BlockCmd { + fn shared_params(&self) -> &SharedParams { + &self.shared_params + } + + fn import_params(&self) -> Option<&ImportParams> { + Some(&self.import_params) + } +} diff --git a/utils/frame/benchmarking-cli/src/block/mod.rs b/utils/frame/benchmarking-cli/src/block/mod.rs new file mode 100644 index 0000000000000..97fdb6ad2c20c --- /dev/null +++ b/utils/frame/benchmarking-cli/src/block/mod.rs @@ -0,0 +1,24 @@ +// This file is part of Substrate. + +// Copyright (C) 2022 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: Apache-2.0 + +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Crate to benchmark the execution time of historic blocks +//! and compare it to their consumed weight. + +mod bench; +mod cmd; + +pub use cmd::BlockCmd; diff --git a/utils/frame/benchmarking-cli/src/lib.rs b/utils/frame/benchmarking-cli/src/lib.rs index e06d57963dad3..288e6b4b86156 100644 --- a/utils/frame/benchmarking-cli/src/lib.rs +++ b/utils/frame/benchmarking-cli/src/lib.rs @@ -15,6 +15,7 @@ // See the License for the specific language governing permissions and // limitations under the License. +mod block; mod command; pub mod overhead; mod post_processing; @@ -24,6 +25,7 @@ mod writer; use sc_cli::{ExecutionStrategy, WasmExecutionMethod, DEFAULT_WASM_EXECUTION_METHOD}; use std::{fmt::Debug, path::PathBuf}; +pub use block::BlockCmd; pub use overhead::{ExtrinsicBuilder, OverheadCmd}; pub use storage::StorageCmd; diff --git a/utils/frame/benchmarking-cli/src/overhead/cmd.rs b/utils/frame/benchmarking-cli/src/overhead/cmd.rs index 8c75627fe2462..f74c32ba72a86 100644 --- a/utils/frame/benchmarking-cli/src/overhead/cmd.rs +++ b/utils/frame/benchmarking-cli/src/overhead/cmd.rs @@ -19,7 +19,7 @@ //! the *overhead* benchmarks. use sc_block_builder::{BlockBuilderApi, BlockBuilderProvider}; -use sc_cli::{CliConfiguration, Result, SharedParams}; +use sc_cli::{CliConfiguration, ImportParams, Result, SharedParams}; use sc_client_api::Backend as ClientBackend; use sc_service::Configuration; use sp_api::{ApiExt, ProvideRuntimeApi}; @@ -45,6 +45,10 @@ pub struct OverheadCmd { #[clap(flatten)] pub shared_params: SharedParams, + #[allow(missing_docs)] + #[clap(flatten)] + pub import_params: ImportParams, + #[allow(missing_docs)] #[clap(flatten)] pub params: OverheadParams, @@ -115,4 +119,8 @@ impl CliConfiguration for OverheadCmd { fn shared_params(&self) -> &SharedParams { &self.shared_params } + + fn import_params(&self) -> Option<&ImportParams> { + Some(&self.import_params) + } }