Skip to main content

nemo_relay/logging/
mod.rs

1// SPDX-FileCopyrightText: Copyright (c) 2026, NVIDIA CORPORATION & AFFILIATES. All rights reserved.
2// SPDX-License-Identifier: Apache-2.0
3
4//! Operational process logging for Relay (stderr + optional file sinks).
5//!
6//! Call sites emit through the `log` facade (`log::info!`, …). This module owns the
7//! `spdlog-rs` backend, `LogCrateProxy` installation, formatters, and sink lifetime.
8
9mod config;
10mod format;
11mod rotation;
12mod sink;
13
14use std::io::{self, Write};
15use std::path::Path;
16use std::sync::{Arc, Mutex, MutexGuard, Weak};
17
18use spdlog::sink::Sink;
19use spdlog::{Logger, ThreadPool};
20use uuid::Uuid;
21
22use crate::error::{FlowError, Result};
23
24pub use config::{
25    DEFAULT_FILE_FLUSH_INTERVAL_MILLIS, DEFAULT_FILE_SINK_QUEUE_ENTRIES, FileLogRotationConfig,
26    FileLogSinkConfig, LogFormat, LogLevel, LogSinkConfig, LoggingConfig,
27    MAX_FILE_SINK_QUEUE_ENTRIES, MAX_FILE_SINK_RETAINED_FILES,
28};
29pub(crate) use sink::build_logger;
30use sink::log_level_filter;
31
32#[cfg(test)]
33pub(crate) use format::format_event_for_test;
34
35static LOGGER_LIFECYCLE_LOCK: Mutex<()> = Mutex::new(());
36static DEFAULT_LOGGING_RUNTIME: Mutex<Option<LoggingRuntime>> = Mutex::new(None);
37static ACTIVE_RELAY_LOGGER: Mutex<Option<Weak<Logger>>> = Mutex::new(None);
38
39fn lock_logger_lifecycle() -> MutexGuard<'static, ()> {
40    LOGGER_LIFECYCLE_LOCK
41        .lock()
42        .unwrap_or_else(|error| error.into_inner())
43}
44
45fn log_crate_proxy_is_installed() -> bool {
46    std::ptr::addr_eq(log::logger(), spdlog::log_crate_proxy() as &dyn log::Log)
47}
48
49fn active_relay_logger_exists() -> bool {
50    ACTIVE_RELAY_LOGGER
51        .lock()
52        .unwrap_or_else(|error| error.into_inner())
53        .as_ref()
54        .is_some_and(|logger| logger.upgrade().is_some())
55}
56
57fn set_active_relay_logger(logger: &Arc<Logger>) {
58    *ACTIVE_RELAY_LOGGER
59        .lock()
60        .unwrap_or_else(|error| error.into_inner()) = Some(Arc::downgrade(logger));
61}
62
63fn clear_active_relay_logger(logger: &Arc<Logger>) {
64    let mut active = ACTIVE_RELAY_LOGGER
65        .lock()
66        .unwrap_or_else(|error| error.into_inner());
67    if active
68        .as_ref()
69        .is_some_and(|current| Weak::ptr_eq(current, &Arc::downgrade(logger)))
70    {
71        *active = None;
72    }
73}
74
75fn install_log_crate_proxy() -> Result<()> {
76    match spdlog::init_log_crate_proxy() {
77        Ok(()) => Ok(()),
78        Err(_) if log_crate_proxy_is_installed() => Ok(()),
79        Err(_) => Err(FlowError::AlreadyExists(
80            "process-global log facade is already initialized by another logger; Relay logging cannot install its log proxy"
81                .into(),
82        )),
83    }
84}
85
86/// Owns logging resources that must remain alive for the process / run lifetime.
87///
88/// When created by [`LoggingRuntime::configure`], dropping this value flushes sinks and detaches this
89/// logger from the process-global spdlog `log` proxy if it is still installed.
90pub struct LoggingRuntime {
91    root_relay_id: String,
92    /// Underlying spdlog logger (also installed into the `log` facade by
93    /// [`LoggingRuntime::configure`]).
94    pub(crate) logger: Arc<Logger>,
95    /// Keeps per-sink async thread pools alive until shutdown.
96    _thread_pools: Vec<Arc<ThreadPool>>,
97}
98
99impl LoggingRuntime {
100    /// Installs process-wide operational logging from resolved configuration.
101    ///
102    /// Stderr is always enabled. Explicit file sinks fail initialization if they cannot be
103    /// opened. Dropping the returned runtime flushes sinks and detaches its logger from the
104    /// process-global `log` proxy when it is still installed.
105    pub fn configure(config: LoggingConfig) -> Result<Self> {
106        // Install once per process. Subsequent calls (tests / re-entry) reuse the proxy and swap
107        // the receiver logger. A different global logger would prevent Relay sinks from receiving
108        // `log` facade records, so fail instead of returning a nonfunctional runtime.
109        let _lifecycle = lock_logger_lifecycle();
110        Self::configure_with_lifecycle_lock(config)
111    }
112
113    fn configure_with_lifecycle_lock(config: LoggingConfig) -> Result<Self> {
114        let root_relay_id = Uuid::now_v7().to_string();
115        let (logger, thread_pools) = build_logger(&config, root_relay_id.clone())?;
116
117        install_log_crate_proxy()?;
118        spdlog::log_crate_proxy().set_logger(Some(Arc::clone(&logger)));
119        spdlog::log_crate_proxy().set_filter(None);
120        log::set_max_level(log_level_filter(config.level));
121        set_active_relay_logger(&logger);
122
123        log::info!(
124            target: "nemo_relay.logging",
125            event = "logging_initialized",
126            file_sink_count = config.sinks.len();
127            "Operational logging initialized"
128        );
129
130        Ok(Self {
131            root_relay_id,
132            logger,
133            _thread_pools: thread_pools,
134        })
135    }
136
137    /// Loads logging configuration from an absolute TOML path and installs it process-wide.
138    pub fn configure_from_file_path(path: impl AsRef<Path>) -> Result<Self> {
139        Self::configure(LoggingConfig::from_file_path(path)?)
140    }
141
142    /// Resolves supported logging environment variables and installs the resulting configuration.
143    ///
144    /// Built-in defaults are used when no logging environment variables are present.
145    pub fn configure_from_environment() -> Result<Self> {
146        Self::configure(LoggingConfig::from_environment()?.unwrap_or_default())
147    }
148
149    /// Returns the process root Relay ID attached to operational records after initialization.
150    pub fn root_relay_id(&self) -> &str {
151        &self.root_relay_id
152    }
153
154    /// Flushes buffered sinks and detaches global proxy wiring by dropping the runtime.
155    pub fn shutdown(self) {
156        drop(self);
157    }
158}
159
160impl Drop for LoggingRuntime {
161    fn drop(&mut self) {
162        log::info!(
163            target: "nemo_relay.logging",
164            event = "logging_shutdown_started";
165            "Operational logging shutdown started"
166        );
167        // Periodic flusher must stop before exit flush so it cannot race teardown.
168        self.logger.set_flush_period(None);
169        // `Logger::flush` only enqueues AsyncPoolSink work. `flush_on_exit` destroys the
170        // pool (draining pending tasks) then flushes the underlying FileSink on this thread.
171        // LogCrateProxy loggers are outside spdlog's atexit default-logger path, so we must
172        // do this explicitly while `_thread_pools` is still alive.
173        for sink in self.logger.sinks() {
174            if let Err(error) = Sink::flush_on_exit(sink.as_ref()) {
175                let _ = writeln!(
176                    io::stderr(),
177                    "nemo-relay: logging shutdown flush failed: {error}"
178                );
179            }
180        }
181
182        // Detach only if we are still the installed receiver. A later configuration may have
183        // replaced us; do not clear that newer install. Installation and teardown are serialized
184        // because swap-and-restore is a multi-step operation.
185        let _lifecycle = lock_logger_lifecycle();
186        let detached = spdlog::log_crate_proxy().swap_logger(None);
187        if let Some(logger) = detached
188            && !Arc::ptr_eq(&logger, &self.logger)
189        {
190            spdlog::log_crate_proxy().set_logger(Some(Arc::clone(&logger)));
191            set_active_relay_logger(&logger);
192        } else {
193            clear_active_relay_logger(&self.logger);
194        }
195    }
196}
197
198/// Installs process-wide operational logging from resolved config.
199///
200/// Stderr is always enabled. Explicit file sinks fail startup if they cannot be opened.
201///
202/// Verbosity comes from [`LoggingConfig::level`]: records below that minimum severity are discarded.
203/// Dropping the returned [`LoggingRuntime`] flushes sinks and detaches this logger from the
204/// process-global `log` proxy when it is still installed.
205pub fn init_logging(config: &LoggingConfig) -> Result<LoggingRuntime> {
206    LoggingRuntime::configure(config.clone())
207}
208
209/// Installs and retains the default process-wide logging runtime for a language binding.
210///
211/// Configuration is resolved from the supported logging environment variables, with built-in
212/// defaults when none are present. Repeated initialization in the same linked runtime is a no-op.
213#[doc(hidden)]
214pub fn initialize_default_logging() -> Result<()> {
215    let mut runtime = DEFAULT_LOGGING_RUNTIME.lock().map_err(|error| {
216        FlowError::Internal(format!("default logging runtime lock poisoned: {error}"))
217    })?;
218    if runtime.is_none() {
219        let config = LoggingConfig::from_environment()?;
220        let uses_default_config = config.is_none();
221        let _lifecycle = lock_logger_lifecycle();
222        if uses_default_config && active_relay_logger_exists() {
223            return Ok(());
224        }
225        match LoggingRuntime::configure_with_lifecycle_lock(config.unwrap_or_default()) {
226            Ok(configured) => *runtime = Some(configured),
227            // Language bindings initialize logging automatically. When Relay was not explicitly
228            // configured, defer to an application logger that already owns the process facade.
229            Err(FlowError::AlreadyExists(_)) if uses_default_config => {}
230            Err(error) => return Err(error),
231        }
232    }
233    Ok(())
234}
235
236/// Shuts down and releases the default process-wide logging runtime for a language binding.
237///
238/// Repeated shutdown in the same linked runtime is a no-op. The runtime is removed from shared
239/// state before its sinks are drained so shutdown does not hold the default-runtime lock.
240#[doc(hidden)]
241pub fn shutdown_default_logging() -> Result<()> {
242    let runtime = DEFAULT_LOGGING_RUNTIME
243        .lock()
244        .map_err(|error| {
245            FlowError::Internal(format!("default logging runtime lock poisoned: {error}"))
246        })?
247        .take();
248    if let Some(runtime) = runtime {
249        runtime.shutdown();
250    }
251    Ok(())
252}
253
254#[cfg(test)]
255#[path = "../../tests/coverage/logging_tests.rs"]
256mod tests;