log rotation

Cargo.toml

@@ -54,6 +54,7 @@ serde_yaml = "0.9.33"
 # telemetry
 tracing = "0.1.40"
 tracing-subscriber = { version = "0.3.18", features = ["env-filter"] }
+tracing-appender = "0.2.3"
 prometheus = "0.13.4"
 
 # crypto

bin/default_pbs.rs

@@ -1,4 +1,6 @@
-use cb_common::{config::load_pbs_config, utils::initialize_tracing_log};
+use cb_common::{
+    config::load_pbs_config, module_names::PBS_MODULE_NAME, utils::initialize_tracing_log,
+};
 use cb_pbs::{DefaultBuilderApi, PbsService, PbsState};
 use eyre::Result;
 
@@ -11,12 +13,10 @@ async fn main() -> Result<()> {
         std::env::set_var("RUST_BACKTRACE", "1");
     }
 
-    initialize_tracing_log();
-
     // TODO: handle errors
     let pbs_config = load_pbs_config().expect("failed to load pbs config");
+    let _guard = initialize_tracing_log(PBS_MODULE_NAME);
     let state = PbsState::<()>::new(pbs_config);
-
     PbsService::init_metrics()?;
     PbsService::run::<(), DefaultBuilderApi>(state).await;
     Ok(())

bin/signer_module.rs

@@ -1,4 +1,6 @@
-use cb_common::{config::StartSignerConfig, utils::initialize_tracing_log};
+use cb_common::{
+    config::StartSignerConfig, module_names::SIGNER_MODULE_NAME, utils::initialize_tracing_log,
+};
 use cb_signer::service::SigningService;
 use eyre::Result;
 
@@ -11,8 +13,7 @@ async fn main() -> Result<()> {
         std::env::set_var("RUST_BACKTRACE", "1");
     }
 
-    initialize_tracing_log();
-
     let config = StartSignerConfig::load_from_env()?;
+    let _guard = initialize_tracing_log(SIGNER_MODULE_NAME);
     SigningService::run(config).await
 }

config.example.toml

@@ -39,3 +39,8 @@ sleep_secs = 5
 id = "BUILDER_LOG"
 type = "events"
 docker_image = "test_builder_log"
+
+[logs]
+duration = "daily"
+host-path="./logs"
+rust-log="info"

crates/cli/src/docker_init.rs

@@ -2,13 +2,13 @@ use std::{path::Path, vec};
 
 use cb_common::{
     config::{
-        CommitBoostConfig, ModuleKind, BUILDER_SERVER_ENV, CB_CONFIG_ENV, CB_CONFIG_NAME, JWTS_ENV,
-        METRICS_SERVER_ENV, MODULE_ID_ENV, MODULE_JWT_ENV, SIGNER_DIR_KEYS, SIGNER_DIR_KEYS_ENV,
-        SIGNER_DIR_SECRETS, SIGNER_DIR_SECRETS_ENV, SIGNER_KEYS, SIGNER_KEYS_ENV,
-        SIGNER_SERVER_ENV,
+        CommitBoostConfig, ModuleKind, BUILDER_SERVER_ENV, CB_BASE_LOG_PATH, CB_CONFIG_ENV,
+        CB_CONFIG_NAME, JWTS_ENV, METRICS_SERVER_ENV, MODULE_ID_ENV, MODULE_JWT_ENV,
+        SIGNER_DIR_KEYS, SIGNER_DIR_KEYS_ENV, SIGNER_DIR_SECRETS, SIGNER_DIR_SECRETS_ENV,
+        SIGNER_KEYS, SIGNER_KEYS_ENV, SIGNER_SERVER_ENV,
     },
     loader::SignerLoader,
-    utils::random_jwt,
+    utils::{random_jwt, ENV_ROLLING_DURATION},
 };
 use docker_compose_types::{
     Compose, ComposeVolume, DependsOnOptions, Environment, Labels, LoggingParameters, MapOrEmpty,
@@ -27,6 +27,8 @@ pub(super) const PROMETHEUS_DATA_VOLUME: &str = "prometheus-data";
 const METRICS_NETWORK: &str = "monitoring_network";
 const SIGNER_NETWORK: &str = "signer_network";
 
+const ENV_RUST_LOG: &str = "RUST_LOG";
+
 /// Builds the docker compose file for the Commit-Boost services
 
 // TODO: do more validation for paths, images, etc
@@ -41,11 +43,17 @@ pub fn handle_docker_init(config_path: String, output_dir: String) -> Result<()>
 
     // config volume to pass to all services
     let config_volume = Volumes::Simple(format!("./{}:{}:ro", config_path, CB_CONFIG_NAME));
+    let log_volume = Volumes::Simple(format!(
+        "{}:{}",
+        cb_config.logs.host_path.to_str().unwrap(),
+        CB_BASE_LOG_PATH
+    ));
 
     let mut jwts = IndexMap::new();
     // envs to write in .env file
     let mut envs = IndexMap::from([(CB_CONFIG_ENV.into(), CB_CONFIG_NAME.into())]);
-
+    envs.insert(ENV_ROLLING_DURATION.into(), cb_config.logs.duration.to_string());
+    envs.insert(ENV_RUST_LOG.into(), cb_config.logs.rust_log);
     // targets to pass to prometheus
     let mut targets = Vec::new();
     let metrics_port = 10000;
@@ -109,7 +117,7 @@ pub fn handle_docker_init(config_path: String, output_dir: String) -> Result<()>
                             METRICS_NETWORK.to_owned(),
                             SIGNER_NETWORK.to_owned(),
                         ]),
-                        volumes: vec![config_volume.clone()],
+                        volumes: vec![config_volume.clone(), log_volume.clone()],
                         environment: Environment::KvPair(module_envs),
                         depends_on: DependsOnOptions::Simple(vec!["cb_signer".to_owned()]),
                         ..Service::default()
@@ -131,7 +139,7 @@ pub fn handle_docker_init(config_path: String, output_dir: String) -> Result<()>
                         container_name: Some(module_cid.clone()),
                         image: Some(module.docker_image),
                         networks: Networks::Simple(vec![METRICS_NETWORK.to_owned()]),
-                        volumes: vec![config_volume.clone()],
+                        volumes: vec![config_volume.clone(), log_volume.clone()],
                         environment: Environment::KvPair(module_envs),
                         depends_on: DependsOnOptions::Simple(vec!["cb_pbs".to_owned()]),
                         ..Service::default()
@@ -157,7 +165,7 @@ pub fn handle_docker_init(config_path: String, output_dir: String) -> Result<()>
             cb_config.pbs.pbs_config.port, cb_config.pbs.pbs_config.port
         )]),
         networks: Networks::Simple(vec![METRICS_NETWORK.to_owned()]),
-        volumes: vec![config_volume.clone()],
+        volumes: vec![config_volume.clone(), log_volume.clone()],
         environment: Environment::KvPair(pbs_envs),
         ..Service::default()
     };
@@ -170,7 +178,7 @@ pub fn handle_docker_init(config_path: String, output_dir: String) -> Result<()>
 
     if let Some(signer_config) = cb_config.signer {
         if needs_signer_module {
-            let mut volumes = vec![config_volume.clone()];
+            let mut volumes = vec![config_volume.clone(), log_volume.clone()];
 
             targets.push(PrometheusTargetConfig {
                 targets: vec![format!("cb_signer:{metrics_port}")],
@@ -288,7 +296,14 @@ pub fn handle_docker_init(config_path: String, output_dir: String) -> Result<()>
             networks: Networks::Simple(vec![METRICS_NETWORK.to_owned()]),
             depends_on: DependsOnOptions::Simple(vec!["cb_prometheus".to_owned()]),
             environment: Environment::List(vec!["GF_SECURITY_ADMIN_PASSWORD=admin".to_owned()]),
-            volumes: vec![Volumes::Simple("./grafana/dashboards:/etc/grafana/provisioning/dashboards".to_owned()), Volumes::Simple("./grafana/datasources:/etc/grafana/provisioning/datasources".to_owned())],
+            volumes: vec![
+                Volumes::Simple(
+                    "./grafana/dashboards:/etc/grafana/provisioning/dashboards".to_owned(),
+                ),
+                Volumes::Simple(
+                    "./grafana/datasources:/etc/grafana/provisioning/datasources".to_owned(),
+                ),
+            ],
             // TODO: re-enable logging here once we move away from docker logs
             logging: Some(LoggingParameters { driver: Some("none".to_owned()), options: None }),
             ..Service::default()

crates/common/Cargo.toml

@@ -28,6 +28,7 @@ serde_json.workspace = true
 # telemetry
 tracing.workspace = true
 tracing-subscriber.workspace = true
+tracing-appender.workspace = true
 
 # crypto
 blst.workspace = true

crates/common/src/config/constants.rs

@@ -4,6 +4,8 @@ pub const METRICS_SERVER_ENV: &str = "METRICS_SERVER";
 pub const SIGNER_SERVER_ENV: &str = "SIGNER_SERVER";
 pub const BUILDER_SERVER_ENV: &str = "BUILDER_SERVER";
 
+pub const CB_BASE_LOG_PATH: &str = "/var/logs/commit-boost";
+
 pub const CB_CONFIG_ENV: &str = "CB_CONFIG";
 pub const CB_CONFIG_NAME: &str = "/cb-config.toml";
 

crates/common/src/config/log.rs

@@ -0,0 +1,52 @@
+use std::{
+    fmt::{Display, Formatter},
+    path::PathBuf,
+};
+
+use serde::{Deserialize, Serialize};
+
+#[derive(Clone, Debug, Deserialize, Serialize)]
+pub struct LogsSettings {
+    #[serde(default)]
+    pub duration: RollingDuration,
+    #[serde(default, rename = "host-path")]
+    pub host_path: PathBuf,
+    #[serde(default, rename = "rust-log")]
+    pub rust_log: String,
+}
+
+impl Default for LogsSettings {
+    fn default() -> Self {
+        Self {
+            duration: RollingDuration::Hourly,
+            host_path: "/var/log/pbs".into(),
+            rust_log: "info".to_string(),
+        }
+    }
+}
+
+#[derive(Clone, Debug, Deserialize, Serialize)]
+#[serde(rename_all = "lowercase")]
+pub enum RollingDuration {
+    Minutely,
+    Hourly,
+    Daily,
+    Never,
+}
+
+impl Display for RollingDuration {
+    fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
+        match self {
+            RollingDuration::Minutely => write!(f, "minutely"),
+            RollingDuration::Hourly => write!(f, "hourly"),
+            RollingDuration::Daily => write!(f, "daily"),
+            RollingDuration::Never => write!(f, "never"),
+        }
+    }
+}
+
+impl Default for RollingDuration {
+    fn default() -> Self {
+        Self::Daily
+    }
+}

crates/common/src/config/mod.rs

@@ -10,7 +10,10 @@ mod pbs;
 mod signer;
 mod utils;
 
+mod log;
+
 pub use constants::*;
+pub use log::*;
 pub use metrics::*;
 pub use module::*;
 pub use pbs::*;
@@ -26,6 +29,8 @@ pub struct CommitBoostConfig {
     pub modules: Option<Vec<StaticModuleConfig>>,
     pub signer: Option<SignerConfig>,
     pub metrics: MetricsConfig,
+    #[serde(default)]
+    pub logs: LogsSettings,
 }
 
 impl CommitBoostConfig {

crates/common/src/lib.rs

@@ -5,6 +5,7 @@ pub mod config;
 pub mod constants;
 pub mod error;
 pub mod loader;
+pub mod module_names;
 pub mod pbs;
 pub mod signature;
 pub mod signer;

crates/common/src/module_names.rs

@@ -0,0 +1,2 @@
+pub const PBS_MODULE_NAME: &str = "pbs";
+pub const SIGNER_MODULE_NAME: &str = "signer";

crates/common/src/utils.rs

@@ -1,4 +1,8 @@
-use std::time::{SystemTime, UNIX_EPOCH};
+use std::{
+    env,
+    str::FromStr,
+    time::{SystemTime, UNIX_EPOCH},
+};
 
 use alloy::{
     primitives::U256,
@@ -7,13 +11,16 @@ use alloy::{
 use blst::min_pk::{PublicKey, Signature};
 use rand::{distributions::Alphanumeric, Rng};
 use reqwest::header::HeaderMap;
-use tracing_subscriber::{fmt, layer::SubscriberExt, util::SubscriberInitExt, EnvFilter};
+use tracing_appender::non_blocking::WorkerGuard;
+use tracing_subscriber::{fmt::Layer, prelude::*, EnvFilter};
 
-use crate::types::Chain;
+use crate::{config::CB_BASE_LOG_PATH, types::Chain};
 
 const SECONDS_PER_SLOT: u64 = 12;
 const MILLIS_PER_SECOND: u64 = 1_000;
 
+pub const ENV_ROLLING_DURATION: &str = "ROLLING_DURATION";
+
 pub fn timestamp_of_slot_start_millis(slot: u64, chain: Chain) -> u64 {
     let seconds_since_genesis = chain.genesis_time_sec() + slot * SECONDS_PER_SLOT;
     seconds_since_genesis * MILLIS_PER_SECOND
@@ -110,9 +117,17 @@ pub const fn default_u256() -> U256 {
 }
 
 // LOGGING
-// TODO: more customized logging + logging guard
-pub fn initialize_tracing_log() {
+pub fn initialize_tracing_log(module_id: &str) -> WorkerGuard {
     let level_env = std::env::var("RUST_LOG").unwrap_or("info".to_owned());
+    // Log all events to a rolling log file.
+
+    let log_file = match env::var(ENV_ROLLING_DURATION).unwrap_or("daily".into()).as_str() {
+        "minutely" => tracing_appender::rolling::minutely(CB_BASE_LOG_PATH, module_id),
+        "hourly" => tracing_appender::rolling::hourly(CB_BASE_LOG_PATH, module_id),
+        "daily" => tracing_appender::rolling::daily(CB_BASE_LOG_PATH, module_id),
+        "never" => tracing_appender::rolling::never(CB_BASE_LOG_PATH, module_id),
+        _ => panic!("unknown rolling duration value"),
+    };
 
     let filter = match level_env.parse::<EnvFilter>() {
         Ok(f) => f,
@@ -121,12 +136,19 @@ pub fn initialize_tracing_log() {
             EnvFilter::new("info")
         }
     };
+    let logging_level = if matches!(level_env.as_str(), "info" | "warning" | "error") {
+        tracing::Level::DEBUG
+    } else {
+        tracing::Level::from_str(&level_env)
+            .unwrap_or_else(|_| panic!("invalid value for tracing. Got {level_env}"))
+    };
+    let stdout_log = tracing_subscriber::fmt::layer().pretty();
+    let (default, guard) = tracing_appender::non_blocking(log_file);
+    let log_file = Layer::new().with_writer(default.with_max_level(logging_level));
+
+    tracing_subscriber::registry().with(stdout_log.with_filter(filter).and_then(log_file)).init();
 
-    tracing_subscriber::registry()
-        .with(filter)
-        .with(fmt::layer().with_target(false))
-        .try_init()
-        .unwrap();
+    guard
 }
 
 pub fn print_logo() {

crates/pbs/src/mev_boost/get_header.rs

@@ -47,7 +47,7 @@ pub async fn get_header<S: BuilderApiState>(
             "late in slot, skipping relay requests"
         );
 
-        return Ok(None)
+        return Ok(None);
     }
 
     let (_, slot_uuid) = state.get_slot_and_uuid();
@@ -168,15 +168,15 @@ async fn send_timed_get_header(
                 .max_by_key(|(start_time, _)| *start_time)
             {
                 debug!(n_headers, "TG: received headers from relay");
-                return Ok(maybe_header)
+                return Ok(maybe_header);
             } else {
                 // all requests failed
                 warn!("TG: no headers received");
 
                 return Err(PbsError::RelayResponse {
                     error_msg: "no headers received".to_string(),
                     code: TIMEOUT_ERROR_CODE,
-                })
+                });
             }
         }
     }
@@ -255,7 +255,7 @@ async fn send_one_get_header(
             response = ?response_bytes,
             "no header from relay"
         );
-        return Ok((start_request_time, None))
+        return Ok((start_request_time, None));
     }
 
     let get_header_response: GetHeaderReponse = serde_json::from_slice(&response_bytes)?;
@@ -293,7 +293,7 @@ fn validate_header(
     let value = signed_header.message.value();
 
     if block_hash == B256::ZERO {
-        return Err(ValidationError::EmptyBlockhash)
+        return Err(ValidationError::EmptyBlockhash);
     }
 
     if parent_hash != signed_header.message.header.parent_hash {
@@ -315,7 +315,7 @@ fn validate_header(
         return Err(ValidationError::PubkeyMismatch {
             expected: expected_relay_pubkey,
             got: received_relay_pubkey,
-        })
+        });
     }
 
     if !skip_sig_verify {