nautilus_common/logging/
mod.rs

1// -------------------------------------------------------------------------------------------------
2//  Copyright (C) 2015-2025 Nautech Systems Pty Ltd. All rights reserved.
3//  https://nautechsystems.io
4//
5//  Licensed under the GNU Lesser General Public License Version 3.0 (the "License");
6//  You may not use this file except in compliance with the License.
7//  You may obtain a copy of the License at https://www.gnu.org/licenses/lgpl-3.0.en.html
8//
9//  Unless required by applicable law or agreed to in writing, software
10//  distributed under the License is distributed on an "AS IS" BASIS,
11//  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12//  See the License for the specific language governing permissions and
13//  limitations under the License.
14// -------------------------------------------------------------------------------------------------
15
16//! The logging framework for Nautilus systems.
17//!
18//! This module implements a high-performance logging subsystem that operates in a separate thread
19//! using an MPSC channel for log message delivery. The system uses reference counting to track
20//! active `LogGuard` instances, ensuring the logging thread completes all pending writes before
21//! termination.
22//!
23//! # LogGuard Reference Counting
24//!
25//! The logging system maintains a global count of active `LogGuard` instances using an atomic
26//! counter (`LOGGING_GUARDS_ACTIVE`). When a `LogGuard` is created, the counter is incremented,
27//! and when dropped, it's decremented. When the last `LogGuard` is dropped (counter reaches zero),
28//! the logging thread is properly joined to ensure all buffered log messages are written to their
29//! destinations before the process terminates.
30//!
31//! The system supports a maximum of 255 concurrent `LogGuard` instances. Attempting to create
32//! more will cause a panic.
33
34pub mod headers;
35pub mod logger;
36pub mod macros;
37pub mod writer;
38
39use std::{
40    collections::HashMap,
41    env,
42    str::FromStr,
43    sync::atomic::{AtomicBool, AtomicU8, Ordering},
44};
45
46use log::LevelFilter;
47// Re-exports
48pub use macros::{log_debug, log_error, log_info, log_trace, log_warn};
49use nautilus_core::{UUID4, time::get_atomic_clock_static};
50use nautilus_model::identifiers::TraderId;
51use tracing_subscriber::EnvFilter;
52use ustr::Ustr;
53
54use self::{
55    logger::{LogGuard, Logger, LoggerConfig},
56    writer::FileWriterConfig,
57};
58use crate::enums::LogLevel;
59
60pub const RECV: &str = "<--";
61pub const SEND: &str = "-->";
62pub const CMD: &str = "[CMD]";
63pub const EVT: &str = "[EVT]";
64pub const DOC: &str = "[DOC]";
65pub const RPT: &str = "[RPT]";
66pub const REQ: &str = "[REQ]";
67pub const RES: &str = "[RES]";
68
69static LOGGING_INITIALIZED: AtomicBool = AtomicBool::new(false);
70static LOGGING_BYPASSED: AtomicBool = AtomicBool::new(false);
71static LOGGING_REALTIME: AtomicBool = AtomicBool::new(true);
72static LOGGING_COLORED: AtomicBool = AtomicBool::new(true);
73static LOGGING_GUARDS_ACTIVE: AtomicU8 = AtomicU8::new(0);
74
75/// Returns whether the core logger is enabled.
76pub fn logging_is_initialized() -> bool {
77    LOGGING_INITIALIZED.load(Ordering::Relaxed)
78}
79
80/// Sets the logging subsystem to bypass mode.
81pub fn logging_set_bypass() {
82    LOGGING_BYPASSED.store(true, Ordering::Relaxed);
83}
84
85/// Shuts down the logging subsystem.
86pub fn logging_shutdown() {
87    // Perform a graceful shutdown: prevent new logs, signal Close, drain and join.
88    // Delegates to logger implementation which has access to the internals.
89    crate::logging::logger::shutdown_graceful();
90}
91
92/// Returns whether the core logger is using ANSI colors.
93pub fn logging_is_colored() -> bool {
94    LOGGING_COLORED.load(Ordering::Relaxed)
95}
96
97/// Sets the global logging clock to real-time mode.
98pub fn logging_clock_set_realtime_mode() {
99    LOGGING_REALTIME.store(true, Ordering::Relaxed);
100}
101
102/// Sets the global logging clock to static mode.
103pub fn logging_clock_set_static_mode() {
104    LOGGING_REALTIME.store(false, Ordering::Relaxed);
105}
106
107/// Sets the global logging clock static time with the given UNIX timestamp (nanoseconds).
108pub fn logging_clock_set_static_time(time_ns: u64) {
109    let clock = get_atomic_clock_static();
110    clock.set_time(time_ns.into());
111}
112
113/// Initialize tracing.
114///
115/// Tracing is meant to be used to trace/debug async Rust code. It can be
116/// configured to filter modules and write up to a specific level by passing
117/// a configuration using the `RUST_LOG` environment variable.
118///
119/// # Safety
120///
121/// Should only be called once during an applications run, ideally at the
122/// beginning of the run.
123///
124/// # Errors
125///
126/// Returns an error if tracing subscriber fails to initialize.
127pub fn init_tracing() -> anyhow::Result<()> {
128    // Skip tracing initialization if `RUST_LOG` is not set
129    if let Ok(v) = env::var("RUST_LOG") {
130        let env_filter = EnvFilter::new(v.clone());
131
132        tracing_subscriber::fmt()
133            .with_env_filter(env_filter)
134            .try_init()
135            .map_err(|e| anyhow::anyhow!("Failed to initialize tracing subscriber: {e}"))?;
136
137        println!("Initialized tracing logs with RUST_LOG={v}");
138    }
139    Ok(())
140}
141
142/// Initialize logging.
143///
144/// Logging should be used for Python and sync Rust logic which is most of
145/// the components in the [nautilus_trader](https://pypi.org/project/nautilus_trader) package.
146/// Logging can be configured to filter components and write up to a specific level only
147/// by passing a configuration using the `NAUTILUS_LOG` environment variable.
148///
149/// # Safety
150///
151/// Should only be called once during an applications run, ideally at the
152/// beginning of the run.
153///
154/// Logging should be used for Python and sync Rust logic which is most of
155/// the components in the `nautilus_trader` package.
156/// Logging can be configured via the `NAUTILUS_LOG` environment variable.
157///
158/// # Errors
159///
160/// Returns an error if the logging subsystem fails to initialize.
161pub fn init_logging(
162    trader_id: TraderId,
163    instance_id: UUID4,
164    config: LoggerConfig,
165    file_config: FileWriterConfig,
166) -> anyhow::Result<LogGuard> {
167    // Only set these after successful initialization
168    let is_colored = config.is_colored;
169    let guard = Logger::init_with_config(trader_id, instance_id, config, file_config)?;
170
171    // Set flags only after successful initialization
172    LOGGING_INITIALIZED.store(true, Ordering::Relaxed);
173    LOGGING_COLORED.store(is_colored, Ordering::Relaxed);
174
175    Ok(guard)
176}
177
178#[must_use]
179pub const fn map_log_level_to_filter(log_level: LogLevel) -> LevelFilter {
180    match log_level {
181        LogLevel::Off => LevelFilter::Off,
182        LogLevel::Trace => LevelFilter::Trace,
183        LogLevel::Debug => LevelFilter::Debug,
184        LogLevel::Info => LevelFilter::Info,
185        LogLevel::Warning => LevelFilter::Warn,
186        LogLevel::Error => LevelFilter::Error,
187    }
188}
189
190/// Parses a string into a [`LevelFilter`].
191///
192/// # Errors
193///
194/// Returns an error if the provided string is not a valid `LevelFilter`.
195pub fn parse_level_filter_str(s: &str) -> anyhow::Result<LevelFilter> {
196    let mut log_level_str = s.to_string().to_uppercase();
197    if log_level_str == "WARNING" {
198        log_level_str = "WARN".to_string();
199    }
200    LevelFilter::from_str(&log_level_str)
201        .map_err(|_| anyhow::anyhow!("Invalid log level string: '{s}'"))
202}
203
204/// Parses component-specific log levels from a JSON value map.
205///
206/// # Errors
207///
208/// Returns an error if a JSON value in the map is not a string or is not a valid log level.
209pub fn parse_component_levels(
210    original_map: Option<HashMap<String, serde_json::Value>>,
211) -> anyhow::Result<HashMap<Ustr, LevelFilter>> {
212    match original_map {
213        Some(map) => {
214            let mut new_map = HashMap::new();
215            for (key, value) in map {
216                let ustr_key = Ustr::from(&key);
217                let s = value.as_str().ok_or_else(|| {
218                    anyhow::anyhow!(
219                        "Component log level for '{key}' must be a string, got: {value}"
220                    )
221                })?;
222                let lvl = parse_level_filter_str(s)?;
223                new_map.insert(ustr_key, lvl);
224            }
225            Ok(new_map)
226        }
227        None => Ok(HashMap::new()),
228    }
229}
230
231/// Logs that a task has started using `tracing::debug!`.
232pub fn log_task_started(task_name: &str) {
233    tracing::debug!("Started task '{task_name}'");
234}
235
236/// Logs that a task has stopped using `tracing::debug!`.
237pub fn log_task_stopped(task_name: &str) {
238    tracing::debug!("Stopped task '{task_name}'");
239}
240
241/// Logs that a task is being awaited using `tracing::debug!`.
242pub fn log_task_awaiting(task_name: &str) {
243    tracing::debug!("Awaiting task '{task_name}'");
244}
245
246/// Logs that a task was aborted using `tracing::debug!`.
247pub fn log_task_aborted(task_name: &str) {
248    tracing::debug!("Aborted task '{task_name}'");
249}
250
251/// Logs that there was an error in a task `tracing::error!`.
252pub fn log_task_error(task_name: &str, e: &anyhow::Error) {
253    tracing::error!("Error in task '{task_name}': {e}");
254}
255
256#[cfg(test)]
257mod tests {
258    use rstest::rstest;
259
260    use super::*;
261
262    #[rstest]
263    #[case("DEBUG", LevelFilter::Debug)]
264    #[case("debug", LevelFilter::Debug)]
265    #[case("Debug", LevelFilter::Debug)]
266    #[case("DeBuG", LevelFilter::Debug)]
267    #[case("INFO", LevelFilter::Info)]
268    #[case("info", LevelFilter::Info)]
269    #[case("WARNING", LevelFilter::Warn)]
270    #[case("warning", LevelFilter::Warn)]
271    #[case("WARN", LevelFilter::Warn)]
272    #[case("warn", LevelFilter::Warn)]
273    #[case("ERROR", LevelFilter::Error)]
274    #[case("error", LevelFilter::Error)]
275    #[case("OFF", LevelFilter::Off)]
276    #[case("off", LevelFilter::Off)]
277    #[case("TRACE", LevelFilter::Trace)]
278    #[case("trace", LevelFilter::Trace)]
279    fn test_parse_level_filter_str_case_insensitive(
280        #[case] input: &str,
281        #[case] expected: LevelFilter,
282    ) {
283        let result = parse_level_filter_str(input).unwrap();
284        assert_eq!(result, expected);
285    }
286
287    #[rstest]
288    #[case("INVALID")]
289    #[case("DEBG")]
290    #[case("WARNINGG")]
291    #[case("")]
292    #[case("INFO123")]
293    fn test_parse_level_filter_str_invalid_returns_error(#[case] invalid_input: &str) {
294        let result = parse_level_filter_str(invalid_input);
295
296        assert!(result.is_err());
297        assert!(
298            result
299                .unwrap_err()
300                .to_string()
301                .contains("Invalid log level")
302        );
303    }
304
305    #[rstest]
306    fn test_parse_component_levels_valid() {
307        let mut map = HashMap::new();
308        map.insert(
309            "Strategy1".to_string(),
310            serde_json::Value::String("DEBUG".to_string()),
311        );
312        map.insert(
313            "Strategy2".to_string(),
314            serde_json::Value::String("info".to_string()),
315        );
316
317        let result = parse_component_levels(Some(map)).unwrap();
318
319        assert_eq!(result.len(), 2);
320        assert_eq!(result[&Ustr::from("Strategy1")], LevelFilter::Debug);
321        assert_eq!(result[&Ustr::from("Strategy2")], LevelFilter::Info);
322    }
323
324    #[rstest]
325    fn test_parse_component_levels_non_string_value_returns_error() {
326        let mut map = HashMap::new();
327        map.insert(
328            "Strategy1".to_string(),
329            serde_json::Value::Number(123.into()),
330        );
331
332        let result = parse_component_levels(Some(map));
333
334        assert!(result.is_err());
335        assert!(result.unwrap_err().to_string().contains("must be a string"));
336    }
337
338    #[rstest]
339    fn test_parse_component_levels_invalid_level_returns_error() {
340        let mut map = HashMap::new();
341        map.insert(
342            "Strategy1".to_string(),
343            serde_json::Value::String("INVALID_LEVEL".to_string()),
344        );
345
346        let result = parse_component_levels(Some(map));
347
348        assert!(result.is_err());
349        assert!(
350            result
351                .unwrap_err()
352                .to_string()
353                .contains("Invalid log level")
354        );
355    }
356
357    #[rstest]
358    fn test_parse_component_levels_none_returns_empty() {
359        let result = parse_component_levels(None).unwrap();
360        assert_eq!(result.len(), 0);
361    }
362}
nautilus_common/logging/mod.rs

nautilus_common/logging/
mod.rs
