Skip to main content

nautilus_common/logging/
logger.rs

1// -------------------------------------------------------------------------------------------------
2//  Copyright (C) 2015-2026 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//! Core logger lifecycle, filtering, event formatting, and dispatch.
17
18use std::{
19    cell::RefCell,
20    fmt::{Display, Write as _},
21    sync::{
22        OnceLock,
23        atomic::{AtomicBool, Ordering},
24        mpsc::SendError,
25    },
26};
27
28use ahash::AHashMap;
29use indexmap::IndexMap;
30use log::{
31    Level, LevelFilter, Log, STATIC_MAX_LEVEL,
32    kv::{ToValue, Value},
33    set_boxed_logger, set_max_level,
34};
35use nautilus_core::{
36    UUID4, UnixNanos,
37    datetime::unix_nanos_to_iso8601,
38    time::{get_atomic_clock_realtime, get_atomic_clock_static},
39};
40use nautilus_model::identifiers::TraderId;
41use parking_lot::Mutex;
42use serde::{Deserialize, Serialize, Serializer, ser::SerializeMap};
43use smallvec::SmallVec;
44use ustr::Ustr;
45
46pub use super::config::LoggerConfig;
47use super::{LOGGING_BYPASSED, LOGGING_GUARDS_ACTIVE, LOGGING_INITIALIZED, LOGGING_REALTIME};
48#[cfg(not(all(feature = "simulation", madsim)))]
49use crate::logging::writer::{FileWriter, LogWriter, StderrWriter, StdoutWriter};
50use crate::{
51    enums::{LogColor, LogLevel},
52    logging::writer::FileWriterConfig,
53};
54
55#[cfg(not(all(feature = "simulation", madsim)))]
56const LOGGING: &str = "logging";
57const KV_COLOR: &str = "color";
58const KV_COMPONENT: &str = "component";
59const LOG_FIELDS_INLINE_CAP: usize = 0;
60const MAX_LEVEL_DISPLAY_LEN: usize = "ERROR".len();
61const ANSI_BOLD_LEN: usize = "\x1b[1m".len();
62const ANSI_RESET_LEN: usize = "\x1b[0m".len();
63const PLAIN_FORMAT_OVERHEAD: usize = " [".len() + "] ".len() + ".".len() + ": ".len() + "\n".len();
64const COLORED_FORMAT_OVERHEAD: usize = ANSI_BOLD_LEN
65    + ANSI_RESET_LEN
66    + " ".len()
67    + "[".len()
68    + "] ".len()
69    + ".".len()
70    + ": ".len()
71    + ANSI_RESET_LEN
72    + "\n".len();
73const REPEATED_USTR_CACHE_CAP: usize = 8;
74
75thread_local! {
76    static REPEATED_USTR_CACHE: RefCell<RepeatedUstrCache> =
77        const { RefCell::new(RepeatedUstrCache::new()) };
78}
79
80/// Storage for structured log fields.
81/// Inline capacity is intentionally zero to keep the producer-side `LogLine` payload small.
82pub type LogFields = SmallVec<[(Ustr, String); LOG_FIELDS_INLINE_CAP]>;
83
84/// Global log sender which allows multiple log guards per process.
85static LOGGER_TX: OnceLock<std::sync::mpsc::Sender<LogEvent>> = OnceLock::new();
86
87/// Global handle to the logging thread - only one thread exists per process.
88static LOGGER_HANDLE: Mutex<Option<std::thread::JoinHandle<()>>> = Mutex::new(None);
89
90#[derive(Debug, Clone, Copy, PartialEq, Eq)]
91enum LoggerLifecycle {
92    Uninitialized,
93    Running,
94    Terminated,
95}
96
97/// Process-global logger lifecycle serialization.
98static LOGGER_LIFECYCLE: Mutex<LoggerLifecycle> = Mutex::new(LoggerLifecycle::Uninitialized);
99
100#[cfg(all(test, not(all(feature = "simulation", madsim))))]
101struct InitPublishHook {
102    reached: std::sync::mpsc::Sender<()>,
103    resume: std::sync::mpsc::Receiver<()>,
104}
105
106#[cfg(all(test, not(all(feature = "simulation", madsim))))]
107static INIT_PUBLISH_HOOK: Mutex<Option<InitPublishHook>> = Mutex::new(None);
108
109#[cfg(all(test, not(all(feature = "simulation", madsim))))]
110enum TestGuardAcquire {
111    LifecycleBusy,
112    Acquired(Option<LogGuard>),
113}
114
115static SHUTDOWN_ON_ERROR: OnceLock<ShutdownOnError> = OnceLock::new();
116
117/// The first error log captured after shutdown-on-error is armed.
118#[derive(Debug, Clone, PartialEq, Eq)]
119pub struct ShutdownOnErrorTrigger {
120    /// The UNIX timestamp (ns) of the error log.
121    pub timestamp: UnixNanos,
122    /// The log component that emitted the error.
123    pub component: Ustr,
124    /// The formatted error log message.
125    pub message: String,
126}
127
128#[derive(Debug, Default)]
129struct ShutdownOnError {
130    armed: AtomicBool,
131    triggered: AtomicBool,
132    pending: Mutex<Option<ShutdownOnErrorTrigger>>,
133}
134
135impl ShutdownOnError {
136    fn is_armed(&self) -> bool {
137        self.armed.load(Ordering::Acquire)
138    }
139
140    fn arm(&self, enabled: bool) {
141        self.pending.lock().take();
142        self.triggered.store(false, Ordering::Release);
143        self.armed.store(enabled, Ordering::Release);
144    }
145
146    fn disarm(&self) {
147        self.armed.store(false, Ordering::Release);
148        self.triggered.store(false, Ordering::Release);
149
150        self.pending.lock().take();
151    }
152
153    fn maybe_record_trigger<F>(
154        &self,
155        level: Level,
156        timestamp: UnixNanos,
157        component: Ustr,
158        message: F,
159    ) where
160        F: FnOnce() -> String,
161    {
162        if !self.armed.load(Ordering::Acquire) || level != Level::Error {
163            return;
164        }
165
166        let mut pending = self.pending.lock();
167
168        if self
169            .triggered
170            .compare_exchange(false, true, Ordering::AcqRel, Ordering::Acquire)
171            .is_err()
172        {
173            return;
174        }
175
176        *pending = Some(ShutdownOnErrorTrigger {
177            timestamp,
178            component,
179            message: message(),
180        });
181    }
182
183    fn take_trigger(&self) -> Option<ShutdownOnErrorTrigger> {
184        if !self.triggered.load(Ordering::Acquire) {
185            return None;
186        }
187
188        self.pending.lock().take()
189    }
190
191    fn try_drain_trigger<F>(&self, drain: F) -> bool
192    where
193        F: FnOnce(&ShutdownOnErrorTrigger) -> bool,
194    {
195        if !self.triggered.load(Ordering::Acquire) {
196            return false;
197        }
198
199        let mut pending = self.pending.lock();
200
201        let Some(trigger) = pending.as_ref() else {
202            return false;
203        };
204
205        if !drain(trigger) {
206            return false;
207        }
208
209        pending.take();
210        true
211    }
212}
213
214/// Arms shutdown-on-error handling for the current run.
215pub fn arm_shutdown_on_error(enabled: bool) {
216    shutdown_on_error().arm(enabled);
217}
218
219/// Disarms shutdown-on-error handling and clears any pending trigger.
220pub fn disarm_shutdown_on_error() {
221    shutdown_on_error().disarm();
222}
223
224/// Returns and clears the pending shutdown-on-error trigger, if one was recorded.
225pub fn take_shutdown_on_error_trigger() -> Option<ShutdownOnErrorTrigger> {
226    shutdown_on_error().take_trigger()
227}
228
229/// Conditionally drains the pending shutdown-on-error trigger.
230pub fn try_drain_shutdown_on_error_trigger<F>(drain: F) -> bool
231where
232    F: FnOnce(&ShutdownOnErrorTrigger) -> bool,
233{
234    shutdown_on_error().try_drain_trigger(drain)
235}
236
237fn shutdown_on_error() -> &'static ShutdownOnError {
238    SHUTDOWN_ON_ERROR.get_or_init(ShutdownOnError::default)
239}
240
241/// Producer-side filtering policy derived from [`LoggerConfig`].
242#[derive(Debug, Clone)]
243struct FilterPolicy {
244    /// Module filters pre-sorted by descending path length for longest-prefix lookup.
245    modules_by_longest_prefix: Vec<(Ustr, LevelFilter)>,
246    /// Per-component log level overrides.
247    components: AHashMap<Ustr, LevelFilter>,
248    /// Whether logs without an explicit component/module filter should be skipped.
249    components_only: bool,
250}
251
252impl FilterPolicy {
253    fn from_config(config: &LoggerConfig) -> Option<Self> {
254        let modules_by_longest_prefix = sorted_module_filters_from_map(&config.module_level);
255        if !config.log_components_only
256            && modules_by_longest_prefix.is_empty()
257            && config.component_level.is_empty()
258        {
259            return None;
260        }
261
262        Some(Self {
263            modules_by_longest_prefix,
264            components: config.component_level.clone(),
265            components_only: config.log_components_only,
266        })
267    }
268
269    fn should_skip(&self, component: &Ustr, level: Level) -> bool {
270        should_filter_log_inner(
271            component,
272            level,
273            &self.modules_by_longest_prefix,
274            &self.components,
275            self.components_only,
276        )
277    }
278}
279
280/// A high-performance logger utilizing a MPSC channel under the hood.
281///
282/// A logger is initialized with a [`LoggerConfig`] to set up different logging levels for
283/// stdout, file, and components. The logger spawns a thread that listens for [`LogEvent`]s
284/// sent via an MPSC channel.
285#[derive(Debug)]
286pub struct Logger {
287    /// Initialization snapshot for logging levels and behavior.
288    ///
289    /// Producer filters are derived into `filter_policy` at initialization; mutating this field
290    /// after registration does not reload component/module filters.
291    pub config: LoggerConfig,
292    /// Producer-side component/module filtering policy.
293    filter_policy: Option<FilterPolicy>,
294    /// Transmitter for sending log events to the 'logging' thread.
295    tx: std::sync::mpsc::Sender<LogEvent>,
296}
297
298/// Represents a type of log event.
299#[derive(Debug)]
300pub enum LogEvent {
301    /// A log line event.
302    Log(LogLine),
303    /// A command to flush all logger buffers.
304    Flush,
305    /// A command to flush and sync file logs to disk, then acknowledge completion.
306    Sync(std::sync::mpsc::Sender<anyhow::Result<()>>),
307    /// A command to close the logger.
308    Close,
309}
310
311/// Represents a log event which includes a message.
312#[derive(Clone, Debug, Serialize, Deserialize)]
313pub struct LogLine {
314    /// The timestamp for the event.
315    pub timestamp: UnixNanos,
316    /// The log level for the event.
317    pub level: Level,
318    /// The color for the log message content.
319    pub color: LogColor,
320    /// The Nautilus system component the log event originated from.
321    pub component: Ustr,
322    /// The log message content.
323    pub message: String,
324    /// Arbitrary structured key-value fields attached to this log event.
325    #[serde(default, skip_serializing_if = "SmallVec::is_empty")]
326    pub fields: LogFields,
327}
328
329impl Display for LogLine {
330    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
331        write!(f, "[{}] {}: {}", self.level, self.component, self.message)?;
332        for (k, v) in &self.fields {
333            write!(f, " {k}={v}")?;
334        }
335        Ok(())
336    }
337}
338
339/// A wrapper around a log line that provides formatted and cached representations.
340///
341/// This struct contains a log line and provides various formatted versions
342/// of it, such as plain string, colored string, and JSON. It also caches the
343/// results for repeated calls, optimizing performance when the same message
344/// needs to be logged multiple times in different formats.
345#[derive(Clone, Debug)]
346pub struct LogLineWrapper {
347    /// The underlying log line that contains the log data.
348    line: LogLine,
349    /// Cached plain string representation of the log line.
350    cache: Option<String>,
351    /// Cached colored string representation of the log line.
352    colored: Option<String>,
353    /// The ID of the trader associated with this log event.
354    trader_id: Ustr,
355}
356
357impl LogLineWrapper {
358    /// Creates a new [`LogLineWrapper`] instance.
359    #[must_use]
360    pub const fn new(line: LogLine, trader_id: Ustr) -> Self {
361        Self {
362            line,
363            cache: None,
364            colored: None,
365            trader_id,
366        }
367    }
368
369    /// Returns the plain log message string, caching the result.
370    ///
371    /// This method constructs the log line format and caches it for repeated calls. Useful when the
372    /// same log message needs to be printed multiple times.
373    pub fn get_string(&mut self) -> &str {
374        self.cache.get_or_insert_with(|| {
375            let timestamp = unix_nanos_to_iso8601(self.line.timestamp);
376            let mut s = String::with_capacity(plain_log_line_capacity(
377                &timestamp,
378                self.trader_id,
379                &self.line,
380            ));
381
382            write!(
383                s,
384                "{} [{}] {}.{}: {}",
385                timestamp, self.line.level, self.trader_id, self.line.component, self.line.message,
386            )
387            .expect("writing to String should not fail");
388
389            for (k, v) in &self.line.fields {
390                s.push(' ');
391                s.push_str(k);
392                s.push('=');
393                s.push_str(v);
394            }
395            s.push('\n');
396            s
397        })
398    }
399
400    /// Returns the colored log message string, caching the result.
401    ///
402    /// This method constructs the colored log line format and caches the result
403    /// for repeated calls, providing the message with ANSI color codes if the
404    /// logger is configured to use colors.
405    pub fn get_colored(&mut self) -> &str {
406        self.colored.get_or_insert_with(|| {
407            let timestamp = unix_nanos_to_iso8601(self.line.timestamp);
408            let color_ansi = self.line.color.as_ansi();
409            let mut s = String::with_capacity(colored_log_line_capacity(
410                &timestamp,
411                color_ansi,
412                self.trader_id,
413                &self.line,
414            ));
415
416            write!(
417                s,
418                "\x1b[1m{}\x1b[0m {}[{}] {}.{}: {}",
419                timestamp,
420                color_ansi,
421                self.line.level,
422                self.trader_id,
423                self.line.component,
424                self.line.message,
425            )
426            .expect("writing to String should not fail");
427
428            for (k, v) in &self.line.fields {
429                s.push(' ');
430                s.push_str(k);
431                s.push('=');
432                s.push_str(v);
433            }
434            s.push_str("\x1b[0m\n");
435            s
436        })
437    }
438
439    /// Returns the log message as a JSON string.
440    ///
441    /// This method serializes the log line and its associated metadata
442    /// (timestamp, trader ID, etc.) into a JSON string format. This is useful
443    /// for structured logging or when logs need to be stored in a JSON format.
444    /// # Panics
445    ///
446    /// Panics if serialization of the log event to JSON fails.
447    #[must_use]
448    pub fn get_json(&self) -> String {
449        let mut json_string =
450            serde_json::to_string(&self).expect("Error serializing log event to string");
451        json_string.push('\n');
452        json_string
453    }
454}
455
456fn formatted_fields_len(fields: &LogFields) -> usize {
457    fields.iter().map(|(k, v)| 2 + k.len() + v.len()).sum()
458}
459
460fn log_line_capacity(
461    timestamp: &str,
462    trader_id: Ustr,
463    line: &LogLine,
464    overhead: usize,
465    ansi_extra_len: usize,
466) -> usize {
467    timestamp.len()
468        + overhead
469        + ansi_extra_len
470        + MAX_LEVEL_DISPLAY_LEN
471        + trader_id.len()
472        + line.component.len()
473        + line.message.len()
474        + formatted_fields_len(&line.fields)
475}
476
477fn plain_log_line_capacity(timestamp: &str, trader_id: Ustr, line: &LogLine) -> usize {
478    log_line_capacity(timestamp, trader_id, line, PLAIN_FORMAT_OVERHEAD, 0)
479}
480
481fn colored_log_line_capacity(
482    timestamp: &str,
483    color_ansi: &str,
484    trader_id: Ustr,
485    line: &LogLine,
486) -> usize {
487    log_line_capacity(
488        timestamp,
489        trader_id,
490        line,
491        COLORED_FORMAT_OVERHEAD,
492        color_ansi.len(),
493    )
494}
495
496impl Serialize for LogLineWrapper {
497    fn serialize<S>(&self, serializer: S) -> Result<S::Ok, S::Error>
498    where
499        S: Serializer,
500    {
501        if has_duplicate_json_field(&self.line.fields) {
502            return serialize_log_line_with_indexmap(self, serializer);
503        }
504
505        let timestamp = unix_nanos_to_iso8601(self.line.timestamp);
506        let mut map = serializer.serialize_map(None)?;
507
508        map.serialize_entry("timestamp", &timestamp)?;
509        map.serialize_entry("trader_id", self.trader_id.as_str())?;
510        map.serialize_entry("level", &DisplayAsString(&self.line.level))?;
511        map.serialize_entry("color", &DisplayAsString(&self.line.color))?;
512        map.serialize_entry("component", self.line.component.as_str())?;
513        map.serialize_entry("message", &self.line.message)?;
514
515        for (k, v) in &self.line.fields {
516            let key = k.as_str();
517            if !is_reserved_json_key(key) {
518                map.serialize_entry(key, v)?;
519            }
520        }
521
522        map.end()
523    }
524}
525
526struct DisplayAsString<'a, T: ?Sized>(&'a T);
527
528impl<T> Serialize for DisplayAsString<'_, T>
529where
530    T: Display + ?Sized,
531{
532    fn serialize<S>(&self, serializer: S) -> Result<S::Ok, S::Error>
533    where
534        S: Serializer,
535    {
536        serializer.collect_str(self.0)
537    }
538}
539
540fn is_reserved_json_key(key: &str) -> bool {
541    matches!(
542        key,
543        "timestamp" | "trader_id" | "level" | "color" | "component" | "message"
544    )
545}
546
547fn has_duplicate_json_field(fields: &LogFields) -> bool {
548    if fields.is_empty() {
549        return false;
550    }
551
552    for (idx, (key, _)) in fields.iter().enumerate() {
553        let key = key.as_str();
554        if is_reserved_json_key(key) {
555            continue;
556        }
557
558        if fields
559            .iter()
560            .take(idx)
561            .any(|(prev, _)| !is_reserved_json_key(prev.as_str()) && prev.as_str() == key)
562        {
563            return true;
564        }
565    }
566
567    false
568}
569
570fn serialize_log_line_with_indexmap<S>(
571    wrapper: &LogLineWrapper,
572    serializer: S,
573) -> Result<S::Ok, S::Error>
574where
575    S: Serializer,
576{
577    let mut json_obj = IndexMap::new();
578    let timestamp = unix_nanos_to_iso8601(wrapper.line.timestamp);
579    json_obj.insert("timestamp".to_string(), timestamp);
580    json_obj.insert("trader_id".to_string(), wrapper.trader_id.to_string());
581    json_obj.insert("level".to_string(), wrapper.line.level.to_string());
582    json_obj.insert("color".to_string(), wrapper.line.color.to_string());
583    json_obj.insert("component".to_string(), wrapper.line.component.to_string());
584    json_obj.insert("message".to_string(), wrapper.line.message.clone());
585    for (k, v) in &wrapper.line.fields {
586        let key = k.as_str();
587        if !is_reserved_json_key(key) {
588            json_obj.insert(k.to_string(), v.clone());
589        }
590    }
591
592    json_obj.serialize(serializer)
593}
594
595fn sorted_module_filters_from_map(
596    module_level: &AHashMap<Ustr, LevelFilter>,
597) -> Vec<(Ustr, LevelFilter)> {
598    let mut filters: Vec<_> = module_level
599        .iter()
600        .map(|(path, level)| (*path, *level))
601        .collect();
602    filters.sort_by_key(|(path, _)| std::cmp::Reverse(path.len()));
603    filters
604}
605
606fn current_log_timestamp() -> UnixNanos {
607    if LOGGING_REALTIME.load(Ordering::Relaxed) {
608        get_atomic_clock_realtime().get_time_ns()
609    } else {
610        get_atomic_clock_static().get_time_ns()
611    }
612}
613
614fn intern_repeated(value: &str) -> Ustr {
615    REPEATED_USTR_CACHE.with(|cache| {
616        let mut cache_state = cache.borrow_mut();
617        let ptr = value.as_ptr() as usize;
618        let len = value.len();
619
620        // Targets and components are usually repeated static strings; the content check keeps
621        // dynamic RecordBuilder targets correct if an allocator reuses the same pointer.
622        for entry in cache_state.entries.iter().flatten() {
623            if entry.ptr == ptr && entry.len == len && entry.value.as_str() == value {
624                return entry.value;
625            }
626        }
627
628        let interned = Ustr::from(value);
629        let insert_idx = cache_state.next;
630        cache_state.entries[insert_idx] = Some(RepeatedUstrCacheEntry {
631            ptr,
632            len,
633            value: interned,
634        });
635        cache_state.next = (insert_idx + 1) % REPEATED_USTR_CACHE_CAP;
636        interned
637    })
638}
639
640#[derive(Clone, Copy)]
641struct RepeatedUstrCacheEntry {
642    ptr: usize,
643    len: usize,
644    value: Ustr,
645}
646
647#[derive(Clone, Copy)]
648struct RepeatedUstrCache {
649    entries: [Option<RepeatedUstrCacheEntry>; REPEATED_USTR_CACHE_CAP],
650    next: usize,
651}
652
653impl RepeatedUstrCache {
654    const fn new() -> Self {
655        Self {
656            entries: [None; REPEATED_USTR_CACHE_CAP],
657            next: 0,
658        }
659    }
660}
661
662fn intern_component_value(value: &log::kv::Value<'_>) -> Ustr {
663    match value.to_borrowed_str() {
664        Some(component) => intern_repeated(component),
665        None => Ustr::from(&value.to_string()),
666    }
667}
668
669#[derive(Default)]
670struct ComponentProbe {
671    component: Option<Ustr>,
672}
673
674impl<'kvs> log::kv::VisitSource<'kvs> for ComponentProbe {
675    fn visit_pair(
676        &mut self,
677        key: log::kv::Key<'kvs>,
678        value: log::kv::Value<'kvs>,
679    ) -> Result<(), log::kv::Error> {
680        if key.as_str() == KV_COMPONENT {
681            self.component = Some(intern_component_value(&value));
682        }
683        Ok(())
684    }
685}
686
687#[derive(Default)]
688struct PayloadCollector {
689    color: Option<LogColor>,
690    fields: LogFields,
691}
692
693impl<'kvs> log::kv::VisitSource<'kvs> for PayloadCollector {
694    fn visit_pair(
695        &mut self,
696        key: log::kv::Key<'kvs>,
697        value: log::kv::Value<'kvs>,
698    ) -> Result<(), log::kv::Error> {
699        match key.as_str() {
700            KV_COLOR => {
701                self.color = value.to_u64().map(|v| (v as u8).into());
702            }
703            KV_COMPONENT => {}
704            _ => {
705                self.fields
706                    .push((Ustr::from(key.as_str()), value.to_string()));
707            }
708        }
709        Ok(())
710    }
711}
712
713#[derive(Default)]
714struct FieldCollector {
715    color: Option<LogColor>,
716    component: Option<Ustr>,
717    fields: LogFields,
718}
719
720impl<'kvs> log::kv::VisitSource<'kvs> for FieldCollector {
721    fn visit_pair(
722        &mut self,
723        key: log::kv::Key<'kvs>,
724        value: log::kv::Value<'kvs>,
725    ) -> Result<(), log::kv::Error> {
726        match key.as_str() {
727            KV_COLOR => {
728                self.color = value.to_u64().map(|v| (v as u8).into());
729            }
730            KV_COMPONENT => {
731                self.component = Some(intern_component_value(&value));
732            }
733            _ => {
734                self.fields
735                    .push((Ustr::from(key.as_str()), value.to_string()));
736            }
737        }
738        Ok(())
739    }
740}
741
742impl Log for Logger {
743    fn enabled(&self, metadata: &log::Metadata) -> bool {
744        if LOGGING_BYPASSED.load(Ordering::Relaxed) {
745            return metadata.level() == Level::Error && shutdown_on_error().is_armed();
746        }
747
748        metadata.level() == Level::Error
749            || metadata.level() <= self.config.stdout_level
750            || metadata.level() <= self.config.fileout_level
751    }
752
753    fn log(&self, record: &log::Record) {
754        let level = record.level();
755
756        if LOGGING_BYPASSED.load(Ordering::Relaxed) {
757            if level == Level::Error {
758                record_shutdown_on_error(record);
759            }
760            return;
761        }
762
763        if self.enabled(record.metadata()) {
764            if let Some(filter_policy) = &self.filter_policy {
765                // Probe only the component before filtering. Filtered error logs still need
766                // enough payload to trigger shutdown-on-error.
767                let mut probe = ComponentProbe::default();
768                let _ = record.key_values().visit(&mut probe);
769                let component = probe
770                    .component
771                    .unwrap_or_else(|| intern_repeated(record.metadata().target()));
772
773                if filter_policy.should_skip(&component, level) {
774                    if level == Level::Error {
775                        shutdown_on_error().maybe_record_trigger(
776                            level,
777                            current_log_timestamp(),
778                            component,
779                            || format!("{}", record.args()),
780                        );
781                    }
782                    return;
783                }
784
785                let timestamp = current_log_timestamp();
786                let mut collector = PayloadCollector::default();
787                let _ = record.key_values().visit(&mut collector);
788                let color = collector.color.unwrap_or_else(|| level.into());
789
790                let line = LogLine {
791                    timestamp,
792                    level,
793                    color,
794                    component,
795                    message: format!("{}", record.args()),
796                    fields: collector.fields,
797                };
798
799                shutdown_on_error().maybe_record_trigger(
800                    line.level,
801                    line.timestamp,
802                    line.component,
803                    || line.message.clone(),
804                );
805                self.send_log_line(line);
806                return;
807            }
808
809            // With no component/module filters configured, keep the producer path to one KV visit.
810            let timestamp = current_log_timestamp();
811            let mut collector = FieldCollector::default();
812            let _ = record.key_values().visit(&mut collector);
813            let color = collector.color.unwrap_or_else(|| level.into());
814            let component = collector
815                .component
816                .unwrap_or_else(|| intern_repeated(record.metadata().target()));
817
818            let line = LogLine {
819                timestamp,
820                level,
821                color,
822                component,
823                message: format!("{}", record.args()),
824                fields: collector.fields,
825            };
826
827            shutdown_on_error().maybe_record_trigger(
828                line.level,
829                line.timestamp,
830                line.component,
831                || line.message.clone(),
832            );
833            self.send_log_line(line);
834        }
835    }
836
837    fn flush(&self) {
838        // Don't attempt to flush if we're already bypassed/shutdown
839        if LOGGING_BYPASSED.load(Ordering::Relaxed) {
840            return;
841        }
842
843        if let Err(e) = self.tx.send(LogEvent::Flush) {
844            eprintln!("Error sending flush log event: {e}");
845        }
846    }
847}
848
849fn record_shutdown_on_error(record: &log::Record) {
850    let mut probe = ComponentProbe::default();
851    let _ = record.key_values().visit(&mut probe);
852    let component = probe
853        .component
854        .unwrap_or_else(|| intern_repeated(record.metadata().target()));
855
856    shutdown_on_error().maybe_record_trigger(
857        record.level(),
858        current_log_timestamp(),
859        component,
860        || format!("{}", record.args()),
861    );
862}
863
864impl Logger {
865    /// Creates a logger instance for direct benchmark harnesses.
866    ///
867    /// This bypasses the global `log::set_logger` singleton so benchmark code can compare
868    /// multiple logger configurations in one process. It does not spawn a writer thread.
869    #[doc(hidden)]
870    #[must_use]
871    pub fn new_for_benchmark(config: LoggerConfig, tx: std::sync::mpsc::Sender<LogEvent>) -> Self {
872        let filter_policy = FilterPolicy::from_config(&config);
873
874        Self {
875            config,
876            filter_policy,
877            tx,
878        }
879    }
880
881    fn send_log_line(&self, line: LogLine) {
882        if let Err(SendError(LogEvent::Log(line))) = self.tx.send(LogEvent::Log(line)) {
883            eprintln!("Error sending log event (receiver closed): {line}");
884        }
885    }
886
887    /// Initializes the logger based on the `NAUTILUS_LOG` environment variable.
888    ///
889    /// # Errors
890    ///
891    /// Returns an error if reading the environment variable or parsing the configuration fails.
892    pub fn init_with_env(
893        trader_id: TraderId,
894        instance_id: UUID4,
895        file_config: FileWriterConfig,
896    ) -> anyhow::Result<LogGuard> {
897        let config = LoggerConfig::from_env()?;
898        Self::init_with_config(trader_id, instance_id, config, file_config)
899    }
900
901    /// Initializes the logger with the given configuration.
902    ///
903    /// # Errors
904    ///
905    /// Returns an error if the logger fails to register or initialize the background thread.
906    #[cfg_attr(
907        not(all(feature = "simulation", madsim)),
908        expect(clippy::needless_pass_by_value)
909    )]
910    pub fn init_with_config(
911        trader_id: TraderId,
912        instance_id: UUID4,
913        config: LoggerConfig,
914        file_config: FileWriterConfig,
915    ) -> anyhow::Result<LogGuard> {
916        let mut lifecycle = LOGGER_LIFECYCLE.lock();
917
918        match *lifecycle {
919            LoggerLifecycle::Running => {
920                return LogGuard::new_locked().ok_or_else(|| {
921                    anyhow::anyhow!(
922                        "Logging already initialized but new guard could not be created"
923                    )
924                });
925            }
926            LoggerLifecycle::Terminated => {
927                anyhow::bail!("Logging has been shut down and cannot be re-initialized");
928            }
929            LoggerLifecycle::Uninitialized => {}
930        }
931
932        let (tx, rx) = std::sync::mpsc::channel::<LogEvent>();
933        let filter_policy = FilterPolicy::from_config(&config);
934
935        #[cfg(not(all(feature = "simulation", madsim)))]
936        let handle = std::thread::Builder::new()
937            .name(LOGGING.to_string())
938            .spawn({
939                let config = config.clone();
940                let file_config = file_config.clone();
941                move || {
942                    Self::handle_messages(
943                        trader_id.to_string(),
944                        instance_id.to_string(),
945                        config,
946                        file_config,
947                        rx,
948                    );
949                }
950            })?;
951
952        let logger = Self {
953            config: config.clone(),
954            filter_policy,
955            tx: tx.clone(),
956        };
957
958        if let Err(e) = set_boxed_logger(Box::new(logger)) {
959            #[cfg(not(all(feature = "simulation", madsim)))]
960            {
961                let _ = tx.send(LogEvent::Close);
962                if handle.thread().id() != std::thread::current().id() {
963                    let _ = handle.join();
964                }
965            }
966            *lifecycle = LoggerLifecycle::Terminated;
967            return Err(e.into());
968        }
969
970        #[cfg(all(test, not(all(feature = "simulation", madsim))))]
971        if let Some(hook) = INIT_PUBLISH_HOOK.lock().take() {
972            let _ = hook.reached.send(());
973            let _ = hook.resume.recv();
974        }
975
976        // Store the sender globally so additional guards can be created
977        if let Err(tx) = LOGGER_TX.set(tx) {
978            #[cfg(not(all(feature = "simulation", madsim)))]
979            {
980                let _ = tx.send(LogEvent::Close);
981                if handle.thread().id() != std::thread::current().id() {
982                    let _ = handle.join();
983                }
984            }
985            drop(tx);
986            *lifecycle = LoggerLifecycle::Terminated;
987            anyhow::bail!("Global logging sender was already published");
988        }
989
990        if config.bypass_logging {
991            super::logging_set_bypass();
992        }
993
994        let is_colored = config.is_colored;
995
996        let print_config = config.print_config;
997        if print_config {
998            println!("STATIC_MAX_LEVEL={STATIC_MAX_LEVEL}");
999            println!("Logger initialized with {config:?} {file_config:?}");
1000        }
1001
1002        #[cfg(not(all(feature = "simulation", madsim)))]
1003        {
1004            // Store the handle globally
1005            let mut handle_guard = LOGGER_HANDLE.lock();
1006            debug_assert!(
1007                handle_guard.is_none(),
1008                "LOGGER_HANDLE already set - re-initialization not supported"
1009            );
1010            *handle_guard = Some(handle);
1011        }
1012
1013        #[cfg(all(feature = "simulation", madsim))]
1014        {
1015            // Under simulation, the background writer thread would escape the
1016            // madsim scheduler. Drop the receiver so the channel closes cleanly
1017            // and force the bypass flag so subsequent log calls no-op without
1018            // SendError noise.
1019            let _ = (trader_id, instance_id, config, file_config, rx);
1020            super::logging_set_bypass();
1021        }
1022
1023        let max_level = log::LevelFilter::Trace;
1024        set_max_level(max_level);
1025
1026        if print_config {
1027            println!("Logger set as `log` implementation with max level {max_level}");
1028        }
1029
1030        super::LOGGING_INITIALIZED.store(true, Ordering::SeqCst);
1031        super::LOGGING_COLORED.store(is_colored, Ordering::SeqCst);
1032        *lifecycle = LoggerLifecycle::Running;
1033
1034        LogGuard::new_locked()
1035            .ok_or_else(|| anyhow::anyhow!("Failed to create LogGuard from global sender"))
1036    }
1037
1038    #[cfg(not(all(feature = "simulation", madsim)))]
1039    #[expect(clippy::needless_pass_by_value)]
1040    fn handle_messages(
1041        trader_id: String,
1042        instance_id: String,
1043        config: LoggerConfig,
1044        file_config: FileWriterConfig,
1045        rx: std::sync::mpsc::Receiver<LogEvent>,
1046    ) {
1047        let LoggerConfig {
1048            stdout_level,
1049            fileout_level,
1050            component_level: _,
1051            module_level: _,
1052            log_components_only: _,
1053            is_colored,
1054            print_config: _,
1055            use_tracing: _,
1056            bypass_logging: _,
1057            file_config: _,
1058            clear_log_file,
1059            fileout_sync_on_flush,
1060            buffered_stdout,
1061        } = config;
1062
1063        let trader_id_cache = Ustr::from(&trader_id);
1064
1065        // Set up std I/O buffers
1066        let mut stdout_writer = StdoutWriter::new(stdout_level, is_colored, buffered_stdout);
1067        let mut stderr_writer = StderrWriter::new(is_colored);
1068
1069        // Conditionally create file writer based on fileout_level
1070        let mut file_writer_opt = if fileout_level == LevelFilter::Off {
1071            None
1072        } else {
1073            FileWriter::new(
1074                trader_id,
1075                instance_id,
1076                file_config,
1077                fileout_level,
1078                clear_log_file,
1079                fileout_sync_on_flush,
1080            )
1081        };
1082
1083        let process_event = |event: LogEvent,
1084                             stdout_writer: &mut StdoutWriter,
1085                             stderr_writer: &mut StderrWriter,
1086                             file_writer_opt: &mut Option<FileWriter>| {
1087            match event {
1088                LogEvent::Log(line) => {
1089                    let mut wrapper = LogLineWrapper::new(line, trader_id_cache);
1090
1091                    if stderr_writer.enabled(&wrapper.line) {
1092                        if is_colored {
1093                            stderr_writer.write(wrapper.get_colored());
1094                        } else {
1095                            stderr_writer.write(wrapper.get_string());
1096                        }
1097                    }
1098
1099                    if stdout_writer.enabled(&wrapper.line) {
1100                        if is_colored {
1101                            stdout_writer.write(wrapper.get_colored());
1102                        } else {
1103                            stdout_writer.write(wrapper.get_string());
1104                        }
1105                    }
1106
1107                    if let Some(file_writer) = file_writer_opt
1108                        && file_writer.enabled(&wrapper.line)
1109                    {
1110                        if file_writer.json_format {
1111                            file_writer.write(&wrapper.get_json());
1112                        } else {
1113                            file_writer.write(wrapper.get_string());
1114                        }
1115                    }
1116                }
1117                LogEvent::Flush => {
1118                    stdout_writer.flush();
1119                    stderr_writer.flush();
1120
1121                    if let Some(file_writer) = file_writer_opt {
1122                        file_writer.flush();
1123                    }
1124                }
1125                LogEvent::Sync(done) => {
1126                    stdout_writer.flush();
1127                    stderr_writer.flush();
1128
1129                    let result = if let Some(file_writer) = file_writer_opt {
1130                        file_writer.flush_and_sync().map_err(anyhow::Error::from)
1131                    } else {
1132                        Ok(())
1133                    };
1134
1135                    let _ = done.send(result);
1136                }
1137                LogEvent::Close => {
1138                    // Close handled in the main loop; ignore here.
1139                }
1140            }
1141        };
1142
1143        // Continue to receive and handle log events until channel is hung up
1144        while let Ok(event) = rx.recv() {
1145            match event {
1146                LogEvent::Log(_) | LogEvent::Flush | LogEvent::Sync(_) => process_event(
1147                    event,
1148                    &mut stdout_writer,
1149                    &mut stderr_writer,
1150                    &mut file_writer_opt,
1151                ),
1152                LogEvent::Close => {
1153                    // First flush what's been written so far
1154                    stdout_writer.flush();
1155                    stderr_writer.flush();
1156
1157                    if let Some(ref mut file_writer) = file_writer_opt {
1158                        file_writer.flush();
1159                    }
1160
1161                    // Drain any remaining events that may have raced with shutdown
1162                    // This ensures logs enqueued just before/around shutdown aren't lost.
1163                    while let Ok(evt) = rx.try_recv() {
1164                        match evt {
1165                            LogEvent::Close => (), // ignore extra Close events
1166                            _ => process_event(
1167                                evt,
1168                                &mut stdout_writer,
1169                                &mut stderr_writer,
1170                                &mut file_writer_opt,
1171                            ),
1172                        }
1173                    }
1174
1175                    // Final flush after draining
1176                    stdout_writer.flush();
1177                    stderr_writer.flush();
1178
1179                    if let Some(ref mut file_writer) = file_writer_opt {
1180                        file_writer.flush_and_sync_logged();
1181                    }
1182
1183                    break;
1184                }
1185            }
1186        }
1187    }
1188}
1189
1190/// Determines if a log line should be filtered out based on module and component filters.
1191///
1192/// Returns `true` if the line should be skipped (filtered out), `false` if it should be logged.
1193///
1194/// The `module_filters_sorted` slice must be pre-sorted by descending path length so the
1195/// first `starts_with` match is the longest prefix.
1196#[must_use]
1197pub fn should_filter_log(
1198    component: &Ustr,
1199    line_level: log::Level,
1200    module_filters_sorted: &[(Ustr, LevelFilter)],
1201    component_level: &AHashMap<Ustr, LevelFilter>,
1202    log_components_only: bool,
1203) -> bool {
1204    should_filter_log_inner(
1205        component,
1206        line_level,
1207        module_filters_sorted,
1208        component_level,
1209        log_components_only,
1210    )
1211}
1212
1213fn should_filter_log_inner(
1214    component: &Ustr,
1215    line_level: log::Level,
1216    module_filters_sorted: &[(Ustr, LevelFilter)],
1217    component_level: &AHashMap<Ustr, LevelFilter>,
1218    log_components_only: bool,
1219) -> bool {
1220    if module_filters_sorted.is_empty() && component_level.is_empty() {
1221        return log_components_only;
1222    }
1223
1224    // Module filter: first match in sorted list is longest prefix
1225    let module_filter = module_filters_sorted
1226        .iter()
1227        .find(|(path, _)| component.starts_with(path.as_str()))
1228        .map(|(_, level)| *level);
1229
1230    let component_filter = component_level.get(component).copied();
1231
1232    if log_components_only && module_filter.is_none() && component_filter.is_none() {
1233        return true;
1234    }
1235
1236    // Module filter takes precedence over component filter
1237    module_filter
1238        .or(component_filter)
1239        .is_some_and(|filter_level| line_level > filter_level)
1240}
1241
1242/// Gracefully shuts down the logging subsystem.
1243///
1244/// This is the sole terminal lifecycle operation. It prevents further logging, closes and joins
1245/// the writer thread, and prevents subsequent logger initialization.
1246///
1247/// # Safety
1248///
1249/// Safe to call multiple times. Thread join is skipped if called from the logging thread.
1250pub(crate) fn shutdown_graceful() {
1251    let mut lifecycle = LOGGER_LIFECYCLE.lock();
1252
1253    if *lifecycle == LoggerLifecycle::Terminated {
1254        return;
1255    }
1256
1257    // Prevent further logging
1258    LOGGING_BYPASSED.store(true, Ordering::SeqCst);
1259    log::set_max_level(log::LevelFilter::Off);
1260
1261    // Signal Close if the sender exists
1262    #[cfg(not(all(feature = "simulation", madsim)))]
1263    if let Some(tx) = LOGGER_TX.get() {
1264        let _ = tx.send(LogEvent::Close);
1265    }
1266
1267    if let Some(handle) = LOGGER_HANDLE.lock().take()
1268        && handle.thread().id() != std::thread::current().id()
1269    {
1270        let _ = handle.join();
1271    }
1272
1273    LOGGING_INITIALIZED.store(false, Ordering::SeqCst);
1274    *lifecycle = LoggerLifecycle::Terminated;
1275}
1276
1277/// Returns whether the process-global logger is running.
1278pub(crate) fn is_running() -> bool {
1279    *LOGGER_LIFECYCLE.lock() == LoggerLifecycle::Running
1280}
1281
1282/// Flushes and syncs file logs to disk through the logging thread.
1283///
1284/// This is a no-op when logging is not initialized or file logging is disabled.
1285///
1286/// # Errors
1287///
1288/// Returns an error if the sync request cannot be delivered or acknowledged.
1289pub fn sync_to_disk() -> anyhow::Result<()> {
1290    #[cfg(all(feature = "simulation", madsim))]
1291    {
1292        Ok(())
1293    }
1294
1295    #[cfg(not(all(feature = "simulation", madsim)))]
1296    {
1297        let lifecycle = LOGGER_LIFECYCLE.lock();
1298
1299        if *lifecycle != LoggerLifecycle::Running {
1300            return Ok(());
1301        }
1302
1303        let Some(tx) = LOGGER_TX.get() else {
1304            anyhow::bail!("Logging is running without a published sender");
1305        };
1306
1307        sync_sender_to_disk(tx)
1308    }
1309}
1310
1311#[cfg(not(all(feature = "simulation", madsim)))]
1312fn sync_sender_to_disk(tx: &std::sync::mpsc::Sender<LogEvent>) -> anyhow::Result<()> {
1313    let (done_tx, done_rx) = std::sync::mpsc::channel();
1314    tx.send(LogEvent::Sync(done_tx))
1315        .map_err(|e| anyhow::anyhow!("failed to request logging sync: {e}"))?;
1316
1317    done_rx
1318        .recv()
1319        .map_err(|e| anyhow::anyhow!("failed to receive logging sync acknowledgement: {e}"))?
1320}
1321
1322/// Logs a message with the given level, color, and component.
1323pub fn log<T: AsRef<str>>(level: LogLevel, color: LogColor, component: Ustr, message: T) {
1324    let color = Value::from(color as u8);
1325
1326    match level {
1327        LogLevel::Off => {}
1328        LogLevel::Trace => {
1329            log::trace!(component = component.to_value(), color = color; "{}", message.as_ref());
1330        }
1331        LogLevel::Debug => {
1332            log::debug!(component = component.to_value(), color = color; "{}", message.as_ref());
1333        }
1334        LogLevel::Info => {
1335            log::info!(component = component.to_value(), color = color; "{}", message.as_ref());
1336        }
1337        LogLevel::Warning => {
1338            log::warn!(component = component.to_value(), color = color; "{}", message.as_ref());
1339        }
1340        LogLevel::Error => {
1341            log::error!(component = component.to_value(), color = color; "{}", message.as_ref());
1342        }
1343    }
1344}
1345
1346/// A guard that manages the lifecycle of the logging subsystem.
1347///
1348/// `LogGuard` tracks active users of the process-global logging subsystem. Dropping the last guard
1349/// synchronously flushes and syncs pending file logs, but leaves the logging thread running so a
1350/// later initialization can acquire a valid guard. Only [`crate::logging::logging_shutdown`]
1351/// permanently terminates the logging thread.
1352///
1353/// # Reference Counting
1354///
1355/// The logging system maintains a global atomic counter of active `LogGuard` instances. This
1356/// ensures that:
1357/// - The logging thread remains active for the process lifetime, including while no guards exist.
1358/// - Pending log messages are flushed when intermediate guards are dropped.
1359/// - Pending file logs are synchronously flushed and synced when the last guard is dropped.
1360///
1361/// # Shutdown Behavior
1362///
1363/// Call [`crate::logging::logging_shutdown`] for terminal shutdown. After shutdown, no new guards
1364/// can be acquired and the logger cannot be re-initialized.
1365///
1366/// **Python on Windows:** Non-deterministic GC order during interpreter shutdown can
1367/// occasionally prevent proper thread join, resulting in truncated logs.
1368///
1369/// # Limits
1370///
1371/// The system supports a maximum of 255 concurrent `LogGuard` instances.
1372#[cfg_attr(feature = "python", pyo3::pyclass(module = "nautilus_trader.common"))]
1373#[cfg_attr(
1374    feature = "python",
1375    pyo3_stub_gen::derive::gen_stub_pyclass(module = "nautilus_trader.common")
1376)]
1377#[derive(Debug)]
1378pub struct LogGuard {
1379    #[cfg(not(all(feature = "simulation", madsim)))]
1380    tx: std::sync::mpsc::Sender<LogEvent>,
1381}
1382
1383impl LogGuard {
1384    /// Creates a new [`LogGuard`] instance from the global logger.
1385    ///
1386    /// Returns `None` if logging has not been initialized or the active `LogGuard`
1387    /// count would exceed 255.
1388    #[must_use]
1389    pub fn new() -> Option<Self> {
1390        let lifecycle = LOGGER_LIFECYCLE.lock();
1391
1392        Self::new_from_lifecycle(&lifecycle)
1393    }
1394
1395    fn new_from_lifecycle(lifecycle: &LoggerLifecycle) -> Option<Self> {
1396        if *lifecycle != LoggerLifecycle::Running {
1397            return None;
1398        }
1399
1400        Self::new_locked()
1401    }
1402
1403    #[cfg(all(test, not(all(feature = "simulation", madsim))))]
1404    fn try_new_for_test() -> TestGuardAcquire {
1405        match LOGGER_LIFECYCLE.try_lock() {
1406            Some(lifecycle) => TestGuardAcquire::Acquired(Self::new_from_lifecycle(&lifecycle)),
1407            None => TestGuardAcquire::LifecycleBusy,
1408        }
1409    }
1410
1411    fn new_locked() -> Option<Self> {
1412        #[cfg(not(all(feature = "simulation", madsim)))]
1413        let tx = LOGGER_TX.get()?;
1414        #[cfg(all(feature = "simulation", madsim))]
1415        LOGGER_TX.get()?;
1416        LOGGING_GUARDS_ACTIVE
1417            .try_update(Ordering::SeqCst, Ordering::SeqCst, |count| {
1418                if count == u8::MAX {
1419                    None
1420                } else {
1421                    Some(count + 1)
1422                }
1423            })
1424            .ok()?;
1425
1426        Some(Self {
1427            #[cfg(not(all(feature = "simulation", madsim)))]
1428            tx: tx.clone(),
1429        })
1430    }
1431}
1432
1433impl Drop for LogGuard {
1434    /// Handles cleanup when a `LogGuard` is dropped.
1435    ///
1436    /// Sends `Flush` if other guards remain active. The last guard synchronously flushes and syncs
1437    /// file output while leaving the process-global logging thread running.
1438    fn drop(&mut self) {
1439        let lifecycle = LOGGER_LIFECYCLE.lock();
1440        let previous_count = LOGGING_GUARDS_ACTIVE
1441            .try_update(Ordering::SeqCst, Ordering::SeqCst, |count| {
1442                assert!(count != 0, "LogGuard reference count underflow");
1443                Some(count - 1)
1444            })
1445            .expect("Failed to decrement LogGuard count");
1446
1447        if *lifecycle != LoggerLifecycle::Running {
1448            return;
1449        }
1450
1451        #[cfg(all(feature = "simulation", madsim))]
1452        let _ = previous_count;
1453
1454        #[cfg(not(all(feature = "simulation", madsim)))]
1455        if previous_count == 1 {
1456            if let Err(e) = sync_sender_to_disk(&self.tx) {
1457                eprintln!("Error syncing logs after dropping the last LogGuard: {e}");
1458            }
1459        } else {
1460            // Other LogGuards are still active, just flush our logs
1461            let _ = self.tx.send(LogEvent::Flush);
1462        }
1463    }
1464}
1465
1466#[cfg(test)]
1467mod tests {
1468    use ahash::AHashMap;
1469    use log::LevelFilter;
1470    use nautilus_core::UUID4;
1471    use nautilus_model::identifiers::TraderId;
1472    use rstest::*;
1473    use serde_json::Value;
1474    use tempfile::tempdir;
1475    use ustr::Ustr;
1476
1477    use super::*;
1478    use crate::enums::LogColor;
1479
1480    #[rstest]
1481    fn log_message_serialization() {
1482        let log_message = LogLine {
1483            timestamp: UnixNanos::default(),
1484            level: log::Level::Info,
1485            color: LogColor::Normal,
1486            component: Ustr::from("Portfolio"),
1487            message: "This is a log message".to_string(),
1488            fields: SmallVec::new(),
1489        };
1490
1491        let serialized_json = serde_json::to_string(&log_message).unwrap();
1492        let deserialized_value: Value = serde_json::from_str(&serialized_json).unwrap();
1493
1494        assert_eq!(deserialized_value["level"], "INFO");
1495        assert_eq!(deserialized_value["component"], "Portfolio");
1496        assert_eq!(deserialized_value["message"], "This is a log message");
1497    }
1498
1499    #[rstest]
1500    fn log_config_parsing() {
1501        let config =
1502            LoggerConfig::from_spec("stdout=Info;is_colored;fileout=Debug;RiskEngine=Error")
1503                .unwrap();
1504        assert_eq!(
1505            config,
1506            LoggerConfig {
1507                stdout_level: LevelFilter::Info,
1508                fileout_level: LevelFilter::Debug,
1509                component_level: AHashMap::from_iter(vec![(
1510                    Ustr::from("RiskEngine"),
1511                    LevelFilter::Error
1512                )]),
1513                module_level: AHashMap::new(),
1514                log_components_only: false,
1515                is_colored: true,
1516                print_config: false,
1517                use_tracing: false,
1518                ..Default::default()
1519            }
1520        );
1521    }
1522
1523    #[rstest]
1524    fn log_config_parsing2() {
1525        let config = LoggerConfig::from_spec("stdout=Warn;print_config;fileout=Error;").unwrap();
1526        assert_eq!(
1527            config,
1528            LoggerConfig {
1529                stdout_level: LevelFilter::Warn,
1530                fileout_level: LevelFilter::Error,
1531                component_level: AHashMap::new(),
1532                module_level: AHashMap::new(),
1533                log_components_only: false,
1534                is_colored: true,
1535                print_config: true,
1536                use_tracing: false,
1537                ..Default::default()
1538            }
1539        );
1540    }
1541
1542    #[rstest]
1543    fn log_config_parsing_with_log_components_only() {
1544        let config =
1545            LoggerConfig::from_spec("stdout=Info;log_components_only;RiskEngine=Debug").unwrap();
1546        assert_eq!(
1547            config,
1548            LoggerConfig {
1549                stdout_level: LevelFilter::Info,
1550                fileout_level: LevelFilter::Off,
1551                component_level: AHashMap::from_iter(vec![(
1552                    Ustr::from("RiskEngine"),
1553                    LevelFilter::Debug
1554                )]),
1555                module_level: AHashMap::new(),
1556                log_components_only: true,
1557                is_colored: true,
1558                print_config: false,
1559                use_tracing: false,
1560                ..Default::default()
1561            }
1562        );
1563    }
1564
1565    #[rstest]
1566    fn test_log_line_wrapper_plain_string() {
1567        let line = LogLine {
1568            timestamp: 1_650_000_000_000_000_000.into(),
1569            level: log::Level::Info,
1570            color: LogColor::Normal,
1571            component: Ustr::from("TestComponent"),
1572            message: "Test message".to_string(),
1573            fields: SmallVec::new(),
1574        };
1575
1576        let mut wrapper = LogLineWrapper::new(line, Ustr::from("TRADER-001"));
1577        let result = wrapper.get_string();
1578
1579        assert!(result.contains("TRADER-001"));
1580        assert!(result.contains("TestComponent"));
1581        assert!(result.contains("Test message"));
1582        assert!(result.contains("[INFO]"));
1583        assert!(result.ends_with('\n'));
1584        // Should NOT contain ANSI codes
1585        assert!(!result.contains("\x1b["));
1586    }
1587
1588    #[rstest]
1589    fn test_log_line_wrapper_colored_string() {
1590        let line = LogLine {
1591            timestamp: 1_650_000_000_000_000_000.into(),
1592            level: log::Level::Info,
1593            color: LogColor::Green,
1594            component: Ustr::from("TestComponent"),
1595            message: "Test message".to_string(),
1596            fields: SmallVec::new(),
1597        };
1598
1599        let mut wrapper = LogLineWrapper::new(line, Ustr::from("TRADER-001"));
1600        let result = wrapper.get_colored();
1601
1602        assert!(result.contains("TRADER-001"));
1603        assert!(result.contains("TestComponent"));
1604        assert!(result.contains("Test message"));
1605        // Should contain ANSI codes
1606        assert!(result.contains("\x1b["));
1607        assert!(result.ends_with('\n'));
1608    }
1609
1610    #[rstest]
1611    fn test_log_line_wrapper_json_output() {
1612        let line = LogLine {
1613            timestamp: 1_650_000_000_000_000_000.into(),
1614            level: log::Level::Warn,
1615            color: LogColor::Yellow,
1616            component: Ustr::from("RiskEngine"),
1617            message: "Warning message".to_string(),
1618            fields: SmallVec::new(),
1619        };
1620
1621        let wrapper = LogLineWrapper::new(line, Ustr::from("TRADER-002"));
1622        let json = wrapper.get_json();
1623
1624        let parsed: Value = serde_json::from_str(json.trim()).unwrap();
1625        assert_eq!(parsed["trader_id"], "TRADER-002");
1626        assert_eq!(parsed["component"], "RiskEngine");
1627        assert_eq!(parsed["message"], "Warning message");
1628        assert_eq!(parsed["level"], "WARN");
1629        assert_eq!(parsed["color"], "YELLOW");
1630    }
1631
1632    #[rstest]
1633    fn test_log_line_wrapper_caches_string() {
1634        let line = LogLine {
1635            timestamp: 1_650_000_000_000_000_000.into(),
1636            level: log::Level::Info,
1637            color: LogColor::Normal,
1638            component: Ustr::from("Test"),
1639            message: "Cached".to_string(),
1640            fields: SmallVec::new(),
1641        };
1642
1643        let mut wrapper = LogLineWrapper::new(line, Ustr::from("TRADER"));
1644        let first = wrapper.get_string().to_string();
1645        let second = wrapper.get_string().to_string();
1646
1647        assert_eq!(first, second);
1648    }
1649
1650    #[rstest]
1651    fn test_log_line_display() {
1652        let line = LogLine {
1653            timestamp: 0.into(),
1654            level: log::Level::Error,
1655            color: LogColor::Red,
1656            component: Ustr::from("Component"),
1657            message: "Error occurred".to_string(),
1658            fields: SmallVec::new(),
1659        };
1660
1661        let display = format!("{line}");
1662        assert_eq!(display, "[ERROR] Component: Error occurred");
1663    }
1664
1665    #[rstest]
1666    fn test_log_line_display_with_fields() {
1667        let line = LogLine {
1668            timestamp: 0.into(),
1669            level: log::Level::Info,
1670            color: LogColor::Normal,
1671            component: Ustr::from("RiskEngine"),
1672            message: "Order filled".to_string(),
1673            fields: smallvec::smallvec![
1674                (Ustr::from("venue"), "BINANCE".to_string()),
1675                (Ustr::from("order_id"), "O-001".to_string()),
1676            ],
1677        };
1678
1679        let display = format!("{line}");
1680        assert_eq!(
1681            display,
1682            "[INFO] RiskEngine: Order filled venue=BINANCE order_id=O-001"
1683        );
1684    }
1685
1686    #[rstest]
1687    fn test_log_line_wrapper_plain_string_with_fields() {
1688        let line = LogLine {
1689            timestamp: 1_650_000_000_000_000_000.into(),
1690            level: log::Level::Info,
1691            color: LogColor::Normal,
1692            component: Ustr::from("DataEngine"),
1693            message: "Connected".to_string(),
1694            fields: smallvec::smallvec![
1695                (Ustr::from("venue"), "BINANCE".to_string()),
1696                (Ustr::from("product_type"), "SPOT".to_string()),
1697            ],
1698        };
1699
1700        let mut wrapper = LogLineWrapper::new(line, Ustr::from("TRADER-001"));
1701        let result = wrapper.get_string();
1702
1703        assert!(result.contains("Connected"));
1704        assert!(result.contains("venue=BINANCE"));
1705        assert!(result.contains("product_type=SPOT"));
1706        assert!(result.ends_with('\n'));
1707        assert!(!result.contains("\x1b["));
1708    }
1709
1710    #[rstest]
1711    fn test_log_line_wrapper_json_with_fields() {
1712        let line = LogLine {
1713            timestamp: 1_650_000_000_000_000_000.into(),
1714            level: log::Level::Info,
1715            color: LogColor::Normal,
1716            component: Ustr::from("RiskEngine"),
1717            message: "Order filled".to_string(),
1718            fields: smallvec::smallvec![
1719                (Ustr::from("strategy_id"), "S-001".to_string()),
1720                (Ustr::from("venue"), "BINANCE".to_string()),
1721            ],
1722        };
1723
1724        let wrapper = LogLineWrapper::new(line, Ustr::from("TRADER-001"));
1725        let json = wrapper.get_json();
1726
1727        let parsed: Value = serde_json::from_str(json.trim()).unwrap();
1728        assert_eq!(parsed["component"], "RiskEngine");
1729        assert_eq!(parsed["message"], "Order filled");
1730        assert_eq!(parsed["strategy_id"], "S-001");
1731        assert_eq!(parsed["venue"], "BINANCE");
1732    }
1733
1734    #[rstest]
1735    fn test_log_line_wrapper_json_no_fields_has_no_extra_keys() {
1736        let line = LogLine {
1737            timestamp: 1_650_000_000_000_000_000.into(),
1738            level: log::Level::Info,
1739            color: LogColor::Normal,
1740            component: Ustr::from("Test"),
1741            message: "Simple".to_string(),
1742            fields: SmallVec::new(),
1743        };
1744
1745        let wrapper = LogLineWrapper::new(line, Ustr::from("TRADER-001"));
1746        let json = wrapper.get_json();
1747
1748        let parsed: Value = serde_json::from_str(json.trim()).unwrap();
1749        let obj = parsed.as_object().unwrap();
1750        assert_eq!(obj.len(), 6); // timestamp, trader_id, level, color, component, message
1751    }
1752
1753    #[rstest]
1754    fn test_log_line_wrapper_json_reserved_keys_not_overwritten() {
1755        let line = LogLine {
1756            timestamp: 1_650_000_000_000_000_000.into(),
1757            level: log::Level::Warn,
1758            color: LogColor::Normal,
1759            component: Ustr::from("Test"),
1760            message: "Real message".to_string(),
1761            fields: smallvec::smallvec![
1762                (Ustr::from("level"), "FAKE".to_string()),
1763                (Ustr::from("message"), "injected".to_string()),
1764                (Ustr::from("timestamp"), "bogus".to_string()),
1765                (Ustr::from("venue"), "BINANCE".to_string()),
1766            ],
1767        };
1768
1769        let wrapper = LogLineWrapper::new(line, Ustr::from("TRADER-001"));
1770        let json = wrapper.get_json();
1771        let parsed: Value = serde_json::from_str(json.trim()).unwrap();
1772
1773        assert_eq!(parsed["level"], "WARN");
1774        assert_eq!(parsed["message"], "Real message");
1775        assert_ne!(parsed["timestamp"], "bogus");
1776        assert_eq!(parsed["venue"], "BINANCE");
1777    }
1778
1779    #[rstest]
1780    fn test_log_line_wrapper_json_duplicate_extra_fields_last_value_wins() {
1781        let line = LogLine {
1782            timestamp: 1_650_000_000_000_000_000.into(),
1783            level: log::Level::Info,
1784            color: LogColor::Normal,
1785            component: Ustr::from("Test"),
1786            message: "Duplicate field".to_string(),
1787            fields: smallvec::smallvec![
1788                (Ustr::from("venue"), "BINANCE".to_string()),
1789                (Ustr::from("venue"), "OKX".to_string()),
1790            ],
1791        };
1792
1793        let wrapper = LogLineWrapper::new(line, Ustr::from("TRADER-001"));
1794        let json = wrapper.get_json();
1795        let parsed: Value = serde_json::from_str(json.trim()).unwrap();
1796
1797        assert_eq!(json.matches("\"venue\"").count(), 1);
1798        assert_eq!(parsed["venue"], "OKX");
1799    }
1800
1801    /// Helper to convert module level map to sorted vec (descending by path length)
1802    fn sorted_module_filters(map: AHashMap<Ustr, LevelFilter>) -> Vec<(Ustr, LevelFilter)> {
1803        let mut v: Vec<_> = map.into_iter().collect();
1804        v.sort_by_key(|b| std::cmp::Reverse(b.0.len()));
1805        v
1806    }
1807
1808    #[rstest]
1809    fn test_filter_no_filters_passes_all() {
1810        let module_filters = vec![];
1811        let component_level = AHashMap::new();
1812
1813        assert!(!should_filter_log(
1814            &Ustr::from("anything"),
1815            Level::Trace,
1816            &module_filters,
1817            &component_level,
1818            false
1819        ));
1820    }
1821
1822    #[rstest]
1823    fn test_filter_component_exact_match() {
1824        let module_filters = vec![];
1825        let component_level = AHashMap::from_iter([(Ustr::from("RiskEngine"), LevelFilter::Error)]);
1826
1827        assert!(should_filter_log(
1828            &Ustr::from("RiskEngine"),
1829            Level::Info,
1830            &module_filters,
1831            &component_level,
1832            false
1833        ));
1834        assert!(!should_filter_log(
1835            &Ustr::from("RiskEngine"),
1836            Level::Error,
1837            &module_filters,
1838            &component_level,
1839            false
1840        ));
1841        assert!(!should_filter_log(
1842            &Ustr::from("Portfolio"),
1843            Level::Info,
1844            &module_filters,
1845            &component_level,
1846            false
1847        ));
1848    }
1849
1850    #[rstest]
1851    fn test_filter_module_prefix_match() {
1852        let module_filters = vec![(Ustr::from("nautilus_okx::websocket"), LevelFilter::Debug)];
1853        let component_level = AHashMap::new();
1854
1855        assert!(!should_filter_log(
1856            &Ustr::from("nautilus_okx::websocket"),
1857            Level::Debug,
1858            &module_filters,
1859            &component_level,
1860            false
1861        ));
1862        assert!(!should_filter_log(
1863            &Ustr::from("nautilus_okx::websocket::handler"),
1864            Level::Debug,
1865            &module_filters,
1866            &component_level,
1867            false
1868        ));
1869        assert!(should_filter_log(
1870            &Ustr::from("nautilus_okx::websocket::handler"),
1871            Level::Trace,
1872            &module_filters,
1873            &component_level,
1874            false
1875        ));
1876        assert!(!should_filter_log(
1877            &Ustr::from("nautilus_binance::data"),
1878            Level::Trace,
1879            &module_filters,
1880            &component_level,
1881            false
1882        ));
1883    }
1884
1885    #[rstest]
1886    fn test_filter_longest_prefix_wins() {
1887        let module_filters = sorted_module_filters(AHashMap::from_iter([
1888            (Ustr::from("nautilus_okx"), LevelFilter::Error),
1889            (Ustr::from("nautilus_okx::websocket"), LevelFilter::Debug),
1890        ]));
1891        let component_level = AHashMap::new();
1892
1893        assert!(!should_filter_log(
1894            &Ustr::from("nautilus_okx::websocket::handler"),
1895            Level::Debug,
1896            &module_filters,
1897            &component_level,
1898            false
1899        ));
1900        assert!(should_filter_log(
1901            &Ustr::from("nautilus_okx::data"),
1902            Level::Debug,
1903            &module_filters,
1904            &component_level,
1905            false
1906        ));
1907        assert!(!should_filter_log(
1908            &Ustr::from("nautilus_okx::data"),
1909            Level::Error,
1910            &module_filters,
1911            &component_level,
1912            false
1913        ));
1914    }
1915
1916    #[rstest]
1917    fn test_filter_module_precedence_over_component() {
1918        let module_filters = vec![(Ustr::from("nautilus_okx::websocket"), LevelFilter::Debug)];
1919        let component_level =
1920            AHashMap::from_iter([(Ustr::from("nautilus_okx::websocket"), LevelFilter::Error)]);
1921
1922        assert!(!should_filter_log(
1923            &Ustr::from("nautilus_okx::websocket"),
1924            Level::Debug,
1925            &module_filters,
1926            &component_level,
1927            false
1928        ));
1929    }
1930
1931    #[rstest]
1932    fn test_filter_log_components_only_blocks_unknown() {
1933        let module_filters = vec![];
1934        let component_level = AHashMap::from_iter([(Ustr::from("RiskEngine"), LevelFilter::Debug)]);
1935
1936        assert!(should_filter_log(
1937            &Ustr::from("Portfolio"),
1938            Level::Info,
1939            &module_filters,
1940            &component_level,
1941            true
1942        ));
1943        assert!(!should_filter_log(
1944            &Ustr::from("RiskEngine"),
1945            Level::Info,
1946            &module_filters,
1947            &component_level,
1948            true
1949        ));
1950    }
1951
1952    #[rstest]
1953    fn test_filter_log_components_only_with_module() {
1954        let module_filters = vec![(Ustr::from("nautilus_okx"), LevelFilter::Debug)];
1955        let component_level = AHashMap::new();
1956
1957        assert!(!should_filter_log(
1958            &Ustr::from("nautilus_okx::websocket"),
1959            Level::Debug,
1960            &module_filters,
1961            &component_level,
1962            true
1963        ));
1964        assert!(should_filter_log(
1965            &Ustr::from("nautilus_binance::data"),
1966            Level::Debug,
1967            &module_filters,
1968            &component_level,
1969            true
1970        ));
1971    }
1972
1973    #[rstest]
1974    fn test_filter_level_comparison() {
1975        let module_filters = vec![];
1976        let component_level = AHashMap::from_iter([(Ustr::from("Test"), LevelFilter::Warn)]);
1977
1978        assert!(!should_filter_log(
1979            &Ustr::from("Test"),
1980            Level::Error,
1981            &module_filters,
1982            &component_level,
1983            false
1984        ));
1985        assert!(!should_filter_log(
1986            &Ustr::from("Test"),
1987            Level::Warn,
1988            &module_filters,
1989            &component_level,
1990            false
1991        ));
1992        assert!(should_filter_log(
1993            &Ustr::from("Test"),
1994            Level::Info,
1995            &module_filters,
1996            &component_level,
1997            false
1998        ));
1999        assert!(should_filter_log(
2000            &Ustr::from("Test"),
2001            Level::Debug,
2002            &module_filters,
2003            &component_level,
2004            false
2005        ));
2006        assert!(should_filter_log(
2007            &Ustr::from("Test"),
2008            Level::Trace,
2009            &module_filters,
2010            &component_level,
2011            false
2012        ));
2013    }
2014
2015    // These tests use global logging state (one logger per process).
2016    // They run correctly with cargo-nextest which isolates each test in its own process.
2017    //
2018    // Gated out under `cfg(madsim)`: every test here drives the file-logging writer
2019    // thread, which is itself gated out under simulation (see `Logger::init_with_config`),
2020    // so log events are dropped and these tests would either hang on `wait_until` or
2021    // assert against an empty log file. Logging is outside the determinism contract.
2022    #[cfg(not(all(feature = "simulation", madsim)))]
2023    mod serial_tests {
2024        use std::{sync::atomic::Ordering, time::Duration};
2025
2026        use super::*;
2027        use crate::{
2028            logging::{
2029                LOGGING_BYPASSED, logging_clock_set_static_mode, logging_clock_set_static_time,
2030                logging_is_initialized, logging_set_bypass, logging_sync_to_disk,
2031            },
2032            testing::wait_until,
2033        };
2034
2035        #[rstest]
2036        fn test_shutdown_on_error_records_once_then_rearms() {
2037            disarm_shutdown_on_error();
2038
2039            let (tx, _rx) = std::sync::mpsc::channel();
2040            let logger = Logger::new_for_benchmark(LoggerConfig::default(), tx);
2041
2042            arm_shutdown_on_error(false);
2043            let args = format_args!("Disabled error");
2044            let record = log::Record::builder()
2045                .args(args)
2046                .level(Level::Error)
2047                .target("RunComponent")
2048                .build();
2049            log::Log::log(&logger, &record);
2050            assert_eq!(take_shutdown_on_error_trigger(), None);
2051
2052            arm_shutdown_on_error(true);
2053            let args = format_args!("First error");
2054            let record = log::Record::builder()
2055                .args(args)
2056                .level(Level::Error)
2057                .target("RunComponent")
2058                .build();
2059            log::Log::log(&logger, &record);
2060
2061            let args = format_args!("Second error");
2062            let record = log::Record::builder()
2063                .args(args)
2064                .level(Level::Error)
2065                .target("RunComponent")
2066                .build();
2067            log::Log::log(&logger, &record);
2068
2069            let first = take_shutdown_on_error_trigger().unwrap();
2070            assert_eq!(first.component, Ustr::from("RunComponent"));
2071            assert_eq!(first.message, "First error");
2072            assert_eq!(take_shutdown_on_error_trigger(), None);
2073
2074            arm_shutdown_on_error(true);
2075            let args = format_args!("Third error");
2076            let record = log::Record::builder()
2077                .args(args)
2078                .level(Level::Error)
2079                .target("RunComponent")
2080                .build();
2081            log::Log::log(&logger, &record);
2082
2083            let third = take_shutdown_on_error_trigger().unwrap();
2084            assert_eq!(third.component, Ustr::from("RunComponent"));
2085            assert_eq!(third.message, "Third error");
2086
2087            let (tx, rx) = std::sync::mpsc::channel();
2088            let logger = Logger::new_for_benchmark(
2089                LoggerConfig {
2090                    log_components_only: true,
2091                    ..Default::default()
2092                },
2093                tx,
2094            );
2095
2096            arm_shutdown_on_error(true);
2097            let args = format_args!("Filtered error");
2098            let record = log::Record::builder()
2099                .args(args)
2100                .level(Level::Error)
2101                .target("FilteredComponent")
2102                .build();
2103            log::Log::log(&logger, &record);
2104
2105            let trigger = take_shutdown_on_error_trigger().unwrap();
2106            assert_eq!(trigger.component, Ustr::from("FilteredComponent"));
2107            assert_eq!(trigger.message, "Filtered error");
2108            assert!(matches!(
2109                rx.try_recv(),
2110                Err(std::sync::mpsc::TryRecvError::Empty)
2111            ));
2112            disarm_shutdown_on_error();
2113        }
2114
2115        #[rstest]
2116        fn test_shutdown_on_error_records_bypassed_error() {
2117            LOGGING_BYPASSED.store(false, Ordering::Relaxed);
2118            disarm_shutdown_on_error();
2119
2120            let (tx, rx) = std::sync::mpsc::channel();
2121            let logger = Logger::new_for_benchmark(LoggerConfig::default(), tx);
2122            let metadata = log::Metadata::builder()
2123                .level(Level::Error)
2124                .target("BypassedComponent")
2125                .build();
2126
2127            logging_set_bypass();
2128            arm_shutdown_on_error(false);
2129            assert!(!log::Log::enabled(&logger, &metadata));
2130
2131            arm_shutdown_on_error(true);
2132            assert!(log::Log::enabled(&logger, &metadata));
2133
2134            let args = format_args!("Bypassed error");
2135            let record = log::Record::builder()
2136                .args(args)
2137                .level(Level::Error)
2138                .target("BypassedComponent")
2139                .build();
2140            log::Log::log(&logger, &record);
2141
2142            let trigger = take_shutdown_on_error_trigger().unwrap();
2143            assert_eq!(trigger.component, Ustr::from("BypassedComponent"));
2144            assert_eq!(trigger.message, "Bypassed error");
2145            assert!(matches!(
2146                rx.try_recv(),
2147                Err(std::sync::mpsc::TryRecvError::Empty)
2148            ));
2149
2150            LOGGING_BYPASSED.store(false, Ordering::Relaxed);
2151            disarm_shutdown_on_error();
2152        }
2153
2154        #[rstest]
2155        fn test_shutdown_on_error_failed_drain_keeps_trigger_pending() {
2156            LOGGING_BYPASSED.store(false, Ordering::Relaxed);
2157            disarm_shutdown_on_error();
2158
2159            let (tx, _rx) = std::sync::mpsc::channel();
2160            let logger = Logger::new_for_benchmark(LoggerConfig::default(), tx);
2161
2162            arm_shutdown_on_error(true);
2163            let args = format_args!("Pending error");
2164            let record = log::Record::builder()
2165                .args(args)
2166                .level(Level::Error)
2167                .target("PendingComponent")
2168                .build();
2169            log::Log::log(&logger, &record);
2170
2171            let drained = try_drain_shutdown_on_error_trigger(|trigger| {
2172                assert_eq!(trigger.component, Ustr::from("PendingComponent"));
2173                assert_eq!(trigger.message, "Pending error");
2174                false
2175            });
2176            assert!(!drained);
2177
2178            let trigger = take_shutdown_on_error_trigger().unwrap();
2179            assert_eq!(trigger.component, Ustr::from("PendingComponent"));
2180            assert_eq!(trigger.message, "Pending error");
2181            disarm_shutdown_on_error();
2182        }
2183
2184        #[rstest]
2185        fn test_logging_to_file() {
2186            let config = LoggerConfig {
2187                fileout_level: LevelFilter::Debug,
2188                ..Default::default()
2189            };
2190
2191            let temp_dir = tempdir().expect("Failed to create temporary directory");
2192            let file_config = FileWriterConfig {
2193                directory: Some(temp_dir.path().to_str().unwrap().to_string()),
2194                ..Default::default()
2195            };
2196
2197            let log_guard = Logger::init_with_config(
2198                TraderId::from("TRADER-001"),
2199                UUID4::new(),
2200                config,
2201                file_config,
2202            );
2203
2204            logging_clock_set_static_mode();
2205            logging_clock_set_static_time(1_650_000_000_000_000);
2206
2207            log::info!(
2208                component = "RiskEngine";
2209                "This is a test"
2210            );
2211
2212            let mut log_contents = String::new();
2213
2214            wait_until(
2215                || {
2216                    std::fs::read_dir(&temp_dir)
2217                        .expect("Failed to read directory")
2218                        .filter_map(Result::ok)
2219                        .any(|entry| entry.path().is_file())
2220                },
2221                Duration::from_secs(3),
2222            );
2223
2224            drop(log_guard); // Ensure log buffers are flushed
2225
2226            wait_until(
2227                || {
2228                    let log_file_path = std::fs::read_dir(&temp_dir)
2229                        .expect("Failed to read directory")
2230                        .filter_map(Result::ok)
2231                        .find(|entry| entry.path().is_file())
2232                        .expect("No files found in directory")
2233                        .path();
2234                    log_contents = std::fs::read_to_string(log_file_path)
2235                        .expect("Error while reading log file");
2236                    !log_contents.is_empty()
2237                },
2238                Duration::from_secs(3),
2239            );
2240
2241            assert_eq!(
2242                log_contents,
2243                "1970-01-20T02:20:00.000000000Z [INFO] TRADER-001.RiskEngine: This is a test\n"
2244            );
2245        }
2246
2247        #[rstest]
2248        fn test_logging_sync_to_disk_flushes_fast_flush_policy() {
2249            let config = LoggerConfig {
2250                fileout_level: LevelFilter::Debug,
2251                fileout_sync_on_flush: false,
2252                ..Default::default()
2253            };
2254
2255            let temp_dir = tempdir().expect("Failed to create temporary directory");
2256            let file_config = FileWriterConfig {
2257                directory: Some(temp_dir.path().to_str().unwrap().to_string()),
2258                ..Default::default()
2259            };
2260
2261            let log_guard = Logger::init_with_config(
2262                TraderId::from("TRADER-SYNC"),
2263                UUID4::new(),
2264                config,
2265                file_config,
2266            )
2267            .expect("Failed to initialize logger");
2268
2269            logging_clock_set_static_mode();
2270            logging_clock_set_static_time(1_650_000_000_000_000);
2271
2272            log::info!(
2273                component = "RiskEngine";
2274                "sync me"
2275            );
2276
2277            logging_sync_to_disk().expect("sync-to-disk should succeed");
2278
2279            let log_file_path = std::fs::read_dir(&temp_dir)
2280                .expect("Failed to read directory")
2281                .filter_map(Result::ok)
2282                .find(|entry| entry.path().is_file())
2283                .expect("No files found in directory")
2284                .path();
2285            let log_contents =
2286                std::fs::read_to_string(log_file_path).expect("Error while reading log file");
2287
2288            assert!(log_contents.contains("sync me"));
2289
2290            drop(log_guard);
2291        }
2292
2293        #[rstest]
2294        fn test_last_guard_drop_syncs_backlog_tail() {
2295            const N: usize = 1000;
2296
2297            // Configure file logging at Info level
2298            let config = LoggerConfig {
2299                stdout_level: LevelFilter::Off,
2300                fileout_level: LevelFilter::Info,
2301                ..Default::default()
2302            };
2303
2304            let temp_dir = tempdir().expect("Failed to create temporary directory");
2305            let file_config = FileWriterConfig {
2306                directory: Some(temp_dir.path().to_str().unwrap().to_string()),
2307                ..Default::default()
2308            };
2309
2310            let log_guard = Logger::init_with_config(
2311                TraderId::from("TRADER-TAIL"),
2312                UUID4::new(),
2313                config,
2314                file_config,
2315            )
2316            .expect("Failed to initialize logger");
2317
2318            // Use static time for reproducibility
2319            logging_clock_set_static_mode();
2320            logging_clock_set_static_time(1_700_000_000_000_000);
2321
2322            // Enqueue a known number of messages synchronously
2323            for i in 0..N {
2324                log::info!(component = "TailDrain"; "BacklogTest {i}");
2325            }
2326
2327            // Drop the last guard to synchronously flush and sync pending messages.
2328            drop(log_guard);
2329
2330            // Wait until the file exists and contains at least N lines with our marker
2331            let mut count = 0usize;
2332            wait_until(
2333                || {
2334                    if let Some(log_file) = std::fs::read_dir(&temp_dir)
2335                        .expect("Failed to read directory")
2336                        .filter_map(Result::ok)
2337                        .find(|entry| entry.path().is_file())
2338                    {
2339                        let log_file_path = log_file.path();
2340                        if let Ok(contents) = std::fs::read_to_string(log_file_path) {
2341                            count = contents
2342                                .lines()
2343                                .filter(|l| l.contains("BacklogTest "))
2344                                .count();
2345                            count >= N
2346                        } else {
2347                            false
2348                        }
2349                    } else {
2350                        false
2351                    }
2352                },
2353                Duration::from_secs(5),
2354            );
2355
2356            assert_eq!(count, N, "Expected all pending messages to be written");
2357        }
2358
2359        #[rstest]
2360        fn test_log_component_level_filtering() {
2361            let config =
2362                LoggerConfig::from_spec("stdout=Info;fileout=Debug;RiskEngine=Error").unwrap();
2363
2364            let temp_dir = tempdir().expect("Failed to create temporary directory");
2365            let file_config = FileWriterConfig {
2366                directory: Some(temp_dir.path().to_str().unwrap().to_string()),
2367                ..Default::default()
2368            };
2369
2370            let log_guard = Logger::init_with_config(
2371                TraderId::from("TRADER-001"),
2372                UUID4::new(),
2373                config,
2374                file_config,
2375            );
2376
2377            logging_clock_set_static_mode();
2378            logging_clock_set_static_time(1_650_000_000_000_000);
2379
2380            log::info!(
2381                component = "RiskEngine";
2382                "This is a test"
2383            );
2384
2385            drop(log_guard); // Ensure log buffers are flushed
2386
2387            wait_until(
2388                || {
2389                    if let Some(log_file) = std::fs::read_dir(&temp_dir)
2390                        .expect("Failed to read directory")
2391                        .filter_map(Result::ok)
2392                        .find(|entry| entry.path().is_file())
2393                    {
2394                        let log_file_path = log_file.path();
2395                        let log_contents = std::fs::read_to_string(log_file_path)
2396                            .expect("Error while reading log file");
2397                        !log_contents.contains("RiskEngine")
2398                    } else {
2399                        false
2400                    }
2401                },
2402                Duration::from_secs(3),
2403            );
2404
2405            assert!(
2406                std::fs::read_dir(&temp_dir)
2407                    .expect("Failed to read directory")
2408                    .filter_map(Result::ok)
2409                    .any(|entry| entry.path().is_file()),
2410                "Log file exists"
2411            );
2412        }
2413
2414        #[rstest]
2415        fn test_logging_to_file_in_json_format() {
2416            let config =
2417                LoggerConfig::from_spec("stdout=Info;is_colored;fileout=Debug;RiskEngine=Info")
2418                    .unwrap();
2419
2420            let temp_dir = tempdir().expect("Failed to create temporary directory");
2421            let file_config = FileWriterConfig {
2422                directory: Some(temp_dir.path().to_str().unwrap().to_string()),
2423                file_format: Some("json".to_string()),
2424                ..Default::default()
2425            };
2426
2427            let log_guard = Logger::init_with_config(
2428                TraderId::from("TRADER-001"),
2429                UUID4::new(),
2430                config,
2431                file_config,
2432            );
2433
2434            logging_clock_set_static_mode();
2435            logging_clock_set_static_time(1_650_000_000_000_000);
2436
2437            log::info!(
2438                component = "RiskEngine";
2439                "This is a test"
2440            );
2441
2442            let mut log_contents = String::new();
2443
2444            drop(log_guard); // Ensure log buffers are flushed
2445
2446            wait_until(
2447                || {
2448                    if let Some(log_file) = std::fs::read_dir(&temp_dir)
2449                        .expect("Failed to read directory")
2450                        .filter_map(Result::ok)
2451                        .find(|entry| entry.path().is_file())
2452                    {
2453                        let log_file_path = log_file.path();
2454                        log_contents = std::fs::read_to_string(log_file_path)
2455                            .expect("Error while reading log file");
2456                        !log_contents.is_empty()
2457                    } else {
2458                        false
2459                    }
2460                },
2461                Duration::from_secs(3),
2462            );
2463
2464            assert_eq!(
2465                log_contents,
2466                "{\"timestamp\":\"1970-01-20T02:20:00.000000000Z\",\"trader_id\":\"TRADER-001\",\"level\":\"INFO\",\"color\":\"NORMAL\",\"component\":\"RiskEngine\",\"message\":\"This is a test\"}\n"
2467            );
2468        }
2469
2470        #[rstest]
2471        fn test_init_sets_logging_is_initialized_flag() {
2472            let config = LoggerConfig::default();
2473            let file_config = FileWriterConfig::default();
2474
2475            let guard = Logger::init_with_config(
2476                TraderId::from("TRADER-001"),
2477                UUID4::new(),
2478                config,
2479                file_config,
2480            );
2481            assert!(guard.is_ok());
2482            assert!(logging_is_initialized());
2483
2484            drop(guard);
2485            assert!(logging_is_initialized());
2486        }
2487
2488        #[rstest]
2489        fn test_init_returns_error_when_log_guard_limit_reached() {
2490            let guard = Logger::init_with_config(
2491                TraderId::from("TRADER-001"),
2492                UUID4::new(),
2493                LoggerConfig::default(),
2494                FileWriterConfig::default(),
2495            )
2496            .expect("Failed to initialize logger");
2497
2498            LOGGING_GUARDS_ACTIVE.store(u8::MAX, Ordering::SeqCst);
2499            let result = Logger::init_with_config(
2500                TraderId::from("TRADER-001"),
2501                UUID4::new(),
2502                LoggerConfig::default(),
2503                FileWriterConfig::default(),
2504            );
2505            LOGGING_GUARDS_ACTIVE.store(1, Ordering::SeqCst);
2506            drop(guard);
2507
2508            assert_eq!(
2509                result.unwrap_err().to_string(),
2510                "Logging already initialized but new guard could not be created"
2511            );
2512        }
2513
2514        #[rstest]
2515        fn test_reinit_after_guard_drop_returns_live_guard() {
2516            let config = LoggerConfig::default();
2517            let file_config = FileWriterConfig::default();
2518
2519            let guard1 = Logger::init_with_config(
2520                TraderId::from("TRADER-001"),
2521                UUID4::new(),
2522                config.clone(),
2523                file_config.clone(),
2524            );
2525            assert!(guard1.is_ok());
2526            drop(guard1);
2527
2528            let guard2 = Logger::init_with_config(
2529                TraderId::from("TRADER-002"),
2530                UUID4::new(),
2531                config,
2532                file_config,
2533            );
2534            assert!(guard2.is_ok());
2535        }
2536
2537        #[rstest]
2538        fn test_bypass_before_init_prevents_logging() {
2539            logging_set_bypass();
2540            assert!(LOGGING_BYPASSED.load(Ordering::Relaxed));
2541
2542            let temp_dir = tempdir().expect("Failed to create temporary directory");
2543            let config = LoggerConfig {
2544                fileout_level: LevelFilter::Debug,
2545                ..Default::default()
2546            };
2547            let file_config = FileWriterConfig {
2548                directory: Some(temp_dir.path().to_str().unwrap().to_string()),
2549                ..Default::default()
2550            };
2551
2552            let guard = Logger::init_with_config(
2553                TraderId::from("TRADER-001"),
2554                UUID4::new(),
2555                config,
2556                file_config,
2557            );
2558            assert!(guard.is_ok());
2559
2560            log::info!(
2561                component = "TestComponent";
2562                "This should be bypassed"
2563            );
2564            std::thread::sleep(Duration::from_millis(100));
2565            drop(guard);
2566
2567            // Bypass flag remains permanently set (no reset mechanism)
2568            assert!(LOGGING_BYPASSED.load(Ordering::Relaxed));
2569        }
2570
2571        #[rstest]
2572        fn test_module_level_filtering() {
2573            // Configure module-level filters (note: requires :: to be a module filter):
2574            // - nautilus::adapters=Warn (general adapter logs at Warn+)
2575            // - nautilus::adapters::okx=Debug (OKX adapter logs at Debug+)
2576            let config = LoggerConfig::from_spec(
2577                "stdout=Off;fileout=Trace;nautilus::adapters=Warn;nautilus::adapters::okx=Debug",
2578            )
2579            .unwrap();
2580
2581            let temp_dir = tempdir().expect("Failed to create temporary directory");
2582            let file_config = FileWriterConfig {
2583                directory: Some(temp_dir.path().to_str().unwrap().to_string()),
2584                ..Default::default()
2585            };
2586
2587            let log_guard = Logger::init_with_config(
2588                TraderId::from("TRADER-MOD"),
2589                UUID4::new(),
2590                config,
2591                file_config,
2592            )
2593            .expect("Failed to initialize logger");
2594
2595            logging_clock_set_static_mode();
2596            logging_clock_set_static_time(1_650_000_000_000_000);
2597
2598            // Log from nautilus::adapters::okx::websocket - should pass (Debug allowed)
2599            log::debug!(
2600                component = "nautilus::adapters::okx::websocket";
2601                "OKX debug message"
2602            );
2603
2604            // Log from nautilus::adapters::okx - should pass (Debug allowed)
2605            log::info!(
2606                component = "nautilus::adapters::okx";
2607                "OKX info message"
2608            );
2609
2610            // Log from nautilus::adapters::binance - should be filtered (only Warn+ allowed)
2611            log::info!(
2612                component = "nautilus::adapters::binance";
2613                "Binance info message SHOULD NOT APPEAR"
2614            );
2615
2616            // Log from nautilus::adapters::binance at Warn - should pass
2617            log::warn!(
2618                component = "nautilus::adapters::binance";
2619                "Binance warn message"
2620            );
2621
2622            // Log from unrelated component - should pass (no filter)
2623            log::trace!(
2624                component = "Portfolio";
2625                "Portfolio trace message"
2626            );
2627
2628            drop(log_guard);
2629
2630            wait_until(
2631                || {
2632                    std::fs::read_dir(&temp_dir)
2633                        .expect("Failed to read directory")
2634                        .filter_map(Result::ok)
2635                        .any(|entry| entry.path().is_file())
2636                },
2637                Duration::from_secs(3),
2638            );
2639
2640            let log_file_path = std::fs::read_dir(&temp_dir)
2641                .expect("Failed to read directory")
2642                .filter_map(Result::ok)
2643                .find(|entry| entry.path().is_file())
2644                .expect("No log file found")
2645                .path();
2646
2647            let log_contents =
2648                std::fs::read_to_string(log_file_path).expect("Error reading log file");
2649
2650            assert!(
2651                log_contents.contains("OKX debug message"),
2652                "OKX debug should pass (longer prefix wins)"
2653            );
2654            assert!(
2655                log_contents.contains("OKX info message"),
2656                "OKX info should pass"
2657            );
2658            assert!(
2659                log_contents.contains("Binance warn message"),
2660                "Binance warn should pass"
2661            );
2662            assert!(
2663                log_contents.contains("Portfolio trace message"),
2664                "Unfiltered component should pass"
2665            );
2666            assert!(
2667                !log_contents.contains("SHOULD NOT APPEAR"),
2668                "Binance info should be filtered (adapters=Warn)"
2669            );
2670        }
2671
2672        #[rstest]
2673        fn test_logging_to_file_with_kv_fields() {
2674            let config = LoggerConfig {
2675                fileout_level: LevelFilter::Debug,
2676                ..Default::default()
2677            };
2678
2679            let temp_dir = tempdir().expect("Failed to create temporary directory");
2680            let file_config = FileWriterConfig {
2681                directory: Some(temp_dir.path().to_str().unwrap().to_string()),
2682                ..Default::default()
2683            };
2684
2685            let log_guard = Logger::init_with_config(
2686                TraderId::from("TRADER-001"),
2687                UUID4::new(),
2688                config,
2689                file_config,
2690            );
2691
2692            logging_clock_set_static_mode();
2693            logging_clock_set_static_time(1_650_000_000_000_000);
2694
2695            log::info!(
2696                component = "DataEngine",
2697                venue = "BINANCE",
2698                product_type = "SPOT";
2699                "WebSocket connected"
2700            );
2701
2702            let mut log_contents = String::new();
2703
2704            drop(log_guard);
2705
2706            wait_until(
2707                || {
2708                    if let Some(log_file) = std::fs::read_dir(&temp_dir)
2709                        .expect("Failed to read directory")
2710                        .filter_map(Result::ok)
2711                        .find(|entry| entry.path().is_file())
2712                    {
2713                        log_contents = std::fs::read_to_string(log_file.path())
2714                            .expect("Error while reading log file");
2715                        !log_contents.is_empty()
2716                    } else {
2717                        false
2718                    }
2719                },
2720                Duration::from_secs(3),
2721            );
2722
2723            assert!(
2724                log_contents.contains("WebSocket connected"),
2725                "Message should be present"
2726            );
2727            assert!(
2728                log_contents.contains("venue=BINANCE"),
2729                "venue field should appear in output, was:\n{log_contents}"
2730            );
2731            assert!(
2732                log_contents.contains("product_type=SPOT"),
2733                "product_type field should appear in output, was:\n{log_contents}"
2734            );
2735        }
2736
2737        #[rstest]
2738        fn test_logging_to_file_json_with_kv_fields() {
2739            let config =
2740                LoggerConfig::from_spec("stdout=Off;fileout=Debug;DataEngine=Debug").unwrap();
2741
2742            let temp_dir = tempdir().expect("Failed to create temporary directory");
2743            let file_config = FileWriterConfig {
2744                directory: Some(temp_dir.path().to_str().unwrap().to_string()),
2745                file_format: Some("json".to_string()),
2746                ..Default::default()
2747            };
2748
2749            let log_guard = Logger::init_with_config(
2750                TraderId::from("TRADER-001"),
2751                UUID4::new(),
2752                config,
2753                file_config,
2754            );
2755
2756            logging_clock_set_static_mode();
2757            logging_clock_set_static_time(1_650_000_000_000_000);
2758
2759            log::info!(
2760                component = "DataEngine",
2761                venue = "BINANCE",
2762                order_id = "O-12345";
2763                "Order filled"
2764            );
2765
2766            let mut log_contents = String::new();
2767
2768            drop(log_guard);
2769
2770            wait_until(
2771                || {
2772                    if let Some(log_file) = std::fs::read_dir(&temp_dir)
2773                        .expect("Failed to read directory")
2774                        .filter_map(Result::ok)
2775                        .find(|entry| entry.path().is_file())
2776                    {
2777                        log_contents = std::fs::read_to_string(log_file.path())
2778                            .expect("Error while reading log file");
2779                        !log_contents.is_empty()
2780                    } else {
2781                        false
2782                    }
2783                },
2784                Duration::from_secs(3),
2785            );
2786
2787            let parsed: serde_json::Value =
2788                serde_json::from_str(log_contents.trim()).expect("Should be valid JSON");
2789            assert_eq!(parsed["component"], "DataEngine");
2790            assert_eq!(parsed["message"], "Order filled");
2791            assert_eq!(parsed["venue"], "BINANCE");
2792            assert_eq!(parsed["order_id"], "O-12345");
2793        }
2794    }
2795
2796    #[cfg(not(all(feature = "simulation", madsim)))]
2797    mod lifecycle_tests {
2798        use std::{
2799            process::Command,
2800            sync::{Arc, Barrier},
2801        };
2802
2803        use super::*;
2804        use crate::logging::{logging_is_initialized, logging_shutdown, logging_sync_to_disk};
2805
2806        const LIFECYCLE_CHILD_ENV: &str = "NAUTILUS_LOGGER_LIFECYCLE_CHILD";
2807
2808        fn in_lifecycle_child(marker: &str) -> bool {
2809            std::env::var(LIFECYCLE_CHILD_ENV).as_deref() == Ok(marker)
2810        }
2811
2812        fn run_lifecycle_child(test_name: &str, marker: &str) {
2813            let output = Command::new(std::env::current_exe().expect("test executable must exist"))
2814                .arg(test_name)
2815                .arg("--nocapture")
2816                .arg("--test-threads=1")
2817                .env(LIFECYCLE_CHILD_ENV, marker)
2818                .output()
2819                .expect("lifecycle child process must start");
2820
2821            assert!(
2822                output.status.success(),
2823                "lifecycle child failed with {}\nstdout:\n{}\nstderr:\n{}",
2824                output.status,
2825                String::from_utf8_lossy(&output.stdout),
2826                String::from_utf8_lossy(&output.stderr),
2827            );
2828        }
2829
2830        #[rstest]
2831        fn test_init_publish_boundary_serializes_guard_acquisition() {
2832            const MARKER: &str = "init-publish-boundary";
2833            if !in_lifecycle_child(MARKER) {
2834                run_lifecycle_child(
2835                    "test_init_publish_boundary_serializes_guard_acquisition",
2836                    MARKER,
2837                );
2838                return;
2839            }
2840
2841            let (publish_reached_tx, publish_reached_rx) = std::sync::mpsc::channel();
2842            let (publish_resume_tx, publish_resume_rx) = std::sync::mpsc::channel();
2843            *INIT_PUBLISH_HOOK.lock() = Some(InitPublishHook {
2844                reached: publish_reached_tx,
2845                resume: publish_resume_rx,
2846            });
2847
2848            let init_thread = std::thread::spawn(|| {
2849                Logger::init_with_config(
2850                    TraderId::from("TRADER-BOUNDARY"),
2851                    UUID4::new(),
2852                    LoggerConfig {
2853                        stdout_level: LevelFilter::Off,
2854                        ..Default::default()
2855                    },
2856                    FileWriterConfig::default(),
2857                )
2858            });
2859            publish_reached_rx
2860                .recv()
2861                .expect("initializer must reach the install/publish boundary");
2862
2863            // This seam proves initialization retains LOGGER_LIFECYCLE through publication.
2864            // Public LogGuard::new() coverage belongs to the contention and sequential tests.
2865            assert!(
2866                matches!(
2867                    LogGuard::try_new_for_test(),
2868                    TestGuardAcquire::LifecycleBusy
2869                ),
2870                "initializer must hold the lifecycle mutex before sender publication completes"
2871            );
2872
2873            publish_resume_tx
2874                .send(())
2875                .expect("initializer must resume publication");
2876            let init_guard = init_thread
2877                .join()
2878                .expect("initializer thread must not panic")
2879                .expect("initialization must succeed");
2880            let TestGuardAcquire::Acquired(Some(second_guard)) = LogGuard::try_new_for_test()
2881            else {
2882                panic!("publication must release the lifecycle mutex and expose a valid guard");
2883            };
2884            drop((init_guard, second_guard));
2885            logging_shutdown();
2886        }
2887
2888        #[rstest]
2889        fn test_concurrent_init_high_contention() {
2890            const MARKER: &str = "concurrent-init";
2891            const THREADS: usize = 64;
2892
2893            if !in_lifecycle_child(MARKER) {
2894                run_lifecycle_child("test_concurrent_init_high_contention", MARKER);
2895                return;
2896            }
2897
2898            let barrier = Arc::new(Barrier::new(THREADS));
2899            let mut threads = Vec::with_capacity(THREADS);
2900            for index in 0..THREADS {
2901                let barrier = Arc::clone(&barrier);
2902                threads.push(std::thread::spawn(move || {
2903                    barrier.wait();
2904                    Logger::init_with_config(
2905                        TraderId::from(format!("TRADER-{index:02}")),
2906                        UUID4::new(),
2907                        LoggerConfig {
2908                            stdout_level: LevelFilter::Off,
2909                            ..Default::default()
2910                        },
2911                        FileWriterConfig::default(),
2912                    )
2913                }));
2914            }
2915
2916            let guards = threads
2917                .into_iter()
2918                .map(|thread| {
2919                    thread
2920                        .join()
2921                        .expect("initializer thread must not panic")
2922                        .expect("every concurrent initialization must return a guard")
2923                })
2924                .collect::<Vec<_>>();
2925            logging_sync_to_disk().expect("logging sync must succeed after concurrent init");
2926            drop(guards);
2927            logging_shutdown();
2928        }
2929
2930        #[rstest]
2931        fn test_sequential_init_reuses_live_worker_and_original_file() {
2932            const MARKER: &str = "sequential-init";
2933            if !in_lifecycle_child(MARKER) {
2934                run_lifecycle_child(
2935                    "test_sequential_init_reuses_live_worker_and_original_file",
2936                    MARKER,
2937                );
2938                return;
2939            }
2940
2941            let temp_dir = tempdir().expect("temporary directory must be created");
2942            let config = LoggerConfig {
2943                stdout_level: LevelFilter::Off,
2944                fileout_level: LevelFilter::Info,
2945                ..Default::default()
2946            };
2947            let file_config = FileWriterConfig {
2948                directory: Some(temp_dir.path().to_str().unwrap().to_string()),
2949                ..Default::default()
2950            };
2951
2952            let first_guard = Logger::init_with_config(
2953                TraderId::from("TRADER-SEQUENTIAL"),
2954                UUID4::new(),
2955                config,
2956                file_config,
2957            )
2958            .expect("first initialization must succeed");
2959            log::info!(component = "LifecycleTest"; "lifecycle marker A");
2960            drop(first_guard);
2961
2962            assert!(logging_is_initialized());
2963            assert!(is_running());
2964
2965            let second_guard = Logger::init_with_config(
2966                TraderId::from("TRADER-IGNORED"),
2967                UUID4::new(),
2968                LoggerConfig::default(),
2969                FileWriterConfig::default(),
2970            )
2971            .expect("second initialization must return a live guard");
2972            log::info!(component = "LifecycleTest"; "lifecycle marker B");
2973            logging_sync_to_disk().expect("logging sync must succeed after re-acquisition");
2974
2975            let log_path = std::fs::read_dir(&temp_dir)
2976                .expect("log directory must be readable")
2977                .filter_map(Result::ok)
2978                .find(|entry| entry.path().is_file())
2979                .expect("original logger must create a log file")
2980                .path();
2981            let contents = std::fs::read_to_string(log_path).expect("log file must be readable");
2982            assert!(contents.contains("lifecycle marker A"));
2983            assert!(contents.contains("lifecycle marker B"));
2984
2985            drop(second_guard);
2986            logging_shutdown();
2987
2988            let error = Logger::init_with_config(
2989                TraderId::from("TRADER-TERMINATED"),
2990                UUID4::new(),
2991                LoggerConfig::default(),
2992                FileWriterConfig::default(),
2993            )
2994            .expect_err("initialization after terminal shutdown must fail");
2995            assert_eq!(
2996                error.to_string(),
2997                "Logging has been shut down and cannot be re-initialized"
2998            );
2999        }
3000    }
3001
3002    #[cfg(all(feature = "simulation", madsim))]
3003    mod sim_tests {
3004        use std::sync::atomic::Ordering;
3005
3006        use super::*;
3007        use crate::logging::LOGGING_BYPASSED;
3008
3009        #[rstest]
3010        fn test_init_under_madsim_skips_writer_thread_and_forces_bypass() {
3011            let config = LoggerConfig {
3012                bypass_logging: false,
3013                ..Default::default()
3014            };
3015            let temp_dir = tempdir().expect("Failed to create temporary directory");
3016            let file_config = FileWriterConfig {
3017                directory: Some(temp_dir.path().to_str().unwrap().to_string()),
3018                ..Default::default()
3019            };
3020
3021            let _guard = Logger::init_with_config(
3022                TraderId::from("TRADER-SIM"),
3023                UUID4::new(),
3024                config,
3025                file_config,
3026            )
3027            .expect("init should succeed under simulation");
3028
3029            assert!(LOGGING_INITIALIZED.load(Ordering::SeqCst));
3030            assert!(
3031                LOGGING_BYPASSED.load(Ordering::SeqCst),
3032                "bypass must be forced under cfg(madsim) even when config disables it"
3033            );
3034            assert!(
3035                LOGGER_HANDLE.lock().is_none(),
3036                "writer thread must not be spawned under cfg(madsim)"
3037            );
3038        }
3039    }
3040}