Radish alpha
r
rad:zwTxygwuz5LDGBq255RA2CbNGrz8
Radicle CI broker
Radicle
Git
feat: allow user to set minimum log level for cib
Merged liw opened 1 year ago

Signed-off-by: Lars Wirzenius liw@liw.fi

3 files changed +151 -11 5b5ba29e 85efaa10
modified ci-broker.md
@@ -512,6 +512,31 @@ when I run bash radenv.sh cib --config broker.yaml queued
then stderr contains "Mordor"
~~~

+
## Allows setting minimum log level
+

+
_What:_ The node admin should be able to set the minimum log level for
+
log messages that get output to stderr.
+

+
_Why:_ This allows controlling how much log spew log admins have to see.
+

+
_Who:_ `node-ops`
+

+
~~~scenario
+
given file radenv.sh
+
given file setup-node.sh
+
when I run bash radenv.sh bash setup-node.sh
+

+
given an installed cib
+
given file broker.yaml
+
given a directory reports
+

+
when I run bash radenv.sh cib --config broker.yaml config
+
then stderr contains "CI broker starts"
+

+
when I run bash radenv.sh cib --config broker.yaml --log-level error config
+
then stderr is exactly ""
+
~~~
+

# Acceptance criteria for test tooling

The event synthesizer is a helper to feed the CI broker node events in
modified src/bin/cib.rs
@@ -17,7 +17,7 @@ use radicle_ci_broker::{
    broker::{Broker, BrokerError},
    config::{Config, ConfigError},
    db::{Db, DbError},
-
    logger,
+
    logger::{self, LogLevel},
    notif::{NotificationChannel, NotificationError},
    pages::StatusPage,
    queueadd::{AdderError, QueueAdderBuilder},
@@ -25,10 +25,9 @@ use radicle_ci_broker::{
};

fn main() {
-
    let _logger = logger::open();
+
    let logger = logger::open();

-
    logger::start_cib();
-
    if let Err(e) = fallible_main() {
+
    if let Err(e) = fallible_main(&logger) {
        logger::error("ERROR", &e);
        logger::end_cib_in_error();
        exit(1);
@@ -36,8 +35,13 @@ fn main() {
    logger::end_cib_successfully();
}

-
fn fallible_main() -> Result<(), CibError> {
+
fn fallible_main(logger: &logger::Logger) -> Result<(), CibError> {
    let args = Args::parse();
+
    logger.set_minimum_level(args.minimum_log_level());
+

+
    // We only log this after setting the minimum log level from the
+
    // command line.
+
    logger::start_cib();

    let config = Config::load(&args.config).map_err(|e| CibError::read_config(&args.config, e))?;
    logger::loaded_config(&config);
@@ -53,6 +57,9 @@ struct Args {
    #[clap(long)]
    config: PathBuf,

+
    #[clap(long, value_enum)]
+
    log_level: Option<logger::LogLevel>,
+

    #[clap(subcommand)]
    cmd: Cmd,
}
@@ -77,6 +84,10 @@ impl Args {
            Err(CibError::UnprocessedBrokerEvents)
        }
    }
+

+
    fn minimum_log_level(&self) -> LogLevel {
+
        self.log_level.unwrap_or(LogLevel::Trace)
+
    }
}

#[derive(Debug, Parser)]
modified src/logger.rs
@@ -2,8 +2,14 @@

#[cfg(test)]
use std::sync::Once;
-
use std::{path::Path, sync::Mutex, time::Duration};
+
use std::{
+
    fmt,
+
    path::Path,
+
    sync::{Arc, Mutex},
+
    time::Duration,
+
};

+
use clap::ValueEnum;
use radicle::{git::raw::Oid, identity::RepoId, node::Event};
use slog::{debug, error, info, o, trace, warn, Drain};
use slog_scope::GlobalLoggerGuard;
@@ -18,14 +24,73 @@ use crate::{
    run::Run,
};

-
pub fn open() -> GlobalLoggerGuard {
-
    let logger = slog_json::Json::new(std::io::stderr())
+
// We define our own type for log levels so that we can apply
+
// clap::ValueEnum on it.
+
#[derive(ValueEnum, Eq, PartialEq, Copy, Clone, Debug)]
+
pub enum LogLevel {
+
    Trace,
+
    Debug,
+
    Info,
+
    Warning,
+
    Error,
+
    Critical,
+
}
+

+
impl fmt::Display for LogLevel {
+
    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
+
        write!(f, "<{:?}>", self)
+
    }
+
}
+

+
impl From<LogLevel> for slog::Level {
+
    fn from(log_level: LogLevel) -> Self {
+
        match log_level {
+
            LogLevel::Trace => slog::Level::Trace,
+
            LogLevel::Debug => slog::Level::Debug,
+
            LogLevel::Info => slog::Level::Info,
+
            LogLevel::Warning => slog::Level::Warning,
+
            LogLevel::Error => slog::Level::Error,
+
            LogLevel::Critical => slog::Level::Critical,
+
        }
+
    }
+
}
+

+
pub struct Logger {
+
    minimum_log_level: Arc<Mutex<slog::Level>>,
+

+
    // We need to keep this for as long as need to log. But we don't
+
    // refer to it directly.
+
    #[allow(dead_code)]
+
    guard: GlobalLoggerGuard,
+
}
+

+
impl Logger {
+
    pub fn set_minimum_level(&self, level: LogLevel) {
+
        *self
+
            .minimum_log_level
+
            .lock()
+
            .expect("set minimum log level") = level.into();
+
    }
+
}
+

+
pub fn open() -> Logger {
+
    let underlying_logger = slog_json::Json::new(std::io::stderr())
        .add_default_keys()
        .set_flush(true)
        .set_newlines(true)
        .build();
-
    let log = slog::Logger::root(Mutex::new(logger).fuse(), o!());
-
    slog_scope::set_global_logger(log)
+

+
    // Set the default log level. Trace is good for tests.
+
    let level = Arc::new(Mutex::new(LogLevel::Trace.into()));
+

+
    let filter = LogLevelFilter::new(underlying_logger, level.clone());
+
    let log = slog::Logger::root(Mutex::new(filter).fuse(), o!());
+
    let guard = slog_scope::set_global_logger(log);
+

+
    Logger {
+
        guard,
+
        minimum_log_level: level,
+
    }
}

// Set up structured logging for tests.
@@ -47,7 +112,46 @@ static INIT: Once = Once::new();

// This is the actual logger for tests.
#[cfg(test)]
-
static mut LOGGER: Option<GlobalLoggerGuard> = None;
+
static mut LOGGER: Option<Logger> = None;
+

+
struct LogLevelFilter<D> {
+
    drain: D,
+
    minimum_log_level: Arc<Mutex<slog::Level>>,
+
}
+

+
impl<D> LogLevelFilter<D> {
+
    pub fn new(drain: D, minimum_log_level: Arc<Mutex<slog::Level>>) -> Self {
+
        Self {
+
            drain,
+
            minimum_log_level,
+
        }
+
    }
+
}
+

+
impl<D> Drain for LogLevelFilter<D>
+
where
+
    D: Drain,
+
{
+
    type Ok = Option<D::Ok>;
+
    type Err = Option<D::Err>;
+

+
    fn log(
+
        &self,
+
        record: &slog::Record,
+
        values: &slog::OwnedKVList,
+
    ) -> Result<Self::Ok, Self::Err> {
+
        #[allow(clippy::unwrap_used)] // We have no good way to report an error
+
        let min = *self
+
            .minimum_log_level
+
            .lock()
+
            .expect("lock log level filter minimum level");
+
        if record.level().is_at_least(min) {
+
            self.drain.log(record, values).map(Some).map_err(Some)
+
        } else {
+
            Ok(None)
+
        }
+
    }
+
}

#[cfg(test)]
#[ctor::ctor]