add tracing metrics layer for dependency logging

Cargo.toml

@@ -160,6 +160,8 @@ tempfile = "3"
 tokio = { version = "1", features = ["rt-multi-thread", "sync", "signal"] }
 tokio-stream = { version = "0.1", features = ["sync"] }
 tokio-util = { version = "0.6", features = ["codec", "compat", "time"] }
+tracing-core = "0.1"
+tracing-subscriber = "0.3"
 tree_hash = "0.5"
 tree_hash_derive = "0.5"
 url = "2"

boot_node/src/lib.rs

@@ -48,11 +48,8 @@ pub fn run(
         log::Level::Error => drain.filter_level(Level::Error),
     };
 
-    let logger = Logger::root(drain.fuse(), o!());
-    let _scope_guard = slog_scope::set_global_logger(logger);
-    slog_stdlog::init_with_level(debug_level).unwrap();
+    let log = Logger::root(drain.fuse(), o!());
 
-    let log = slog_scope::logger();
     // Run the main function emitting any errors
     if let Err(e) = match eth_spec_id {
         EthSpecId::Minimal => {

common/logging/Cargo.toml

@@ -20,3 +20,5 @@ parking_lot = { workspace = true }
 serde = { workspace = true }
 serde_json = { workspace = true }
 chrono = { version = "0.4", default-features = false, features = ["clock", "std"] }
+tracing-subscriber = { workspace = true }
+tracing-core = { workspace = true }

common/logging/src/lib.rs

@@ -13,7 +13,10 @@ pub const MAX_MESSAGE_WIDTH: usize = 40;
 
 pub mod async_record;
 mod sse_logging_components;
+mod tracing_metrics_layer;
+
 pub use sse_logging_components::SSELoggingComponents;
+pub use tracing_metrics_layer::MetricsLayer;
 
 /// The minimum interval between log messages indicating that a queue is full.
 const LOG_DEBOUNCE_INTERVAL: Duration = Duration::from_secs(30);

common/logging/src/tracing_metrics_layer.rs

@@ -0,0 +1,56 @@
+//! Exposes [`MetricsLayer`]: A tracing layer that registers metrics of logging events.
+
+use lighthouse_metrics as metrics;
+
+lazy_static! {
+    /// Count of `INFO` logs registered per enabled dependency.
+    pub static ref DEP_INFOS_TOTAL: metrics::Result<metrics::IntCounterVec> =
+        metrics::try_create_int_counter_vec(
+            "dep_info_total",
+            "Count of infos logged per enabled dependency",
+            &["target"]
+        );
+    /// Count of `WARN` logs registered per enabled dependency.
+    pub static ref DEP_WARNS_TOTAL: metrics::Result<metrics::IntCounterVec> =
+        metrics::try_create_int_counter_vec(
+            "dep_warn_total",
+            "Count of warns logged per enabled dependency",
+            &["target"]
+        );
+    /// Count of `ERROR` logs registered per enabled dependency.
+    pub static ref DEP_ERRORS_TOTAL: metrics::Result<metrics::IntCounterVec> =
+        metrics::try_create_int_counter_vec(
+            "dep_error_total",
+            "Count of errors logged per enabled dependency",
+            &["target"]
+        );
+}
+
+/// Layer that registers Prometheus metrics for `INFO`, `WARN` and `ERROR` logs emitted per dependency.
+/// Dependencies are enabled via the `RUST_LOG` env flag.
+pub struct MetricsLayer;
+
+impl<S: tracing_core::Subscriber> tracing_subscriber::layer::Layer<S> for MetricsLayer {
+    fn on_event(
+        &self,
+        event: &tracing_core::Event<'_>,
+        _ctx: tracing_subscriber::layer::Context<'_, S>,
+    ) {
+        let meta = event.metadata();
+        if !meta.is_event() {
+            // ignore tracing span events
+            return;
+        }
+        let target = match meta.target().split_once("::") {
+            Some((crate_name, _)) => crate_name,
+            None => "unknown",
+        };
+        let target = &[target];
+        match *meta.level() {
+            tracing_core::Level::INFO => metrics::inc_counter_vec(&DEP_INFOS_TOTAL, target),
+            tracing_core::Level::WARN => metrics::inc_counter_vec(&DEP_WARNS_TOTAL, target),
+            tracing_core::Level::ERROR => metrics::inc_counter_vec(&DEP_ERRORS_TOTAL, target),
+            _ => {}
+        }
+    }
+}

lighthouse/Cargo.toml

@@ -35,7 +35,6 @@ types = { workspace = true }
 bls = { workspace = true }
 ethereum_hashing = { workspace = true }
 clap = { workspace = true }
-env_logger = { workspace = true }
 environment = { workspace = true }
 boot_node = { path = "../boot_node" }
 futures = { workspace = true }
@@ -57,6 +56,8 @@ unused_port = { workspace = true }
 database_manager = { path = "../database_manager" }
 slasher = { workspace = true }
 validator_manager = { path = "../validator_manager" }
+tracing-subscriber = { workspace = true }
+logging = { workspace = true }
 
 [dev-dependencies]
 tempfile = { workspace = true }

lighthouse/src/main.rs

@@ -4,7 +4,6 @@ use beacon_node::ProductionBeaconNode;
 use clap::{App, Arg, ArgMatches};
 use clap_utils::{flags::DISABLE_MALLOC_TUNING_FLAG, get_eth2_network_config};
 use directory::{parse_path_or_default, DEFAULT_BEACON_NODE_DIR, DEFAULT_VALIDATOR_DIR};
-use env_logger::{Builder, Env};
 use environment::{EnvironmentBuilder, LoggerConfig};
 use eth2_network_config::{Eth2NetworkConfig, DEFAULT_HARDCODED_NETWORK, HARDCODED_NET_NAMES};
 use ethereum_hashing::have_sha_extensions;
@@ -15,6 +14,7 @@ use slog::{crit, info};
 use std::path::PathBuf;
 use std::process::exit;
 use task_executor::ShutdownReason;
+use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
 use types::{EthSpec, EthSpecId};
 use validator_client::ProductionValidatorClient;
 
@@ -84,7 +84,8 @@ fn main() {
         .arg(
             Arg::with_name("env_log")
                 .short("l")
-                .help("Enables environment logging giving access to sub-protocol logs such as discv5 and libp2p",
+                .help(
+                    "DEPRECATED Enables environment logging giving access to sub-protocol logs such as discv5 and libp2p",
                 )
                 .takes_value(false),
         )
@@ -364,9 +365,30 @@ fn main() {
         }
     }
 
-    // Debugging output for libp2p and external crates.
+    // Debugging output for discv5, libp2p and external crates.
     if matches.is_present("env_log") {
-        Builder::from_env(Env::default()).init();
+        eprintln!("The -l flag is DEPRECATED. Dependency logging will be on by default.");
+    }
+
+    // read the `RUST_LOG` statement
+    let filter_layer = match tracing_subscriber::EnvFilter::try_from_default_env()
+        .or_else(|_| tracing_subscriber::EnvFilter::try_new("warn"))
+    {
+        Ok(filter) => filter,
+        Err(e) => {
+            eprintln!("Failed to initialize dependency logging {e}");
+            exit(1)
+        }
+    };
+
+    if let Err(e) = tracing_subscriber::fmt()
+        .with_env_filter(filter_layer)
+        .finish()
+        .with(logging::MetricsLayer)
+        .try_init()
+    {
+        eprintln!("Failed to initialize dependency logging {e}");
+        exit(1)
     }
 
     let result = get_eth2_network_config(&matches).and_then(|eth2_network_config| {