From 9e6298e7f773c61d384677e6eebfa8d7eee9d2ac Mon Sep 17 00:00:00 2001 From: Andrei Eres Date: Tue, 6 Feb 2024 17:57:38 +0100 Subject: [PATCH] subsystem-bench: Prepare CI output (#3158) 1. Benchmark results are collected in a single struct. 2. The output of the results is prettified. 3. The result struct used to save the output as a yaml and store it in artifacts in a CI job. ``` $ cargo run -p polkadot-subsystem-bench --release -- test-sequence --path polkadot/node/subsystem-bench/examples/availability_read.yaml | tee output.txt $ cat output.txt polkadot/node/subsystem-bench/examples/availability_read.yaml #1 Network usage, KiB total per block Received from peers 510796.000 170265.333 Sent to peers 221.000 73.667 CPU usage, s total per block availability-recovery 38.671 12.890 Test environment 0.255 0.085 polkadot/node/subsystem-bench/examples/availability_read.yaml #2 Network usage, KiB total per block Received from peers 413633.000 137877.667 Sent to peers 353.000 117.667 CPU usage, s total per block availability-recovery 52.630 17.543 Test environment 0.271 0.090 polkadot/node/subsystem-bench/examples/availability_read.yaml #3 Network usage, KiB total per block Received from peers 424379.000 141459.667 Sent to peers 703.000 234.333 CPU usage, s total per block availability-recovery 51.128 17.043 Test environment 0.502 0.167 ``` ``` $ cargo run -p polkadot-subsystem-bench --release -- --ci test-sequence --path polkadot/node/subsystem-bench/examples/availability_read.yaml | tee output.txt $ cat output.txt - benchmark_name: 'polkadot/node/subsystem-bench/examples/availability_read.yaml #1' network: - resource: Received from peers total: 509011.0 per_block: 169670.33333333334 - resource: Sent to peers total: 220.0 per_block: 73.33333333333333 cpu: - resource: availability-recovery total: 31.845848445 per_block: 10.615282815 - resource: Test environment total: 0.23582828799999941 per_block: 0.07860942933333313 - benchmark_name: 'polkadot/node/subsystem-bench/examples/availability_read.yaml #2' network: - resource: Received from peers total: 411738.0 per_block: 137246.0 - resource: Sent to peers total: 351.0 per_block: 117.0 cpu: - resource: availability-recovery total: 18.93596025099999 per_block: 6.31198675033333 - resource: Test environment total: 0.2541994199999979 per_block: 0.0847331399999993 - benchmark_name: 'polkadot/node/subsystem-bench/examples/availability_read.yaml #3' network: - resource: Received from peers total: 424548.0 per_block: 141516.0 - resource: Sent to peers total: 703.0 per_block: 234.33333333333334 cpu: - resource: availability-recovery total: 16.54178526900001 per_block: 5.513928423000003 - resource: Test environment total: 0.43960946299999537 per_block: 0.14653648766666513 ``` --------- Co-authored-by: Andrei Sandu <54316454+sandreim@users.noreply.github.com> --- .../node/subsystem-bench/src/approval/mod.rs | 18 ++- .../subsystem-bench/src/availability/mod.rs | 32 +++-- polkadot/node/subsystem-bench/src/cli.rs | 16 +++ .../subsystem-bench/src/core/environment.rs | 120 ++++++++++++------ .../subsystem-bench/src/subsystem-bench.rs | 62 ++++++--- 5 files changed, 173 insertions(+), 75 deletions(-) diff --git a/polkadot/node/subsystem-bench/src/approval/mod.rs b/polkadot/node/subsystem-bench/src/approval/mod.rs index 3544ce74711e..055aeb193456 100644 --- a/polkadot/node/subsystem-bench/src/approval/mod.rs +++ b/polkadot/node/subsystem-bench/src/approval/mod.rs @@ -29,7 +29,9 @@ use crate::{ }, core::{ configuration::{TestAuthorities, TestConfiguration}, - environment::{TestEnvironment, TestEnvironmentDependencies, MAX_TIME_OF_FLIGHT}, + environment::{ + BenchmarkUsage, TestEnvironment, TestEnvironmentDependencies, MAX_TIME_OF_FLIGHT, + }, mock::{ dummy_builder, network_bridge::{MockNetworkBridgeRx, MockNetworkBridgeTx}, @@ -876,7 +878,11 @@ fn prepare_test_inner( ) } -pub async fn bench_approvals(env: &mut TestEnvironment, mut state: ApprovalTestState) { +pub async fn bench_approvals( + benchmark_name: &str, + env: &mut TestEnvironment, + mut state: ApprovalTestState, +) -> BenchmarkUsage { let producer_rx = state .start_message_production( env.network(), @@ -885,15 +891,16 @@ pub async fn bench_approvals(env: &mut TestEnvironment, mut state: ApprovalTestS env.registry().clone(), ) .await; - bench_approvals_run(env, state, producer_rx).await + bench_approvals_run(benchmark_name, env, state, producer_rx).await } /// Runs the approval benchmark. pub async fn bench_approvals_run( + benchmark_name: &str, env: &mut TestEnvironment, state: ApprovalTestState, producer_rx: oneshot::Receiver<()>, -) { +) -> BenchmarkUsage { let config = env.config().clone(); env.metrics().set_n_validators(config.n_validators); @@ -1054,6 +1061,5 @@ pub async fn bench_approvals_run( state.total_unique_messages.load(std::sync::atomic::Ordering::SeqCst) ); - env.display_network_usage(); - env.display_cpu_usage(&["approval-distribution", "approval-voting"]); + env.collect_resource_usage(benchmark_name, &["approval-distribution", "approval-voting"]) } diff --git a/polkadot/node/subsystem-bench/src/availability/mod.rs b/polkadot/node/subsystem-bench/src/availability/mod.rs index f7f1184448b3..56ec6705b7e3 100644 --- a/polkadot/node/subsystem-bench/src/availability/mod.rs +++ b/polkadot/node/subsystem-bench/src/availability/mod.rs @@ -13,7 +13,10 @@ // You should have received a copy of the GNU General Public License // along with Polkadot. If not, see . -use crate::{core::mock::ChainApiState, TestEnvironment}; +use crate::{ + core::{environment::BenchmarkUsage, mock::ChainApiState}, + TestEnvironment, +}; use av_store::NetworkAvailabilityState; use bitvec::bitvec; use colored::Colorize; @@ -430,7 +433,11 @@ impl TestState { } } -pub async fn benchmark_availability_read(env: &mut TestEnvironment, mut state: TestState) { +pub async fn benchmark_availability_read( + benchmark_name: &str, + env: &mut TestEnvironment, + mut state: TestState, +) -> BenchmarkUsage { let config = env.config().clone(); env.import_block(new_block_import_info(Hash::repeat_byte(1), 1)).await; @@ -490,12 +497,15 @@ pub async fn benchmark_availability_read(env: &mut TestEnvironment, mut state: T format!("{} ms", test_start.elapsed().as_millis() / env.config().num_blocks as u128).red() ); - env.display_network_usage(); - env.display_cpu_usage(&["availability-recovery"]); env.stop().await; + env.collect_resource_usage(benchmark_name, &["availability-recovery"]) } -pub async fn benchmark_availability_write(env: &mut TestEnvironment, mut state: TestState) { +pub async fn benchmark_availability_write( + benchmark_name: &str, + env: &mut TestEnvironment, + mut state: TestState, +) -> BenchmarkUsage { let config = env.config().clone(); env.metrics().set_n_validators(config.n_validators); @@ -648,15 +658,11 @@ pub async fn benchmark_availability_write(env: &mut TestEnvironment, mut state: format!("{} ms", test_start.elapsed().as_millis() / env.config().num_blocks as u128).red() ); - env.display_network_usage(); - - env.display_cpu_usage(&[ - "availability-distribution", - "bitfield-distribution", - "availability-store", - ]); - env.stop().await; + env.collect_resource_usage( + benchmark_name, + &["availability-distribution", "bitfield-distribution", "availability-store"], + ) } pub fn peer_bitfield_message_v2( diff --git a/polkadot/node/subsystem-bench/src/cli.rs b/polkadot/node/subsystem-bench/src/cli.rs index bfce8cc183a9..21f5e6a85629 100644 --- a/polkadot/node/subsystem-bench/src/cli.rs +++ b/polkadot/node/subsystem-bench/src/cli.rs @@ -40,6 +40,22 @@ pub enum TestObjective { Unimplemented, } +impl std::fmt::Display for TestObjective { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + write!( + f, + "{}", + match self { + Self::DataAvailabilityRead(_) => "DataAvailabilityRead", + Self::DataAvailabilityWrite => "DataAvailabilityWrite", + Self::TestSequence(_) => "TestSequence", + Self::ApprovalVoting(_) => "ApprovalVoting", + Self::Unimplemented => "Unimplemented", + } + ) + } +} + #[derive(Debug, clap::Parser)] #[clap(rename_all = "kebab-case")] #[allow(missing_docs)] diff --git a/polkadot/node/subsystem-bench/src/core/environment.rs b/polkadot/node/subsystem-bench/src/core/environment.rs index 59bfed7f1120..cffda38f2110 100644 --- a/polkadot/node/subsystem-bench/src/core/environment.rs +++ b/polkadot/node/subsystem-bench/src/core/environment.rs @@ -22,6 +22,7 @@ use colored::Colorize; use core::time::Duration; use futures::{Future, FutureExt}; use polkadot_overseer::{BlockInfo, Handle as OverseerHandle}; +use serde::{Deserialize, Serialize}; use polkadot_node_subsystem::{messages::AllMessages, Overseer, SpawnGlue, TimeoutExt}; use polkadot_node_subsystem_types::Hash; @@ -347,57 +348,102 @@ impl TestEnvironment { } } - /// Display network usage stats. - pub fn display_network_usage(&self) { - let stats = self.network().peer_stats(0); - - let total_node_received = stats.received() / 1024; - let total_node_sent = stats.sent() / 1024; - - println!( - "\nPayload bytes received from peers: {}, {}", - format!("{:.2} KiB total", total_node_received).blue(), - format!("{:.2} KiB/block", total_node_received / self.config().num_blocks) - .bright_blue() - ); + pub fn collect_resource_usage( + &self, + benchmark_name: &str, + subsystems_under_test: &[&str], + ) -> BenchmarkUsage { + BenchmarkUsage { + benchmark_name: benchmark_name.to_string(), + network_usage: self.network_usage(), + cpu_usage: self.cpu_usage(subsystems_under_test), + } + } - println!( - "Payload bytes sent to peers: {}, {}", - format!("{:.2} KiB total", total_node_sent).blue(), - format!("{:.2} KiB/block", total_node_sent / self.config().num_blocks).bright_blue() - ); + fn network_usage(&self) -> Vec { + let stats = self.network().peer_stats(0); + let total_node_received = (stats.received() / 1024) as f64; + let total_node_sent = (stats.sent() / 1024) as f64; + let num_blocks = self.config().num_blocks as f64; + + vec![ + ResourceUsage { + resource_name: "Received from peers".to_string(), + total: total_node_received, + per_block: total_node_received / num_blocks, + }, + ResourceUsage { + resource_name: "Sent to peers".to_string(), + total: total_node_sent, + per_block: total_node_sent / num_blocks, + }, + ] } - /// Print CPU usage stats in the CLI. - pub fn display_cpu_usage(&self, subsystems_under_test: &[&str]) { + fn cpu_usage(&self, subsystems_under_test: &[&str]) -> Vec { let test_metrics = super::display::parse_metrics(self.registry()); + let mut usage = vec![]; + let num_blocks = self.config().num_blocks as f64; for subsystem in subsystems_under_test.iter() { let subsystem_cpu_metrics = test_metrics.subset_with_label_value("task_group", subsystem); let total_cpu = subsystem_cpu_metrics.sum_by("substrate_tasks_polling_duration_sum"); - println!( - "{} CPU usage {}", - subsystem.to_string().bright_green(), - format!("{:.3}s", total_cpu).bright_purple() - ); - println!( - "{} CPU usage per block {}", - subsystem.to_string().bright_green(), - format!("{:.3}s", total_cpu / self.config().num_blocks as f64).bright_purple() - ); + usage.push(ResourceUsage { + resource_name: subsystem.to_string(), + total: total_cpu, + per_block: total_cpu / num_blocks, + }); } let test_env_cpu_metrics = test_metrics.subset_with_label_value("task_group", "test-environment"); let total_cpu = test_env_cpu_metrics.sum_by("substrate_tasks_polling_duration_sum"); - println!( - "Total test environment CPU usage {}", - format!("{:.3}s", total_cpu).bright_purple() - ); - println!( - "Test environment CPU usage per block {}", - format!("{:.3}s", total_cpu / self.config().num_blocks as f64).bright_purple() + + usage.push(ResourceUsage { + resource_name: "Test environment".to_string(), + total: total_cpu, + per_block: total_cpu / num_blocks, + }); + + usage + } +} + +#[derive(Debug, Serialize, Deserialize)] +pub struct BenchmarkUsage { + benchmark_name: String, + network_usage: Vec, + cpu_usage: Vec, +} + +impl std::fmt::Display for BenchmarkUsage { + fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result { + write!( + f, + "\n{}\n\n{}\n{}\n\n{}\n{}\n", + self.benchmark_name.purple(), + format!("{:<32}{:>12}{:>12}", "Network usage, KiB", "total", "per block").blue(), + self.network_usage + .iter() + .map(|v| v.to_string()) + .collect::>() + .join("\n"), + format!("{:<32}{:>12}{:>12}", "CPU usage in seconds", "total", "per block").blue(), + self.cpu_usage.iter().map(|v| v.to_string()).collect::>().join("\n") ) } } + +#[derive(Debug, Serialize, Deserialize)] +pub struct ResourceUsage { + resource_name: String, + total: f64, + per_block: f64, +} + +impl std::fmt::Display for ResourceUsage { + fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result { + write!(f, "{:<32}{:>12.3}{:>12.3}", self.resource_name.cyan(), self.total, self.per_block) + } +} diff --git a/polkadot/node/subsystem-bench/src/subsystem-bench.rs b/polkadot/node/subsystem-bench/src/subsystem-bench.rs index 6f45214bc735..433354f6525d 100644 --- a/polkadot/node/subsystem-bench/src/subsystem-bench.rs +++ b/polkadot/node/subsystem-bench/src/subsystem-bench.rs @@ -100,6 +100,10 @@ struct BenchCli { /// Enable Cache Misses Profiling with Valgrind. Linux only, Valgrind must be in the PATH pub cache_misses: bool, + #[clap(long, default_value_t = false)] + /// Shows the output in YAML format + pub yaml_output: bool, + #[command(subcommand)] pub objective: cli::TestObjective, } @@ -164,34 +168,51 @@ impl BenchCli { format!("Sequence contains {} step(s)", num_steps).bright_purple() ); for (index, test_config) in test_sequence.into_iter().enumerate() { + let benchmark_name = + format!("{} #{} {}", &options.path, index + 1, test_config.objective); gum::info!(target: LOG_TARGET, "{}", format!("Step {}/{}", index + 1, num_steps).bright_purple(),); display_configuration(&test_config); - match test_config.objective { + let usage = match test_config.objective { TestObjective::DataAvailabilityRead(ref _opts) => { let mut state = TestState::new(&test_config); let (mut env, _protocol_config) = prepare_test(test_config, &mut state); env.runtime().block_on(availability::benchmark_availability_read( - &mut env, state, - )); + &benchmark_name, + &mut env, + state, + )) }, TestObjective::ApprovalVoting(ref options) => { let (mut env, state) = approval::prepare_test(test_config.clone(), options.clone()); - - env.runtime().block_on(bench_approvals(&mut env, state)); + env.runtime().block_on(bench_approvals( + &benchmark_name, + &mut env, + state, + )) }, TestObjective::DataAvailabilityWrite => { let mut state = TestState::new(&test_config); let (mut env, _protocol_config) = prepare_test(test_config, &mut state); env.runtime().block_on(availability::benchmark_availability_write( - &mut env, state, - )); + &benchmark_name, + &mut env, + state, + )) }, TestObjective::TestSequence(_) => todo!(), TestObjective::Unimplemented => todo!(), - } + }; + + let output = if self.yaml_output { + serde_yaml::to_string(&vec![usage])? + } else { + usage.to_string() + }; + println!("{}", output); } + return Ok(()) }, TestObjective::DataAvailabilityRead(ref _options) => self.create_test_configuration(), @@ -232,25 +253,28 @@ impl BenchCli { let mut state = TestState::new(&test_config); let (mut env, _protocol_config) = prepare_test(test_config, &mut state); - match self.objective { - TestObjective::DataAvailabilityRead(_options) => { - env.runtime() - .block_on(availability::benchmark_availability_read(&mut env, state)); - }, - TestObjective::DataAvailabilityWrite => { - env.runtime() - .block_on(availability::benchmark_availability_write(&mut env, state)); - }, - TestObjective::TestSequence(_options) => {}, + let benchmark_name = format!("{}", self.objective); + let usage = match self.objective { + TestObjective::DataAvailabilityRead(_options) => env.runtime().block_on( + availability::benchmark_availability_read(&benchmark_name, &mut env, state), + ), + TestObjective::DataAvailabilityWrite => env.runtime().block_on( + availability::benchmark_availability_write(&benchmark_name, &mut env, state), + ), + TestObjective::TestSequence(_options) => todo!(), TestObjective::ApprovalVoting(_) => todo!(), TestObjective::Unimplemented => todo!(), - } + }; if let Some(agent_running) = agent_running { let agent_ready = agent_running.stop()?; agent_ready.shutdown(); } + let output = + if self.yaml_output { serde_yaml::to_string(&vec![usage])? } else { usage.to_string() }; + println!("{}", output); + Ok(()) } }