subsystem-bench: Prepare CI output (paritytech#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>

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"])
 }

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 <http://www.gnu.org/licenses/>.
-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(

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)]

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<ResourceUsage> {
+		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<ResourceUsage> {
 		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<ResourceUsage>,
+	cpu_usage: Vec<ResourceUsage>,
+}
+
+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::<Vec<String>>()
+				.join("\n"),
+			format!("{:<32}{:>12}{:>12}", "CPU usage in seconds", "total", "per block").blue(),
+			self.cpu_usage.iter().map(|v| v.to_string()).collect::<Vec<String>>().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)
+	}
+}

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(())
 	}
 }