acme_proxy_server/

logging.rs

//! `[logging]` — resolving the configuration into an installed subscriber, and
//! swapping it on a reload.
//!
//! The rule the whole module follows: **every knob is validated before anything
//! is installed, and an unknown value is an error the caller prints and exits
//! on rather than a silent fallback.** A certificate authority running at a log
//! level or to a destination its operator did not ask for is worse than one
//! that refuses to start and says why.
//!
//! Which invocation gets a subscriber at all, and the `--log-level` flag whose
//! directive outranks `RUST_LOG` and `logging.filter`, are the CLI's
//! (`cli::logging`); this module takes that directive as a string and records
//! which of the three layers won in [`FilterSource`], so a reload can say.
//!
//! # Reloading
//!
//! All six keys reload on `SIGHUP`, which is why the whole stack is built as one
//! [`Installed`] layer behind a [`tracing_subscriber::reload::Layer`] rather
//! than through the `tracing_subscriber::fmt()` builder. Three things that shape
//! rests on, each a bug if reversed:
//!
//! - **The filter is composed with [`Layer::and_then`], never `with_filter`.**
//!   `reload::Handle::reload` is documented as unusable with a
//!   [`tracing_subscriber::filter::Filtered`] layer (tokio-rs/tracing#1629),
//!   because replacing it mints a filter id the registry never saw. `and_then`
//!   is global filtering — `Layered::enabled` is the conjunction of both halves
//!   — which is exactly the semantics `with_env_filter` gave before.
//! - **One boxed layer, not two.** `Box<dyn Layer<S>>` has to name its `S`, and
//!   a second `.with()` makes the next layer's `S` the `Layered<…>` of the
//!   first — a type nothing can write down in a `static`. One box is also one
//!   lock rather than two.
//! - **The handle lives in a process-wide [`OnceLock`], beside the global it is
//!   a handle to.** The subscriber already is process-global (`.init()` panics
//!   on a second call); this is not a second one. Threading the handle from
//!   `main.rs` to `server::generation::publish_reload` instead would touch six
//!   signatures, including the `serve_on*` seams every test enters through.
//!   When it is unset — a test binary, or a consumer that installed its own
//!   subscriber — [`publish_logging`] is a **no-op that says so**, since
//!   logging is then not ours to swap.
//!
//! The cost, stated rather than buried: a `reload::Layer` puts an `RwLock` read
//! on every event.

use std::sync::OnceLock;

use tracing_subscriber::fmt::format::FmtSpan;
use tracing_subscriber::fmt::writer::BoxMakeWriter;
use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::util::SubscriberInitExt;
use tracing_subscriber::{EnvFilter, Layer, Registry, reload};

/// The layer stack as one value, so a reload can replace all of it at once.
///
/// Boxed against `Registry` specifically: that is the base subscriber both
/// [`init_logging`] and every swap build on.
type Installed = Box<dyn Layer<Registry> + Send + Sync>;

/// The handle to the installed stack, or unset when this process installed no
/// subscriber of its own. See the reloading notes in the module doc.
static RELOAD: OnceLock<reload::Handle<Installed, Registry>> = OnceLock::new();

/// The `--log-level` directive this process was started with, or unset when the
/// flag was not given.
///
/// Beside [`RELOAD`] and for its reason, stated in the module doc: a reload
/// rebuilds the stack from the *file*, so without somewhere process-wide to
/// read the flag back from, `SIGHUP` would silently drop it — and threading it
/// down instead would touch the same six signatures, `serve_on*` included.
/// Written once, after the value has been validated by building a filter from
/// it, so a refused startup leaves nothing behind.
static FILTER_OVERRIDE: OnceLock<String> = OnceLock::new();

/// The `--log-level` directive to apply, or `None` when the flag was not given.
///
/// The one accessor for [`FILTER_OVERRIDE`], so a reload re-reads what startup
/// was told rather than each caller reaching for the cell.
pub(crate) fn flag_override() -> Option<&'static str> {
    FILTER_OVERRIDE.get().map(String::as_str)
}

/// Which of the three layers supplied the filter in force.
///
/// The provenance travels with the filter because it decides whether an
/// operator is owed a warning: with either of the two outranking layers in
/// play, editing `logging.filter` and reloading changes nothing at all, and a
/// silent no-op is the one outcome worth a line in the log. It is also the
/// `source` field on that warning, so the operator is told *which* to unset.
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
pub(crate) enum FilterSource {
    /// `--log-level`, typed on this command line.
    Flag,
    /// `RUST_LOG`, from the environment.
    Env,
    /// `logging.filter`, from the configuration file.
    Config,
}

impl FilterSource {
    /// The `source` field's value on `server_logging_filter_overridden`.
    pub(crate) fn as_str(self) -> &'static str {
        match self {
            Self::Flag => "flag",
            Self::Env => "env",
            Self::Config => "config",
        }
    }

    /// Whether `logging.filter` was overruled, i.e. whether editing it and
    /// reloading would change nothing.
    pub(crate) fn outranks_config(self) -> bool {
        !matches!(self, Self::Config)
    }
}

/// The tracing filter, and where it came from.
#[derive(Debug)]
struct ResolvedFilter {
    filter: EnvFilter,
    source: FilterSource,
}

/// Builds the tracing filter: `flag` if given, else `RUST_LOG` if set and
/// valid, else `logging.filter`.
///
/// Returns an error rather than unwrapping. `logging.filter` is
/// operator-supplied and environment-overridable, so a typo in it used to
/// panic the process with a backtrace — four lines after a configuration error
/// was handled cleanly with a message and an exit code. Exiting rather than
/// silently falling back to a default is the deliberate half: a certificate
/// authority quietly running at a different log level than its operator asked
/// for is worse than one that refuses to start and says why.
///
/// `flag` outranks `RUST_LOG` for `cli::style`'s reason: it was typed on
/// this command line, where the environment is ambient. It is a `LogLevel`
/// rendering rather than operator text, so it cannot fail to parse — but it
/// goes through the same `try_new` as the other two rather than being trusted,
/// since a value that cannot fail is one nobody notices becoming able to.
///
/// The precedence is the same on a reload as at startup, and deliberately: the
/// two disagreeing about what the server is running would be worse than the
/// override itself.
fn build_env_filter(
    logging: &acme_proxy_core::config::LoggingConfig,
    flag: Option<&str>,
) -> Result<ResolvedFilter, String> {
    if let Some(directive) = flag {
        return EnvFilter::try_new(directive)
            .map(|filter| ResolvedFilter {
                filter,
                source: FilterSource::Flag,
            })
            .map_err(|error| {
                format!("--log-level `{directive}` is not a valid tracing filter: {error}")
            });
    }
    if let Ok(filter) = EnvFilter::try_from_default_env() {
        return Ok(ResolvedFilter {
            filter,
            source: FilterSource::Env,
        });
    }
    EnvFilter::try_new(&logging.filter)
        .map(|filter| ResolvedFilter {
            filter,
            source: FilterSource::Config,
        })
        .map_err(|error| {
            format!(
                "configuration error: logging.filter `{}` is not a valid tracing filter: {error}",
                logging.filter
            )
        })
}

/// Resolves `logging.target` to the writer records are sent to.
///
/// Boxed so both values leave this function as one type — the two `fmt`
/// builder chains below are already split by `json_format`, and splitting them
/// again by writer would be four arms saying the same thing.
fn parse_target(target: &str) -> Result<BoxMakeWriter, String> {
    match target {
        "stdout" => Ok(BoxMakeWriter::new(std::io::stdout)),
        "stderr" => Ok(BoxMakeWriter::new(std::io::stderr)),
        other => Err(format!(
            "configuration error: logging.target `{other}` is not a known target (stdout, stderr)"
        )),
    }
}

/// Resolves `logging.span_events` to the span lifecycle records emitted.
///
/// `close` is the one worth reaching for: it emits a record as each span ends,
/// carrying the time spent busy and idle inside it — per-request timing without
/// a metrics endpoint. `full` adds `new`/`enter`/`exit` and is a debugging tool,
/// not something to run a server on.
fn parse_span_events(span_events: &str) -> Result<FmtSpan, String> {
    match span_events {
        "none" => Ok(FmtSpan::NONE),
        "close" => Ok(FmtSpan::CLOSE),
        "full" => Ok(FmtSpan::FULL),
        other => Err(format!(
            "configuration error: logging.span_events `{other}` is not a known value (none, close, full)"
        )),
    }
}

/// Whether to colour the human-readable format: `logging.ansi`, with `NO_COLOR`
/// able to veto it.
///
/// `tracing-subscriber` honours `NO_COLOR` in its own default, and calling
/// `with_ansi` at all replaces that default outright — so configuring this key
/// naively would have silently broken the convention for every operator who
/// relies on it. Either switch turns colour off; neither can turn it on against
/// the other.
///
/// Per the convention, `NO_COLOR` counts only when set to a non-empty value —
/// which is [`no_color_set`](acme_proxy_core::palette::no_color_set)'s judgement, shared with the admin
/// CLI's own `--color` so the two answers cannot drift. Note the *precedence*
/// deliberately does not match: a `--color always` outranks `NO_COLOR` where
/// this key cannot, because a flag is typed and a configuration file is
/// ambient. `cli::style`'s module doc has the argument.
fn ansi_enabled(configured: bool, no_color: Option<&str>) -> bool {
    configured && !acme_proxy_core::palette::no_color_set(no_color)
}

/// A layer stack built from `[logging]` but not yet installed.
///
/// The build/publish split is [`crate::Assembly::build_parts`] and
/// `publish_notifiers`', for the same reason: a reload must be able to fail
/// *after* building this and still leave the running configuration untouched.
pub(crate) struct PreparedLogging {
    layer: Installed,
    /// Which of the three layers the filter came from, and so whether
    /// `logging.filter` had any say.
    pub(crate) filter_source: FilterSource,
}

/// Resolves `[logging]` into a layer stack, validating every key.
///
/// The one place a stack is built, so startup and a reload cannot drift — the
/// reasoning behind [`crate::generation::build_generation`], applied
/// to one layer.
pub(crate) fn prepare_logging(
    logging: &acme_proxy_core::config::LoggingConfig,
    flag: Option<&str>,
) -> Result<PreparedLogging, String> {
    let ResolvedFilter { filter, source } = build_env_filter(logging, flag)?;
    let writer = parse_target(&logging.target)?;
    let span_events = parse_span_events(&logging.span_events)?;
    let ansi = ansi_enabled(logging.ansi, std::env::var("NO_COLOR").ok().as_deref());

    // The two arms are separate because `.json()` changes the layer's type, not
    // because they differ in what they configure.
    //
    // **`format.and_then(filter)`, never the other way round.** `and_then`
    // makes its argument the *outer* layer, and `Layered::max_level_hint`
    // directly over a `Registry` returns the outer hint alone — so composing
    // them the readable way round hands the format layer's `None` to
    // `LevelFilter::current()`, which then sits at `TRACE` for the life of the
    // process. Every record would still be filtered correctly by `enabled`, so
    // nothing would look wrong; the cost is that `tracing`'s static
    // short-circuit stops working and every disabled callsite in the tree pays
    // a subscriber call.
    let layer: Installed = if logging.json_format {
        tracing_subscriber::fmt::layer()
            .json()
            .flatten_event(logging.flatten_event)
            .with_span_events(span_events)
            .with_writer(writer)
            .and_then(filter)
            .boxed()
    } else {
        tracing_subscriber::fmt::layer()
            .with_ansi(ansi)
            .with_span_events(span_events)
            .with_writer(writer)
            .and_then(filter)
            .boxed()
    };

    Ok(PreparedLogging {
        layer,
        filter_source: source,
    })
}

/// Makes `prepared` the stack every later record goes through, reporting
/// whether it took.
///
/// `false` means this process installed no subscriber of its own, so there is
/// no handle and nothing was swapped — see the module doc. Synchronous, which
/// is what lets it sit inside `server::generation::publish_reload`'s publishing
/// run beside the `watch` sends.
pub(crate) fn publish_logging(prepared: PreparedLogging) -> bool {
    RELOAD
        .get()
        .is_some_and(|handle| handle.reload(prepared.layer).is_ok())
}

/// Installs the process-wide tracing subscriber from `[logging]`.
///
/// Every knob is validated before anything is installed, and an unknown value
/// is an error the caller prints and exits on rather than a silent fallback —
/// the same reasoning as [`build_env_filter`]: a certificate authority running
/// at a log level or to a destination its operator did not ask for is worse
/// than one that refuses to start and says why.
pub fn init_logging(
    logging: &acme_proxy_core::config::LoggingConfig,
    directive: Option<String>,
) -> Result<(), String> {
    let prepared = prepare_logging(logging, directive.as_deref())?;
    let (layer, handle) = reload::Layer::new(prepared.layer);
    tracing_subscriber::registry().with(layer).init();
    // A second install would already have panicked in `init()` above, so the
    // only way this loses the race is a caller that never got that far.
    let _ = RELOAD.set(handle);
    // Stored only now: a directive that would not build must leave the cell
    // unset, or a refused startup would hand a reload a filter nothing ever
    // installed.
    if let Some(directive) = directive {
        let _ = FILTER_OVERRIDE.set(directive);
    }
    Ok(())
}

/// The stack a one-shot admin command logs through, when it logs at all.
///
/// **`stderr`, whatever `logging.target` says**, and `logging.filter` is not
/// consulted either: that section describes the *server's* log stream, while
/// this is a diagnostic an operator asked one command for. stdout is the answer
/// — the rows, or the `--json` document — and putting a record in it is what
/// this whole path exists to stop.
///
/// Human-readable rather than `logging.json_format`'s shape for the same
/// reason: the audience is the terminal the command was typed into. `NO_COLOR`
/// still vetoes the colour, through the shared [`ansi_enabled`].
fn command_logging_config() -> acme_proxy_core::config::LoggingConfig {
    acme_proxy_core::config::LoggingConfig {
        target: "stderr".to_string(),
        // The compiled default, deliberately, and not the operator's own
        // `logging.filter`. It is reached only when `--log-level` was not
        // given, i.e. when a non-empty `RUST_LOG` is what asked — and that
        // outranks it, so this is a fallback nothing normally reads.
        ..acme_proxy_core::config::LoggingConfig::default()
    }
}

/// Installs the diagnostic subscriber a one-shot admin command asked for.
///
/// `directive` is `None` when a non-empty `RUST_LOG` is what asked, in which case
/// it supplies the filter through [`build_env_filter`]'s second layer — see
/// `cli::plan_logging`, which is what decides this function is called at all.
pub fn init_command_logging(directive: Option<String>) -> Result<(), String> {
    init_logging(&command_logging_config(), directive)
}

#[cfg(test)]
mod tests {
    use super::*;
    use tracing::level_filters::LevelFilter;

    /// A malformed `logging.filter` is an error a caller can print, not a
    /// panic. It is operator-supplied and environment-overridable, so a typo
    /// used to take the process down with a backtrace — four lines after a
    /// configuration error was handled cleanly.
    #[test]
    fn a_malformed_logging_filter_is_reported_rather_than_panicking() {
        // `RUST_LOG` outranks `logging.filter`, so a developer with one set in
        // their shell would otherwise see this pass on an answer that never
        // looked at the malformed value.
        let _guard = acme_proxy_core::config::ENV_LOCK
            .lock()
            .unwrap_or_else(std::sync::PoisonError::into_inner);
        // SAFETY: the lock above makes this the only thread touching the
        // environment.
        unsafe { std::env::remove_var("RUST_LOG") };

        let logging = acme_proxy_core::config::LoggingConfig {
            filter: "this is not=a=valid=filter".to_string(),
            ..Default::default()
        };
        let error = build_env_filter(&logging, None).unwrap_err();
        assert!(error.contains("logging.filter"), "{error}");
        assert!(error.contains("this is not=a=valid=filter"), "{error}");
    }

    #[test]
    fn a_valid_logging_filter_builds() {
        let _guard = acme_proxy_core::config::ENV_LOCK
            .lock()
            .unwrap_or_else(|e| e.into_inner());
        unsafe { std::env::remove_var("RUST_LOG") };

        let logging = acme_proxy_core::config::LoggingConfig {
            filter: "acme_proxy=debug".to_string(),
            ..Default::default()
        };
        let resolved = build_env_filter(&logging, None).expect("a valid filter builds");
        assert_eq!(
            resolved.source,
            FilterSource::Config,
            "with RUST_LOG unset and no flag the filter comes from `logging.filter`",
        );
    }

    /// The provenance the reload path warns off: `RUST_LOG` wins, so an edited
    /// `logging.filter` would change nothing.
    #[test]
    fn rust_log_wins_and_says_so() {
        let _guard = acme_proxy_core::config::ENV_LOCK
            .lock()
            .unwrap_or_else(|e| e.into_inner());
        unsafe { std::env::set_var("RUST_LOG", "acme_proxy=warn") };

        let logging = acme_proxy_core::config::LoggingConfig {
            filter: "acme_proxy=trace".to_string(),
            ..Default::default()
        };
        let resolved = build_env_filter(&logging, None).expect("RUST_LOG parses");
        assert_eq!(resolved.source, FilterSource::Env);

        unsafe { std::env::remove_var("RUST_LOG") };
    }

    /// `NO_COLOR` must keep working: `tracing-subscriber` honours it in the
    /// default that `with_ansi` replaces, so configuring the key at all is what
    /// put the convention at risk.
    #[test]
    fn no_color_vetoes_ansi_and_an_empty_value_does_not() {
        assert!(ansi_enabled(true, None));
        assert!(!ansi_enabled(true, Some("1")));
        assert!(!ansi_enabled(true, Some("anything")));
        // The convention counts only a non-empty value.
        assert!(ansi_enabled(true, Some("")));
        // Configured off stays off however NO_COLOR is set.
        assert!(!ansi_enabled(false, None));
        assert!(!ansi_enabled(false, Some("1")));
    }

    #[test]
    fn both_logging_targets_resolve() {
        assert!(parse_target("stdout").is_ok());
        assert!(parse_target("stderr").is_ok());
    }

    /// A typo'd target must stop the process, not quietly pick one: an operator
    /// who asked for `stderr` and silently got `stdout` would look for the log
    /// in the wrong stream.
    #[test]
    fn an_unknown_logging_target_is_reported() {
        let error = parse_target("syslog").unwrap_err();
        assert!(error.contains("logging.target"), "{error}");
        assert!(error.contains("syslog"), "{error}");
        assert!(error.contains("stdout"), "{error}");
    }

    #[test]
    fn every_span_events_value_resolves() {
        assert_eq!(parse_span_events("none").unwrap(), FmtSpan::NONE);
        assert_eq!(parse_span_events("close").unwrap(), FmtSpan::CLOSE);
        assert_eq!(parse_span_events("full").unwrap(), FmtSpan::FULL);
    }

    #[test]
    fn an_unknown_span_events_value_is_reported() {
        let error = parse_span_events("enter").unwrap_err();
        assert!(error.contains("logging.span_events"), "{error}");
        assert!(error.contains("enter"), "{error}");
        assert!(error.contains("close"), "{error}");
    }

    /// `prepare_logging` validates everything before building anything, so each
    /// bad key is reported by name — which is what makes a reload carrying one
    /// a refusal with the message startup would have printed, rather than a
    /// half-swapped stack. `init_logging` funnels through it, so the failure
    /// path below covers both.
    #[test]
    fn prepare_logging_reports_each_bad_key_by_name() {
        for (logging, expected) in bad_key_cases() {
            let _guard = acme_proxy_core::config::ENV_LOCK
                .lock()
                .unwrap_or_else(|e| e.into_inner());
            unsafe { std::env::remove_var("RUST_LOG") };

            // Not `expect_err`: the `Ok` side holds a boxed `Layer`, which has
            // no `Debug` to print.
            let Err(error) = prepare_logging(&logging, None) else {
                panic!("`{expected}` must be refused, not built");
            };
            assert!(error.contains(expected), "{error}");
        }
    }

    /// Publishing with no subscriber installed is a documented no-op rather
    /// than a panic or a lie: this process never called `init_logging`, so
    /// logging is not ours to swap. The `false` is what
    /// `ReloadReport::logging_reloaded` carries, so an operator is told.
    #[test]
    fn publishing_without_an_installed_subscriber_is_a_no_op() {
        let _guard = acme_proxy_core::config::ENV_LOCK
            .lock()
            .unwrap_or_else(|e| e.into_inner());
        unsafe { std::env::remove_var("RUST_LOG") };

        let prepared = prepare_logging(&acme_proxy_core::config::LoggingConfig::default(), None)
            .expect("the defaults build");
        assert!(!publish_logging(prepared));
    }

    /// The swap really changes what is enabled, which is the whole feature.
    ///
    /// `LevelFilter::current()` is the static maximum `tracing` consults before
    /// it reaches any subscriber, so asserting it moved is what proves
    /// `Handle::reload` rebuilt the interest cache rather than merely storing a
    /// new layer nothing asks. Its own process, like the two installers below.
    #[test]
    fn a_reloaded_filter_changes_what_is_enabled() {
        let _guard = acme_proxy_core::config::ENV_LOCK
            .lock()
            .unwrap_or_else(|e| e.into_inner());
        unsafe { std::env::remove_var("RUST_LOG") };

        let at_info = acme_proxy_core::config::LoggingConfig {
            filter: "acme_proxy=info".to_string(),
            target: "stderr".to_string(),
            ..Default::default()
        };
        init_logging(&at_info, None).expect("the subscriber installs");
        assert_eq!(LevelFilter::current(), LevelFilter::INFO);
        assert!(!tracing::enabled!(target: "acme_proxy", tracing::Level::DEBUG));

        let at_debug = acme_proxy_core::config::LoggingConfig {
            filter: "acme_proxy=debug".to_string(),
            target: "stderr".to_string(),
            ..Default::default()
        };
        let prepared = prepare_logging(&at_debug, None).expect("the debug filter builds");
        assert!(publish_logging(prepared), "the handle is installed");

        assert_eq!(LevelFilter::current(), LevelFilter::DEBUG);
        assert!(tracing::enabled!(target: "acme_proxy", tracing::Level::DEBUG));
    }

    /// The other five keys change the stack's *shape*, which is why the whole
    /// layer is boxed behind one handle rather than only the filter being
    /// reloadable. Human-readable to JSON is the biggest such change there is.
    #[test]
    fn a_reloaded_format_swaps_the_whole_stack() {
        let _guard = acme_proxy_core::config::ENV_LOCK
            .lock()
            .unwrap_or_else(|e| e.into_inner());
        unsafe { std::env::remove_var("RUST_LOG") };

        init_logging(
            &acme_proxy_core::config::LoggingConfig {
                target: "stderr".to_string(),
                ansi: false,
                ..Default::default()
            },
            None,
        )
        .expect("the subscriber installs");

        let as_json = acme_proxy_core::config::LoggingConfig {
            json_format: true,
            flatten_event: true,
            target: "stderr".to_string(),
            span_events: "close".to_string(),
            ..Default::default()
        };
        let prepared = prepare_logging(&as_json, None).expect("the JSON stack builds");
        assert!(publish_logging(prepared));

        // The filter has to survive the shape change: `and_then` puts it on the
        // outside precisely so `Layered::max_level_hint` keeps reading it, and
        // building the JSON arm the readable way round would silently drop it
        // to `TRACE` here.
        assert_eq!(
            LevelFilter::current(),
            LevelFilter::INFO,
            "swapping the format must not lose the filter's level hint",
        );
    }

    /// The three keys whose value can be wrong, and the name each must be
    /// refused by. Shared so `init_logging` and `prepare_logging` cannot drift
    /// on which of them they check.
    fn bad_key_cases() -> Vec<(acme_proxy_core::config::LoggingConfig, &'static str)> {
        vec![
            (
                acme_proxy_core::config::LoggingConfig {
                    filter: "not=a=filter".to_string(),
                    ..Default::default()
                },
                "logging.filter",
            ),
            (
                acme_proxy_core::config::LoggingConfig {
                    target: "nowhere".to_string(),
                    ..Default::default()
                },
                "logging.target",
            ),
            (
                acme_proxy_core::config::LoggingConfig {
                    span_events: "sometimes".to_string(),
                    ..Default::default()
                },
                "logging.span_events",
            ),
        ]
    }

    /// `init_logging` validates everything before installing anything, so each
    /// bad key is reported by name. Only the failure path is driven here:
    /// installing a subscriber is process-wide and would leak into every other
    /// test in this binary.
    #[test]
    fn init_logging_reports_each_bad_key_by_name() {
        for (logging, expected) in bad_key_cases() {
            // `RUST_LOG` wins over `logging.filter`, so the filter case is only
            // reachable with it unset — which the crate-wide lock guarantees.
            let _guard = acme_proxy_core::config::ENV_LOCK
                .lock()
                .unwrap_or_else(|e| e.into_inner());
            unsafe { std::env::remove_var("RUST_LOG") };

            let error = init_logging(&logging, None).unwrap_err();
            assert!(error.contains(expected), "{error}");
        }
    }

    /// The two arms that actually install a subscriber, one per test.
    ///
    /// `init()` panics on a second call, so these would be untestable under
    /// plain `cargo test` — one process, every test a thread. nextest runs each
    /// test as its own process, which is what makes installing a *global*
    /// subscriber a thing a test can do at all. (The suite already requires
    /// nextest for an unrelated reason; see the Testing notes.)
    #[test]
    fn the_human_readable_subscriber_installs() {
        let logging = acme_proxy_core::config::LoggingConfig {
            target: "stderr".to_string(),
            ansi: false,
            span_events: "close".to_string(),
            ..Default::default()
        };
        assert!(init_logging(&logging, None).is_ok());
    }

    #[test]
    fn the_json_subscriber_installs() {
        let logging = acme_proxy_core::config::LoggingConfig {
            json_format: true,
            flatten_event: true,
            span_events: "full".to_string(),
            ..Default::default()
        };
        assert!(init_logging(&logging, None).is_ok());
    }

    /// A flag was typed on this command line where both other layers are
    /// ambient — `cli::style`'s argument for `--color always`
    /// outranking `NO_COLOR`, applied to the filter.
    #[test]
    fn the_flag_outranks_rust_log_and_the_file() {
        let _guard = acme_proxy_core::config::ENV_LOCK
            .lock()
            .unwrap_or_else(|e| e.into_inner());
        unsafe { std::env::set_var("RUST_LOG", "acme_proxy=warn") };

        let logging = acme_proxy_core::config::LoggingConfig {
            filter: "acme_proxy=error".to_string(),
            ..Default::default()
        };
        let resolved = build_env_filter(&logging, Some("acme_proxy=trace"))
            .expect("the flag's directive builds");
        assert_eq!(resolved.source, FilterSource::Flag);
        assert_eq!(
            resolved.filter.to_string(),
            "acme_proxy=trace",
            "neither RUST_LOG nor logging.filter may have a say once the flag is given",
        );

        unsafe { std::env::remove_var("RUST_LOG") };
    }

    /// stdout is the answer an admin command was run for — the rows, or the
    /// `--json` document — so a record asked for with `--log-level` goes to
    /// stderr whatever `logging.target` says. That key describes the server's
    /// stream, and this path deliberately does not consult it.
    #[test]
    fn a_command_run_logs_to_stderr_whatever_logging_target_says() {
        assert_eq!(
            acme_proxy_core::config::LoggingConfig::default().target,
            "stdout",
            "the default this must not inherit",
        );
        let built = command_logging_config();
        assert_eq!(built.target, "stderr");
        assert!(!built.json_format, "the audience is a terminal");
    }

    /// The three `FilterSource`s, and the question the reload warning asks of
    /// them. `config` is the only one that does *not* make an edited
    /// `logging.filter` a no-op.
    #[test]
    fn only_the_two_outranking_sources_silence_an_edit() {
        assert!(FilterSource::Flag.outranks_config());
        assert!(FilterSource::Env.outranks_config());
        assert!(!FilterSource::Config.outranks_config());
        assert_eq!(FilterSource::Flag.as_str(), "flag");
        assert_eq!(FilterSource::Env.as_str(), "env");
        assert_eq!(FilterSource::Config.as_str(), "config");
    }

    /// The flag's own directives cannot fail to parse — they are renderings of
    /// a closed enum — but the arm is built to refuse rather than to trust,
    /// since a value that cannot be wrong is one nobody notices becoming able
    /// to. Driven with a hand-written directive, which is the only way in.
    #[test]
    fn an_unparseable_flag_directive_is_refused_by_name() {
        let error = build_env_filter(
            &acme_proxy_core::config::LoggingConfig::default(),
            Some("not=a=filter"),
        )
        .unwrap_err();
        assert!(error.contains("--log-level"), "{error}");
        assert!(error.contains("not=a=filter"), "{error}");
    }

    /// The whole admin-command path, installed: the flag's level in force and
    /// the records on stderr. Its own process, like the three installers above.
    #[test]
    fn a_command_subscriber_installs_at_the_flags_level() {
        let _guard = acme_proxy_core::config::ENV_LOCK
            .lock()
            .unwrap_or_else(|e| e.into_inner());
        unsafe { std::env::remove_var("RUST_LOG") };

        init_command_logging(Some("acme_proxy=warn".to_string())).expect("the subscriber installs");
        assert_eq!(LevelFilter::current(), LevelFilter::WARN);
        assert!(!tracing::enabled!(target: "acme_proxy", tracing::Level::INFO));
        assert_eq!(flag_override(), Some("acme_proxy=warn"));
    }

    /// A `--log-level` typed at startup has to survive a `SIGHUP`: the stack is
    /// rebuilt from the *file*, so without the process-wide cell the reload
    /// would quietly demote the server to `logging.filter`. Its own process,
    /// like the three installers above — it installs a global subscriber and
    /// writes a `OnceLock`.
    #[test]
    fn the_flag_survives_a_reload() {
        let _guard = acme_proxy_core::config::ENV_LOCK
            .lock()
            .unwrap_or_else(|e| e.into_inner());
        unsafe { std::env::remove_var("RUST_LOG") };

        assert!(flag_override().is_none(), "nothing is set before startup");

        let at_error = acme_proxy_core::config::LoggingConfig {
            filter: "acme_proxy=error".to_string(),
            target: "stderr".to_string(),
            ..Default::default()
        };
        init_logging(&at_error, Some("acme_proxy=debug".to_string()))
            .expect("the subscriber installs");
        assert_eq!(LevelFilter::current(), LevelFilter::DEBUG);
        assert_eq!(flag_override(), Some("acme_proxy=debug"));

        // The reload's own call, verbatim: a new file with a different filter,
        // rebuilt through the flag the cell remembers.
        let edited = acme_proxy_core::config::LoggingConfig {
            filter: "acme_proxy=error".to_string(),
            target: "stderr".to_string(),
            span_events: "close".to_string(),
            ..Default::default()
        };
        let prepared = prepare_logging(&edited, flag_override()).expect("the stack rebuilds");
        assert_eq!(prepared.filter_source, FilterSource::Flag);
        assert!(publish_logging(prepared));
        assert_eq!(
            LevelFilter::current(),
            LevelFilter::DEBUG,
            "the reload must not demote the server to the file's filter",
        );
    }
}