Files
pezkuwi-subxt/polkadot/node/network/availability-recovery/src/metrics.rs
T
Andrei Sandu 8a6e9ef189 Introduce subsystem benchmarking tool (#2528)
This tool makes it easy to run parachain consensus stress/performance
testing on your development machine or in CI.

## Motivation
The parachain consensus node implementation spans across many modules
which we call subsystems. Each subsystem is responsible for a small part
of logic of the parachain consensus pipeline, but in general the most
load and performance issues are localized in just a few core subsystems
like `availability-recovery`, `approval-voting` or
`dispute-coordinator`. In the absence of such a tool, we would run large
test nets to load/stress test these parts of the system. Setting up and
making sense of the amount of data produced by such a large test is very
expensive, hard to orchestrate and is a huge development time sink.

## PR contents
- CLI tool 
- Data Availability Read test
- reusable mockups and components needed so far
- Documentation on how to get started

### Data Availability Read test

An overseer is built with using a real `availability-recovery` susbsytem
instance while dependent subsystems like `av-store`, `network-bridge`
and `runtime-api` are mocked. The network bridge will emulate all the
network peers and their answering to requests.

The test is going to be run for a number of blocks. For each block it
will generate send a “RecoverAvailableData” request for an arbitrary
number of candidates. We wait for the subsystem to respond to all
requests before moving to the next block.
At the same time we collect the usual subsystem metrics and task CPU
metrics and show some nice progress reports while running.

### Here is how the CLI looks like:

```
[2023-11-28T13:06:27Z INFO  subsystem_bench::core::display] n_validators = 1000, n_cores = 20, pov_size = 5120 - 5120, error = 3, latency = Some(PeerLatency { min_latency: 1ms, max_latency: 100ms })
[2023-11-28T13:06:27Z INFO  subsystem-bench::availability] Generating template candidate index=0 pov_size=5242880
[2023-11-28T13:06:27Z INFO  subsystem-bench::availability] Created test environment.
[2023-11-28T13:06:27Z INFO  subsystem-bench::availability] Pre-generating 60 candidates.
[2023-11-28T13:06:30Z INFO  subsystem-bench::core] Initializing network emulation for 1000 peers.
[2023-11-28T13:06:30Z INFO  subsystem-bench::availability] Current block 1/3
[2023-11-28T13:06:30Z INFO  substrate_prometheus_endpoint] 〽️ Prometheus exporter started at 127.0.0.1:9999
[2023-11-28T13:06:30Z INFO  subsystem_bench::availability] 20 recoveries pending
[2023-11-28T13:06:37Z INFO  subsystem_bench::availability] Block time 6262ms
[2023-11-28T13:06:37Z INFO  subsystem-bench::availability] Sleeping till end of block (0ms)
[2023-11-28T13:06:37Z INFO  subsystem-bench::availability] Current block 2/3
[2023-11-28T13:06:37Z INFO  subsystem_bench::availability] 20 recoveries pending
[2023-11-28T13:06:43Z INFO  subsystem_bench::availability] Block time 6369ms
[2023-11-28T13:06:43Z INFO  subsystem-bench::availability] Sleeping till end of block (0ms)
[2023-11-28T13:06:43Z INFO  subsystem-bench::availability] Current block 3/3
[2023-11-28T13:06:43Z INFO  subsystem_bench::availability] 20 recoveries pending
[2023-11-28T13:06:49Z INFO  subsystem_bench::availability] Block time 6194ms
[2023-11-28T13:06:49Z INFO  subsystem-bench::availability] Sleeping till end of block (0ms)
[2023-11-28T13:06:49Z INFO  subsystem_bench::availability] All blocks processed in 18829ms
[2023-11-28T13:06:49Z INFO  subsystem_bench::availability] Throughput: 102400 KiB/block
[2023-11-28T13:06:49Z INFO  subsystem_bench::availability] Block time: 6276 ms
[2023-11-28T13:06:49Z INFO  subsystem_bench::availability] 
    
    Total received from network: 415 MiB
    Total sent to network: 724 KiB
    Total subsystem CPU usage 24.00s
    CPU usage per block 8.00s
    Total test environment CPU usage 0.15s
    CPU usage per block 0.05s
```

### Prometheus/Grafana stack in action
<img width="1246" alt="Screenshot 2023-11-28 at 15 11 10"
src="https://github.com/paritytech/polkadot-sdk/assets/54316454/eaa47422-4a5e-4a3a-aaef-14ca644c1574">
<img width="1246" alt="Screenshot 2023-11-28 at 15 12 01"
src="https://github.com/paritytech/polkadot-sdk/assets/54316454/237329d6-1710-4c27-8f67-5fb11d7f66ea">
<img width="1246" alt="Screenshot 2023-11-28 at 15 12 38"
src="https://github.com/paritytech/polkadot-sdk/assets/54316454/a07119e8-c9f1-4810-a1b3-f1b7b01cf357">

---------

Signed-off-by: Andrei Sandu <andrei-mihail@parity.io>
2023-12-14 12:57:17 +02:00

244 lines
7.9 KiB
Rust

// Copyright (C) Parity Technologies (UK) Ltd.
// This file is part of Polkadot.
// Polkadot is free software: you can redistribute it and/or modify
// it under the terms of the GNU General Public License as published by
// the Free Software Foundation, either version 3 of the License, or
// (at your option) any later version.
// Polkadot is distributed in the hope that it will be useful,
// but WITHOUT ANY WARRANTY; without even the implied warranty of
// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
// GNU General Public License for more details.
// You should have received a copy of the GNU General Public License
// along with Polkadot. If not, see <http://www.gnu.org/licenses/>.
use polkadot_node_subsystem_util::metrics::{
self,
prometheus::{self, Counter, CounterVec, Histogram, Opts, PrometheusError, Registry, U64},
};
/// Availability Distribution metrics.
#[derive(Clone, Default)]
pub struct Metrics(Option<MetricsInner>);
#[derive(Clone)]
struct MetricsInner {
/// Number of sent chunk requests.
///
/// Gets incremented on each sent chunk requests.
chunk_requests_issued: Counter<U64>,
/// Total number of bytes recovered
///
/// Gets incremented on each succesful recovery
recovered_bytes_total: Counter<U64>,
/// A counter for finished chunk requests.
///
/// Split by result:
/// - `no_such_chunk` ... peer did not have the requested chunk
/// - `timeout` ... request timed out.
/// - `network_error` ... Some networking issue except timeout
/// - `invalid` ... Chunk was received, but not valid.
/// - `success`
chunk_requests_finished: CounterVec<U64>,
/// The duration of request to response.
time_chunk_request: Histogram,
/// The duration between the pure recovery and verification.
time_erasure_recovery: Histogram,
/// How much time it takes to re-encode the data into erasure chunks in order to verify
/// the root hash of the provided Merkle tree. See `reconstructed_data_matches_root`.
time_reencode_chunks: Histogram,
/// Time of a full recovery, including erasure decoding or until we gave
/// up.
time_full_recovery: Histogram,
/// Number of full recoveries that have been finished one way or the other.
full_recoveries_finished: CounterVec<U64>,
/// Number of full recoveries that have been started on this subsystem.
///
/// Note: Those are only recoveries which could not get served locally already - so in other
/// words: Only real recoveries.
full_recoveries_started: Counter<U64>,
}
impl Metrics {
/// Create new dummy metrics, not reporting anything.
pub fn new_dummy() -> Self {
Metrics(None)
}
/// Increment counter on fetched labels.
pub fn on_chunk_request_issued(&self) {
if let Some(metrics) = &self.0 {
metrics.chunk_requests_issued.inc()
}
}
/// A chunk request timed out.
pub fn on_chunk_request_timeout(&self) {
if let Some(metrics) = &self.0 {
metrics.chunk_requests_finished.with_label_values(&["timeout"]).inc()
}
}
/// A chunk request failed because validator did not have its chunk.
pub fn on_chunk_request_no_such_chunk(&self) {
if let Some(metrics) = &self.0 {
metrics.chunk_requests_finished.with_label_values(&["no_such_chunk"]).inc()
}
}
/// A chunk request failed for some non timeout related network error.
pub fn on_chunk_request_error(&self) {
if let Some(metrics) = &self.0 {
metrics.chunk_requests_finished.with_label_values(&["error"]).inc()
}
}
/// A chunk request succeeded, but was not valid.
pub fn on_chunk_request_invalid(&self) {
if let Some(metrics) = &self.0 {
metrics.chunk_requests_finished.with_label_values(&["invalid"]).inc()
}
}
/// A chunk request succeeded.
pub fn on_chunk_request_succeeded(&self) {
if let Some(metrics) = &self.0 {
metrics.chunk_requests_finished.with_label_values(&["success"]).inc()
}
}
/// Get a timer to time request/response duration.
pub fn time_chunk_request(&self) -> Option<metrics::prometheus::prometheus::HistogramTimer> {
self.0.as_ref().map(|metrics| metrics.time_chunk_request.start_timer())
}
/// Get a timer to time erasure code recover.
pub fn time_erasure_recovery(&self) -> Option<metrics::prometheus::prometheus::HistogramTimer> {
self.0.as_ref().map(|metrics| metrics.time_erasure_recovery.start_timer())
}
/// Get a timer to time chunk encoding.
pub fn time_reencode_chunks(&self) -> Option<metrics::prometheus::prometheus::HistogramTimer> {
self.0.as_ref().map(|metrics| metrics.time_reencode_chunks.start_timer())
}
/// Get a timer to measure the time of the complete recovery process.
pub fn time_full_recovery(&self) -> Option<metrics::prometheus::prometheus::HistogramTimer> {
self.0.as_ref().map(|metrics| metrics.time_full_recovery.start_timer())
}
/// A full recovery succeeded.
pub fn on_recovery_succeeded(&self, bytes: usize) {
if let Some(metrics) = &self.0 {
metrics.full_recoveries_finished.with_label_values(&["success"]).inc();
metrics.recovered_bytes_total.inc_by(bytes as u64)
}
}
/// A full recovery failed (data not available).
pub fn on_recovery_failed(&self) {
if let Some(metrics) = &self.0 {
metrics.full_recoveries_finished.with_label_values(&["failure"]).inc()
}
}
/// A full recovery failed (data was recovered, but invalid).
pub fn on_recovery_invalid(&self) {
if let Some(metrics) = &self.0 {
metrics.full_recoveries_finished.with_label_values(&["invalid"]).inc()
}
}
/// A recover was started.
pub fn on_recovery_started(&self) {
if let Some(metrics) = &self.0 {
metrics.full_recoveries_started.inc()
}
}
}
impl metrics::Metrics for Metrics {
fn try_register(registry: &Registry) -> Result<Self, PrometheusError> {
let metrics = MetricsInner {
chunk_requests_issued: prometheus::register(
Counter::new(
"polkadot_parachain_availability_recovery_chunk_requests_issued",
"Total number of issued chunk requests.",
)?,
registry,
)?,
recovered_bytes_total: prometheus::register(
Counter::new(
"polkadot_parachain_availability_recovery_bytes_total",
"Total number of bytes recovered",
)?,
registry,
)?,
chunk_requests_finished: prometheus::register(
CounterVec::new(
Opts::new(
"polkadot_parachain_availability_recovery_chunk_requests_finished",
"Total number of chunk requests finished.",
),
&["result"],
)?,
registry,
)?,
time_chunk_request: prometheus::register(
prometheus::Histogram::with_opts(prometheus::HistogramOpts::new(
"polkadot_parachain_availability_recovery_time_chunk_request",
"Time spent waiting for a response to a chunk request",
))?,
registry,
)?,
time_erasure_recovery: prometheus::register(
prometheus::Histogram::with_opts(prometheus::HistogramOpts::new(
"polkadot_parachain_availability_recovery_time_erasure_recovery",
"Time spent to recover the erasure code and verify the merkle root by re-encoding as erasure chunks",
))?,
registry,
)?,
time_reencode_chunks: prometheus::register(
prometheus::Histogram::with_opts(prometheus::HistogramOpts::new(
"polkadot_parachain_availability_reencode_chunks",
"Time spent re-encoding the data as erasure chunks",
))?,
registry,
)?,
time_full_recovery: prometheus::register(
prometheus::Histogram::with_opts(prometheus::HistogramOpts::new(
"polkadot_parachain_availability_recovery_time_total",
"Time a full recovery process took, either until failure or successful erasure decoding.",
))?,
registry,
)?,
full_recoveries_finished: prometheus::register(
CounterVec::new(
Opts::new(
"polkadot_parachain_availability_recovery_recoveries_finished",
"Total number of recoveries that finished.",
),
&["result"],
)?,
registry,
)?,
full_recoveries_started: prometheus::register(
Counter::new(
"polkadot_parachain_availability_recovery_recovieries_started",
"Total number of started recoveries.",
)?,
registry,
)?,
};
Ok(Metrics(Some(metrics)))
}
}