Add support for wasm runtime metrics try #2

Cargo.toml

@@ -118,6 +118,7 @@ panic = "unwind"
 runtime-benchmarks= [ "polkadot-cli/runtime-benchmarks" ]
 try-runtime = [ "polkadot-cli/try-runtime" ]
 disputes = [ "polkadot-cli/disputes" ]
+runtime-metrics = [ "polkadot-cli/runtime-metrics" ]
 
 # Configuration for building a .deb package - for use with `cargo-deb`
 [package.metadata.deb]

cli/Cargo.toml

@@ -28,6 +28,7 @@ frame-benchmarking-cli = { git = "https://github.com/paritytech/substrate", bran
 try-runtime-cli = { git = "https://github.com/paritytech/substrate", branch = "master", optional = true }
 sc-cli = { git = "https://github.com/paritytech/substrate", branch = "master", optional = true }
 sc-service = { git = "https://github.com/paritytech/substrate", branch = "master", optional = true }
+polkadot-node-metrics = { path = "../node/metrics" }
 sc-tracing = { git = "https://github.com/paritytech/substrate", branch = "master", optional = true }
 
 # this crate is used only to enable `trie-memory-tracker` feature
@@ -66,3 +67,4 @@ rococo-native = [ "service/rococo-native" ]
 
 malus = [ "full-node", "service/malus" ]
 disputes = [ "service/disputes" ]
+runtime-metrics = ["service/runtime-metrics", "polkadot-node-metrics/runtime-metrics"]

cli/src/command.rs

@@ -222,11 +222,20 @@ fn host_perf_check() -> Result<()> {
 /// for integration tests as needed.
 #[cfg(feature = "malus")]
 pub fn run_node(run: Cli, overseer_gen: impl service::OverseerGen) -> Result<()> {
-	run_node_inner(run, overseer_gen)
+	run_node_inner(run, overseer_gen, |_, _| {})
 }
 
-fn run_node_inner(cli: Cli, overseer_gen: impl service::OverseerGen) -> Result<()> {
-	let runner = cli.create_runner(&cli.run.base).map_err(Error::from)?;
+fn run_node_inner<F>(
+	cli: Cli,
+	overseer_gen: impl service::OverseerGen,
+	logger_hook: F,
+) -> Result<()>
+where
+	F: FnOnce(&mut sc_cli::LoggerBuilder, &sc_service::Configuration),
+{
+	let runner = cli
+		.create_runner_with_logger_hook::<sc_cli::RunCmd, F>(&cli.run.base, logger_hook)
+		.map_err(Error::from)?;
 	let chain_spec = &runner.config().chain_spec;
 
 	set_default_ss58_version(chain_spec);
@@ -267,12 +276,17 @@ fn run_node_inner(cli: Cli, overseer_gen: impl service::OverseerGen) -> Result<(
 	})
 }
 
+/// TODO: Start the node with support for publishing runtime metrics.
+pub fn run_with_wasm_metrics() -> Result<()> {
+	Ok(())
+}
+
 /// Parses polkadot specific CLI arguments and run the service.
 pub fn run() -> Result<()> {
-	let cli = Cli::from_args();
+	let cli: Cli = Cli::from_args();
 
 	match &cli.subcommand {
-		None => run_node_inner(cli, service::RealOverseerGen),
+		None => run_node_inner(cli, service::RealOverseerGen, polkadot_node_metrics::logger_hook()),
 		Some(Subcommand::BuildSpec(cmd)) => {
 			let runner = cli.create_runner(cmd)?;
 			Ok(runner.sync_run(|config| cmd.run(config.chain_spec, config.network))?)

node/client/Cargo.toml

@@ -45,3 +45,9 @@ polkadot = ["polkadot-runtime"]
 kusama = ["kusama-runtime"]
 rococo = ["rococo-runtime"]
 westend = ["westend-runtime"]
+runtime-metrics = [
+    "rococo-runtime/runtime-metrics",
+    "kusama-runtime/runtime-metrics",
+    "westend-runtime/runtime-metrics",
+    "polkadot-runtime/runtime-metrics",
+]

node/metrics/Cargo.toml

@@ -3,15 +3,26 @@ name = "polkadot-node-metrics"
 version = "0.9.13"
 authors = ["Parity Technologies <[email protected]>"]
 edition = "2018"
-description = "Subsystem traits and message definitions"
+description = "Subsystem metric helpers"
 
 [dependencies]
 futures = "0.3.17"
 futures-timer = "3.0.2"
+tracing = "0.1.29"
 
 metered-channel = { path = "../metered-channel" }
 
+# Both `sc-service` and `sc-cli` are required by runtime metrics `logger_hook()`.
+sc-service = { git = "https://github.com/paritytech/substrate", branch = "master" }
+sc-cli = { git = "https://github.com/paritytech/substrate", branch = "master" }
+
 substrate-prometheus-endpoint = { git = "https://github.com/paritytech/substrate", branch = "master" }
+sc-tracing = { git = "https://github.com/paritytech/substrate", branch = "master" }
+codec = { package = "parity-scale-codec", version = "2.2.0" }
+primitives = { package = "polkadot-primitives", path = "../../primitives/" }
+bs58 = { version = "0.4.0", features = ["alloc"] }
+log = "0.4.13"
 
 [features]
 default = []
+runtime-metrics = []

node/metrics/src/lib.rs

@@ -30,6 +30,17 @@ pub use metered_channel as metered;
 pub mod metronome;
 pub use self::metronome::Metronome;
 
+#[cfg(feature = "runtime-metrics")]
+pub mod runtime;
+#[cfg(feature = "runtime-metrics")]
+pub use self::runtime::logger_hook;
+
+/// Export a dummy logger hook when `wasm tracing` is not enabled.
+#[cfg(not(feature = "runtime-metrics"))]
+pub fn logger_hook() -> impl FnOnce(&mut sc_cli::LoggerBuilder, &sc_service::Configuration) -> () {
+	|_logger_builder, _config| {}
+}
+
 /// This module reexports Prometheus types and defines the [`Metrics`] trait.
 pub mod metrics {
 	/// Reexport Substrate Prometheus types.

node/metrics/src/runtime.rs

@@ -0,0 +1,174 @@
+// Copyright 2021 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/>.
+
+//! Runtime Metrics helpers.
+//!
+//! A runtime metric provider implementation that builds on top of Substrate wasm
+//! tracing support. This requires that the custom profiler (`TraceHandler`) to be
+//! registered in substrate via a `logger_hook()`. Events emitted from runtime are
+//! then captured/processed by the `TraceHandler` implementation.
+//!
+#![cfg(feature = "runtime-metrics")]
+
+use codec::Decode;
+use primitives::v1::{
+	RuntimeMetricLabelValues, RuntimeMetricOp, RuntimeMetricRegisterParams, RuntimeMetricUpdate,
+};
+use std::{
+	collections::hash_map::HashMap,
+	sync::{Arc, Mutex},
+};
+use substrate_prometheus_endpoint::{register, CounterVec, Opts, PrometheusError, Registry, U64};
+
+const LOG_TARGET: &'static str = "metrics::runtime";
+
+/// Support only CounterVec for now.
+/// TODO: add more when needed.
+#[derive(Clone, Default)]
+pub struct Metrics {
+	counter_vecs: Arc<Mutex<HashMap<String, CounterVec<U64>>>>,
+}
+/// Runtime metrics wrapper.
+#[derive(Clone)]
+pub struct RuntimeMetricsProvider(Registry, Metrics);
+
+impl RuntimeMetricsProvider {
+	/// Creates new instance.
+	pub fn new(metrics_registry: Registry) -> Self {
+		Self(metrics_registry, Metrics::default())
+	}
+
+	/// Register a counter vec metric.
+	pub fn register_countervec(
+		&self,
+		metric_name: &str,
+		params: &RuntimeMetricRegisterParams,
+	) -> Result<(), PrometheusError> {
+		match self.1.counter_vecs.lock() {
+			Ok(mut unlocked_hashtable) => {
+				if unlocked_hashtable.contains_key(metric_name) {
+					return Ok(())
+				}
+
+				unlocked_hashtable.insert(
+					metric_name.to_owned(),
+					register(
+						CounterVec::new(
+							Opts::new(metric_name, params.description()),
+							&params.labels(),
+						)?,
+						&self.0,
+					)?,
+				);
+			},
+			Err(e) => tracing::error!(
+				target: LOG_TARGET,
+				"Failed to acquire the `counter_vecs` lock: {:?}",
+				e
+			),
+		}
+		Ok(())
+	}
+
+	/// Increment a counter vec by a value.
+	pub fn inc_counter_by(&self, name: &str, value: u64, labels: &RuntimeMetricLabelValues) {
+		let _ = self.1.counter_vecs.lock().map(|mut unlocked_hashtable| {
+			if let Some(counter_vec) = unlocked_hashtable.get_mut(name) {
+				counter_vec.with_label_values(&labels.as_str()).inc_by(value);
+			} else {
+				tracing::error!(
+					target: LOG_TARGET,
+					"Cannot increment counter `{}`, metric not in registered or present in hashtable",
+					name
+				);
+			}
+		});
+	}
+}
+
+impl sc_tracing::TraceHandler for RuntimeMetricsProvider {
+	fn handle_span(&self, _span: &sc_tracing::SpanDatum) {}
+	fn handle_event(&self, event: &sc_tracing::TraceEvent) {
+		if event
+			.values
+			.string_values
+			.get("target")
+			.unwrap_or(&String::default())
+			.ne("metrics")
+		{
+			return
+		}
+
+		if let Some(update_op_bs58) = event.values.string_values.get("params").cloned() {
+			// Deserialize the metric update struct.
+			match RuntimeMetricUpdate::decode(
+				&mut RuntimeMetricsProvider::parse_event_params(&update_op_bs58)
+					.unwrap_or_default()
+					.as_slice(),
+			) {
+				Ok(update_op) => {
+					self.parse_metric_update(update_op);
+				},
+				Err(e) => {
+					tracing::error!(target: LOG_TARGET, "TraceEvent decode failed: {:?}", e);
+				},
+			}
+		}
+	}
+}
+
+impl RuntimeMetricsProvider {
+	// Parse end execute the update operation.
+	fn parse_metric_update(&self, update: RuntimeMetricUpdate) {
+		match update.op {
+			RuntimeMetricOp::Register(ref params) => {
+				let _ = self.register_countervec(update.metric_name(), &params);
+			},
+			RuntimeMetricOp::Increment(value, ref labels) =>
+				self.inc_counter_by(update.metric_name(), value, labels),
+		}
+	}
+
+	// Returns the `bs58` encoded metric update operation.
+	fn parse_event_params(event_params: &String) -> Option<Vec<u8>> {
+		// Shave " }" suffix.
+		let new_len = event_params.len().saturating_sub(2);
+		let event_params = &event_params[..new_len];
+
+		// Shave " { update_op: " prefix.
+		const SKIP_CHARS: &'static str = " { update_op: ";
+		if SKIP_CHARS.len() < event_params.len() {
+			if SKIP_CHARS.eq_ignore_ascii_case(&event_params[..SKIP_CHARS.len()]) {
+				return bs58::decode(&event_params[SKIP_CHARS.len()..].as_bytes()).into_vec().ok()
+			}
+		}
+
+		// No event was parsed
+		None
+	}
+}
+
+/// Returns the custom profiling closure that we'll apply to the LoggerBuilder.
+pub fn logger_hook() -> impl FnOnce(&mut sc_cli::LoggerBuilder, &sc_service::Configuration) -> () {
+	|logger_builder, config| {
+		if config.prometheus_registry().is_none() {
+			return
+		}
+		let registry = config.prometheus_registry().cloned().unwrap();
+		let metrics_provider = RuntimeMetricsProvider::new(registry);
+		logger_builder.with_custom_profiling(Box::new(metrics_provider));
+	}
+}

node/service/Cargo.toml

@@ -179,3 +179,11 @@ try-runtime = [
 ]
 malus = ["full-node"]
 disputes = ["polkadot-node-core-dispute-coordinator/disputes"]
+runtime-metrics = [
+	"polkadot-client/runtime-metrics", 
+	"rococo-runtime/runtime-metrics",
+	"westend-runtime/runtime-metrics",
+	"kusama-runtime/runtime-metrics",
+	"polkadot-runtime/runtime-metrics",
+	"polkadot-runtime-parachains/runtime-metrics"
+]