nautilus_common/logging/
writer.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//! Stdout, stderr, and rotating file log writers.
17
18use std::{
19    borrow::Cow,
20    collections::VecDeque,
21    fs::{File, create_dir_all},
22    io::{self, BufWriter, Stderr, Stdout, Write},
23    path::{Path, PathBuf},
24};
25
26use anyhow::Context;
27use jiff::{Timestamp, civil::Date, tz::Offset};
28use log::LevelFilter;
29use nautilus_core::consts::NAUTILUS_PREFIX;
30use serde::{Deserialize, Serialize};
31
32use crate::{
33    config::{ConfigError, ConfigErrorCollector, ConfigResult},
34    logging::logger::LogLine,
35};
36
37pub trait LogWriter {
38    /// Writes a log line.
39    fn write(&mut self, line: &str);
40    /// Flushes buffered logs.
41    fn flush(&mut self);
42    /// Checks if a line needs to be written to the writer or not.
43    fn enabled(&self, line: &LogLine) -> bool;
44}
45
46/// Writes eligible log lines to stdout with optional buffering and ANSI colors.
47#[derive(Debug)]
48pub struct StdoutWriter {
49    pub is_colored: bool,
50    io: StdoutSink,
51    level: LevelFilter,
52}
53
54#[derive(Debug)]
55enum StdoutSink {
56    Direct(Stdout),
57    Buffered(BufWriter<Stdout>),
58}
59
60impl StdoutWriter {
61    /// Creates a new [`StdoutWriter`] instance.
62    #[must_use]
63    pub fn new(level: LevelFilter, is_colored: bool, buffered: bool) -> Self {
64        let io = if buffered {
65            StdoutSink::Buffered(BufWriter::new(io::stdout()))
66        } else {
67            StdoutSink::Direct(io::stdout())
68        };
69
70        Self {
71            is_colored,
72            io,
73            level,
74        }
75    }
76}
77
78impl LogWriter for StdoutWriter {
79    fn write(&mut self, line: &str) {
80        let result = match &mut self.io {
81            StdoutSink::Direct(io) => io.write_all(line.as_bytes()),
82            StdoutSink::Buffered(io) => io.write_all(line.as_bytes()),
83        };
84
85        if let Err(e) = result {
86            let _ = writeln!(io::stderr(), "Error writing to stdout: {e:?}");
87        }
88    }
89
90    fn flush(&mut self) {
91        let result = match &mut self.io {
92            StdoutSink::Direct(io) => io.flush(),
93            StdoutSink::Buffered(io) => io.flush(),
94        };
95
96        if let Err(e) = result {
97            let _ = writeln!(io::stderr(), "Error flushing stdout: {e:?}");
98        }
99    }
100
101    fn enabled(&self, line: &LogLine) -> bool {
102        // Prevent error logs also writing to stdout (they go to stderr)
103        line.level > LevelFilter::Error && line.level <= self.level
104    }
105}
106
107/// Writes error log lines to stderr.
108#[derive(Debug)]
109pub struct StderrWriter {
110    pub is_colored: bool,
111    io: Stderr,
112}
113
114impl StderrWriter {
115    /// Creates a new [`StderrWriter`] instance.
116    #[must_use]
117    pub fn new(is_colored: bool) -> Self {
118        Self {
119            io: io::stderr(),
120            is_colored,
121        }
122    }
123}
124
125// Diagnostics here use `writeln!` because `eprintln!` panics when stderr is a closed pipe
126impl LogWriter for StderrWriter {
127    fn write(&mut self, line: &str) {
128        let _ = self.io.write_all(line.as_bytes());
129    }
130
131    fn flush(&mut self) {
132        let _ = self.io.flush();
133    }
134
135    fn enabled(&self, line: &LogLine) -> bool {
136        line.level == LevelFilter::Error
137    }
138}
139
140/// Configures size-based log file rotation.
141#[derive(Debug, Clone, Serialize, Deserialize)]
142#[serde(default, deny_unknown_fields)]
143pub struct FileRotateConfig {
144    /// Maximum file size in bytes before rotating.
145    pub max_file_size: u64,
146    /// Maximum number of backup files to keep.
147    pub max_backup_count: u32,
148    /// Current file size tracking.
149    #[serde(skip)]
150    cur_file_size: u64,
151    /// Current file creation date.
152    #[serde(skip, default = "today_date")]
153    cur_file_creation_date: Date,
154    /// Queue of backup file paths (oldest first).
155    #[serde(skip)]
156    backup_files: VecDeque<PathBuf>,
157}
158
159fn utc_date(timestamp: Timestamp) -> Date {
160    Offset::UTC.to_datetime(timestamp).date()
161}
162
163fn today_date() -> Date {
164    utc_date(Timestamp::now())
165}
166
167impl PartialEq for FileRotateConfig {
168    fn eq(&self, other: &Self) -> bool {
169        self.max_file_size == other.max_file_size && self.max_backup_count == other.max_backup_count
170    }
171}
172
173impl Eq for FileRotateConfig {}
174
175impl Default for FileRotateConfig {
176    fn default() -> Self {
177        Self {
178            max_file_size: 100 * 1024 * 1024, // 100MB default
179            max_backup_count: 5,
180            cur_file_size: 0,
181            cur_file_creation_date: today_date(),
182            backup_files: VecDeque::new(),
183        }
184    }
185}
186
187impl From<(u64, u32)> for FileRotateConfig {
188    fn from(value: (u64, u32)) -> Self {
189        let (max_file_size, max_backup_count) = value;
190        Self {
191            max_file_size,
192            max_backup_count,
193            cur_file_size: 0,
194            cur_file_creation_date: today_date(),
195            backup_files: VecDeque::new(),
196        }
197    }
198}
199
200/// Configures file log output.
201#[cfg_attr(
202    feature = "python",
203    pyo3::pyclass(module = "nautilus_trader.common", from_py_object)
204)]
205#[cfg_attr(
206    feature = "python",
207    pyo3_stub_gen::derive::gen_stub_pyclass(module = "nautilus_trader.common")
208)]
209#[derive(Debug, Clone, Default, PartialEq, Eq, Serialize, Deserialize)]
210#[serde(default, deny_unknown_fields)]
211pub struct FileWriterConfig {
212    pub directory: Option<String>,
213    pub file_name: Option<String>,
214    pub file_format: Option<String>,
215    pub file_rotate: Option<FileRotateConfig>,
216}
217
218impl FileWriterConfig {
219    /// Creates a new [`FileWriterConfig`] instance.
220    #[must_use]
221    pub fn new(
222        directory: Option<String>,
223        file_name: Option<String>,
224        file_format: Option<String>,
225        file_rotate: Option<(u64, u32)>,
226    ) -> Self {
227        let file_rotate = file_rotate.map(FileRotateConfig::from);
228        Self {
229            directory,
230            file_name,
231            file_format,
232            file_rotate,
233        }
234    }
235
236    /// Validates the file writer configuration, collecting every field violation.
237    ///
238    /// # Errors
239    ///
240    /// Returns an error if any field fails validation. Multiple validation failures are collected
241    /// into one error.
242    pub fn validate(&self) -> ConfigResult<()> {
243        let mut errors = ConfigErrorCollector::new();
244
245        for (field, value) in [
246            ("file_config.directory", &self.directory),
247            ("file_config.file_name", &self.file_name),
248        ] {
249            if let Some(value) = value {
250                errors.check(!value.trim().is_empty(), ConfigError::empty_field(field));
251            }
252        }
253
254        if let Some(rotate) = &self.file_rotate {
255            let max_file_size = rotate.max_file_size;
256            errors.check(
257                max_file_size > 0,
258                ConfigError::range(
259                    "file_config.file_rotate.max_file_size",
260                    format!("must be a positive number of bytes, was {max_file_size}"),
261                ),
262            );
263        }
264
265        errors.into_result()
266    }
267}
268
269/// Writes sanitized plain-text or JSON log lines with optional file rotation.
270#[derive(Debug)]
271pub struct FileWriter {
272    pub json_format: bool,
273    buf: BufWriter<File>,
274    path: PathBuf,
275    file_config: FileWriterConfig,
276    trader_id: String,
277    instance_id: String,
278    level: LevelFilter,
279    cur_file_date: Date,
280    sync_on_flush: bool,
281}
282
283// Rotated log file names avoid ':' which is reserved in Windows file names
284const ROTATION_TIMESTAMP_FORMAT: &str = "%Y-%m-%d_%H%M%S-%3f";
285
286impl FileWriter {
287    /// Creates a new [`FileWriter`] instance.
288    ///
289    /// # Errors
290    ///
291    /// Returns an error if the log directory cannot be created or the log file cannot be opened.
292    pub fn new(
293        trader_id: String,
294        instance_id: String,
295        file_config: FileWriterConfig,
296        fileout_level: LevelFilter,
297        clear_log_file: bool,
298        sync_on_flush: bool,
299    ) -> anyhow::Result<Self> {
300        // Set up log file
301        let json_format = match file_config.file_format.as_ref().map(|s| s.to_lowercase()) {
302            Some(ref format) if format == "json" => true,
303            None => false,
304            Some(ref unrecognized) => {
305                let _ = writeln!(
306                    io::stderr(),
307                    "{NAUTILUS_PREFIX} Unrecognized log file format: {unrecognized}. Using plain text format as default."
308                );
309                false
310            }
311        };
312
313        let file_path = Self::create_log_file_path(
314            &file_config,
315            &trader_id,
316            &instance_id,
317            json_format,
318            Timestamp::now(),
319        )
320        .with_context(|| {
321            format!(
322                "failed to create log directory {}",
323                file_config.directory.as_deref().unwrap_or_default()
324            )
325        })?;
326
327        if clear_log_file
328            && file_path.exists()
329            && let Err(e) = File::create(&file_path)
330        {
331            let _ = writeln!(
332                io::stderr(),
333                "{NAUTILUS_PREFIX} Error clearing log file {}: {e}",
334                file_path.display()
335            );
336        }
337
338        let file = File::options()
339            .create(true)
340            .append(true)
341            .open(&file_path)
342            .with_context(|| format!("failed to open log file {}", file_path.display()))?;
343
344        // Seed cur_file_size from existing file length if rotation is enabled
345        let mut file_config = file_config;
346        if let Some(ref mut rotate_config) = file_config.file_rotate
347            && let Ok(metadata) = file.metadata()
348        {
349            rotate_config.cur_file_size = metadata.len();
350        }
351
352        Ok(Self {
353            json_format,
354            buf: BufWriter::new(file),
355            path: file_path,
356            file_config,
357            trader_id,
358            instance_id,
359            level: fileout_level,
360            cur_file_date: today_date(),
361            sync_on_flush,
362        })
363    }
364
365    fn create_log_file_path(
366        file_config: &FileWriterConfig,
367        trader_id: &str,
368        instance_id: &str,
369        is_json_format: bool,
370        utc_now: Timestamp,
371    ) -> Result<PathBuf, io::Error> {
372        let basename = if let Some(file_name) = file_config.file_name.as_ref() {
373            // The format suffix replaces any extension in the configured name
374            let stem = Path::new(file_name).with_extension("");
375            let stem = stem.to_string_lossy();
376
377            if file_config.file_rotate.is_some() {
378                let utc_datetime = utc_now.strftime(ROTATION_TIMESTAMP_FORMAT);
379                format!("{stem}_{utc_datetime}")
380            } else {
381                stem.into_owned()
382            }
383        } else {
384            let utc_component = if file_config.file_rotate.is_some() {
385                utc_now.strftime(ROTATION_TIMESTAMP_FORMAT)
386            } else {
387                utc_now.strftime("%Y-%m-%d")
388            };
389
390            format!("{trader_id}_{utc_component}_{instance_id}")
391        };
392
393        let suffix = if is_json_format { "jsonl" } else { "log" };
394        let mut file_path = PathBuf::new();
395
396        if let Some(directory) = file_config.directory.as_ref() {
397            file_path.push(directory);
398            create_dir_all(&file_path)?;
399        }
400
401        // Not `set_extension`, which would truncate a basename at a `.` inside a trader ID
402        file_path.push(format!("{basename}.{suffix}"));
403        Ok(file_path)
404    }
405
406    #[must_use]
407    fn should_rotate_file(&self, next_line_size: u64) -> bool {
408        // Size-based rotation takes priority when configured
409        if let Some(ref rotate_config) = self.file_config.file_rotate {
410            rotate_config.cur_file_size + next_line_size > rotate_config.max_file_size
411        // Otherwise, for default-named logs, rotate on UTC date change
412        } else if self.file_config.file_name.is_none() {
413            let today = today_date();
414            self.cur_file_date != today
415        // No rotation for custom-named logs without size-based rotation
416        } else {
417            false
418        }
419    }
420
421    fn rotate_file(&mut self) {
422        self.rotate_file_at(Timestamp::now());
423    }
424
425    fn rotate_file_at(&mut self, utc_now: Timestamp) {
426        let new_path = match Self::create_log_file_path(
427            &self.file_config,
428            &self.trader_id,
429            &self.instance_id,
430            self.json_format,
431            utc_now,
432        ) {
433            Ok(path) => path,
434            Err(e) => {
435                let _ = writeln!(
436                    io::stderr(),
437                    "{NAUTILUS_PREFIX} Error creating log directory for rotation: {e}"
438                );
439                self.reset_rotation_trigger(utc_now);
440                return;
441            }
442        };
443
444        if new_path == self.path {
445            // Rotation names have millisecond resolution: a second rotation within the same
446            // millisecond resolves to the active path. Keep writing to it; rotating would
447            // enqueue the active file as a backup where cleanup could delete it.
448            return;
449        }
450
451        let new_file = match File::options().create(true).append(true).open(&new_path) {
452            Ok(file) => file,
453            Err(e) => {
454                let _ = writeln!(
455                    io::stderr(),
456                    "{NAUTILUS_PREFIX} Error creating log file {}: {e}",
457                    new_path.display()
458                );
459                self.reset_rotation_trigger(utc_now);
460                return;
461            }
462        };
463
464        self.flush_and_sync_logged();
465
466        if let Some(rotate_config) = &mut self.file_config.file_rotate {
467            rotate_config.backup_files.push_back(self.path.clone());
468            cleanup_backups(rotate_config);
469        }
470
471        self.reset_rotation_trigger(utc_now);
472
473        self.buf = BufWriter::new(new_file);
474        self.path.clone_from(&new_path);
475        let _ = writeln!(
476            io::stderr(),
477            "{NAUTILUS_PREFIX} Rotated log file, now logging to: {}",
478            new_path.display()
479        );
480    }
481
482    // Also used on rotation failure so the retry waits for the next boundary, not the next line
483    fn reset_rotation_trigger(&mut self, utc_now: Timestamp) {
484        if let Some(rotate_config) = &mut self.file_config.file_rotate {
485            rotate_config.cur_file_size = 0;
486            rotate_config.cur_file_creation_date = utc_date(utc_now);
487        } else {
488            self.cur_file_date = utc_date(utc_now);
489        }
490    }
491
492    /// Flushes the userspace file buffer to the OS.
493    ///
494    /// # Errors
495    ///
496    /// Returns an error if the underlying file buffer cannot be flushed.
497    pub fn flush_buffer(&mut self) -> io::Result<()> {
498        self.buf.flush()
499    }
500
501    /// Requests that flushed file data is synchronized to durable storage.
502    ///
503    /// # Errors
504    ///
505    /// Returns an error if the operating system cannot sync the file to disk.
506    pub fn sync_to_disk(&mut self) -> io::Result<()> {
507        self.buf.get_ref().sync_all()
508    }
509
510    /// Flushes buffered file data and then syncs it to disk.
511    ///
512    /// # Errors
513    ///
514    /// Returns an error if either flushing the file buffer or syncing the file to disk fails.
515    pub fn flush_and_sync(&mut self) -> io::Result<()> {
516        let flush_result = self.flush_buffer();
517        let sync_result = self.sync_to_disk();
518        flush_result.and(sync_result)
519    }
520
521    /// Flushes and syncs while preserving the existing logging-on-error behavior.
522    pub fn flush_and_sync_logged(&mut self) {
523        let flush_result = self.flush_buffer();
524        if let Err(e) = flush_result {
525            let _ = writeln!(io::stderr(), "{NAUTILUS_PREFIX} Error flushing file: {e:?}");
526        }
527
528        let sync_result = self.sync_to_disk();
529        if let Err(e) = sync_result {
530            let _ = writeln!(io::stderr(), "{NAUTILUS_PREFIX} Error syncing file: {e:?}");
531        }
532    }
533}
534
535/// Clean up old backup files if we exceed the max backup count.
536///
537/// TODO: Minor consider using a more specific version to pop a single file
538/// since normal execution will not create more than 1 excess file
539fn cleanup_backups(rotate_config: &mut FileRotateConfig) {
540    // Remove oldest backup files until we are at or below max_backup_count
541    let excess = rotate_config
542        .backup_files
543        .len()
544        .saturating_sub(rotate_config.max_backup_count as usize);
545    for _ in 0..excess {
546        let Some(path) = rotate_config.backup_files.pop_front() else {
547            break;
548        };
549
550        if path.exists()
551            && let Err(e) = std::fs::remove_file(&path)
552        {
553            let _ = writeln!(
554                io::stderr(),
555                "{NAUTILUS_PREFIX} Failed to remove old log file {}: {e}",
556                path.display()
557            );
558        }
559    }
560}
561
562impl LogWriter for FileWriter {
563    fn write(&mut self, line: &str) {
564        let line = sanitize_file_line(line);
565        let line_size = line.len() as u64;
566
567        // Rotate file if needed (size-based or date-based depending on configuration)
568        if self.should_rotate_file(line_size) {
569            self.rotate_file();
570        }
571
572        if let Err(e) = self.buf.write_all(line.as_bytes()) {
573            let _ = writeln!(
574                io::stderr(),
575                "{NAUTILUS_PREFIX} Error writing to file: {e:?}"
576            );
577            return;
578        }
579
580        // Update current file size
581        if let Some(rotate_config) = &mut self.file_config.file_rotate {
582            rotate_config.cur_file_size += line_size;
583        }
584    }
585
586    fn flush(&mut self) {
587        if let Err(e) = self.flush_buffer() {
588            let _ = writeln!(io::stderr(), "{NAUTILUS_PREFIX} Error flushing file: {e:?}");
589        }
590
591        if self.sync_on_flush
592            && let Err(e) = self.sync_to_disk()
593        {
594            let _ = writeln!(io::stderr(), "{NAUTILUS_PREFIX} Error syncing file: {e:?}");
595        }
596    }
597
598    fn enabled(&self, line: &LogLine) -> bool {
599        line.level <= self.level
600    }
601}
602
603fn contains_ansi_escape(s: &str) -> bool {
604    s.as_bytes().contains(&b'\x1b')
605}
606
607fn contains_nonprinting_except_newline(s: &str) -> bool {
608    if s.is_ascii() {
609        return s.bytes().any(|b| b != b'\n' && (b < b' ' || b == b'\x7f'));
610    }
611
612    s.chars()
613        .any(|c| c != '\n' && (c.is_control() || c == '\u{7F}'))
614}
615
616fn strip_nonprinting_except_newline(s: &str) -> Cow<'_, str> {
617    if !contains_nonprinting_except_newline(s) {
618        return Cow::Borrowed(s);
619    }
620
621    Cow::Owned(strip_nonprinting_to_string(s))
622}
623
624fn strip_nonprinting_to_string(s: &str) -> String {
625    s.chars()
626        .filter(|&c| c == '\n' || (!c.is_control() && c != '\u{7F}'))
627        .collect()
628}
629
630fn sanitize_file_line(s: &str) -> Cow<'_, str> {
631    if !contains_ansi_escape(s) {
632        return strip_nonprinting_except_newline(s);
633    }
634
635    Cow::Owned(strip_ansi_and_nonprinting_to_string(s))
636}
637
638fn strip_ansi_and_nonprinting_to_string(s: &str) -> String {
639    let bytes = s.as_bytes();
640    let mut out = String::with_capacity(s.len());
641    let mut i = 0;
642
643    while i < bytes.len() {
644        if bytes[i] == b'\x1b' {
645            if let Some(end) = ansi_escape_end(bytes, i) {
646                i = end;
647            } else {
648                i += 1;
649            }
650            continue;
651        }
652
653        if bytes[i].is_ascii() {
654            if bytes[i] == b'\n' || (bytes[i] >= b' ' && bytes[i] != b'\x7f') {
655                out.push(bytes[i] as char);
656            }
657            i += 1;
658            continue;
659        }
660
661        let ch = s[i..]
662            .chars()
663            .next()
664            .expect("valid UTF-8 char boundary expected");
665
666        if ch == '\n' || (!ch.is_control() && ch != '\u{7F}') {
667            out.push(ch);
668        }
669        i += ch.len_utf8();
670    }
671
672    out
673}
674
675fn ansi_escape_end(bytes: &[u8], start: usize) -> Option<usize> {
676    match bytes.get(start + 1).copied() {
677        Some(b'[') => csi_escape_end(bytes, start + 2),
678        Some(b']') => osc_escape_end(bytes, start + 2),
679        _ => None,
680    }
681}
682
683fn csi_escape_end(bytes: &[u8], mut i: usize) -> Option<usize> {
684    while let Some(byte) = bytes.get(i).copied() {
685        if byte.is_ascii_alphabetic() {
686            return Some(i + 1);
687        }
688
689        if !matches!(byte, b'0'..=b'9' | b';' | b'?' | b'=') {
690            return None;
691        }
692        i += 1;
693    }
694
695    None
696}
697
698fn osc_escape_end(bytes: &[u8], mut i: usize) -> Option<usize> {
699    while let Some(byte) = bytes.get(i).copied() {
700        if byte == b'\x07' {
701            return Some(i + 1);
702        }
703        i += 1;
704    }
705
706    None
707}
708
709#[cfg(test)]
710mod tests {
711    use log::LevelFilter;
712    use rstest::rstest;
713    use smallvec::SmallVec;
714    use tempfile::tempdir;
715
716    use super::*;
717
718    #[rstest]
719    fn test_validate_accepts_default() {
720        assert!(FileWriterConfig::default().validate().is_ok());
721    }
722
723    #[rstest]
724    fn test_validate_rejects_empty_directory() {
725        let config = FileWriterConfig::new(Some(String::new()), None, None, None);
726        assert!(
727            matches!(config.validate(), Err(ConfigError::EmptyField { field }) if field == "file_config.directory")
728        );
729    }
730
731    #[rstest]
732    fn test_validate_rejects_empty_file_name() {
733        let config = FileWriterConfig::new(None, Some(String::new()), None, None);
734        assert!(
735            matches!(config.validate(), Err(ConfigError::EmptyField { field }) if field == "file_config.file_name")
736        );
737    }
738
739    #[rstest]
740    fn test_validate_rejects_zero_rotation_size() {
741        let config = FileWriterConfig::new(None, None, None, Some((0, 5)));
742        assert!(
743            matches!(config.validate(), Err(ConfigError::Range { field, .. }) if field == "file_config.file_rotate.max_file_size")
744        );
745    }
746
747    #[rstest]
748    fn test_file_writer_with_rotation_creates_new_timestamped_file() {
749        let temp_dir = tempdir().unwrap();
750
751        let config = FileWriterConfig {
752            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
753            file_name: Some("test".to_string()),
754            file_format: None,
755            file_rotate: Some(FileRotateConfig::from((2000, 5))),
756        };
757
758        let writer = FileWriter::new(
759            "TRADER-001".to_string(),
760            "instance-123".to_string(),
761            config,
762            LevelFilter::Info,
763            false,
764            true,
765        )
766        .unwrap();
767
768        assert_eq!(
769            writer
770                .file_config
771                .file_rotate
772                .as_ref()
773                .unwrap()
774                .cur_file_size,
775            0
776        );
777        assert!(writer.path.to_str().unwrap().contains("test_"));
778    }
779
780    fn fixed_rotation_time(millis: u32) -> Timestamp {
781        Offset::UTC
782            .to_timestamp(Date::new(2024, 1, 15).unwrap().at(
783                10,
784                30,
785                45,
786                i32::try_from(millis).unwrap() * 1_000_000,
787            ))
788            .unwrap()
789    }
790
791    #[rstest]
792    fn test_create_log_file_path_with_rotation_uses_portable_separator() {
793        let temp_dir = tempdir().unwrap();
794
795        let config = FileWriterConfig {
796            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
797            file_name: Some("test".to_string()),
798            file_format: None,
799            file_rotate: Some(FileRotateConfig::from((2000, 5))),
800        };
801
802        let path = FileWriter::create_log_file_path(
803            &config,
804            "TRADER-001",
805            "instance-123",
806            false,
807            fixed_rotation_time(123),
808        )
809        .unwrap();
810
811        let file_name = path.file_name().unwrap().to_str().unwrap();
812        assert_eq!(file_name, "test_2024-01-15_103045-123.log");
813    }
814
815    #[rstest]
816    fn test_create_log_file_path_with_rotation_default_name_uses_portable_separator() {
817        let config = FileWriterConfig {
818            directory: None,
819            file_name: None,
820            file_format: None,
821            file_rotate: Some(FileRotateConfig::from((2000, 5))),
822        };
823
824        let path = FileWriter::create_log_file_path(
825            &config,
826            "TRADER-001",
827            "instance-123",
828            false,
829            fixed_rotation_time(123),
830        )
831        .unwrap();
832
833        let file_name = path.file_name().unwrap().to_str().unwrap();
834        assert_eq!(
835            file_name,
836            "TRADER-001_2024-01-15_103045-123_instance-123.log"
837        );
838    }
839
840    #[rstest]
841    #[case::custom_name_with_extension_rotating(
842        Some("nautilus.log"),
843        "TRADER-001",
844        true,
845        "nautilus_2024-01-15_103045-123.log"
846    )]
847    #[case::custom_name_with_extension(Some("nautilus.log"), "TRADER-001", false, "nautilus.log")]
848    #[case::custom_name_with_other_extension(Some("app.v2"), "TRADER-001", false, "app.log")]
849    #[case::dotted_trader_id_rotating(
850        None,
851        "TRADER.A-001",
852        true,
853        "TRADER.A-001_2024-01-15_103045-123_instance-123.log"
854    )]
855    #[case::dotted_trader_id_daily(
856        None,
857        "TRADER.A-001",
858        false,
859        "TRADER.A-001_2024-01-15_instance-123.log"
860    )]
861    fn test_create_log_file_path_keeps_dotted_names(
862        #[case] file_name: Option<&str>,
863        #[case] trader_id: &str,
864        #[case] rotate: bool,
865        #[case] expected: &str,
866    ) {
867        let config = FileWriterConfig {
868            directory: None,
869            file_name: file_name.map(str::to_string),
870            file_format: None,
871            file_rotate: rotate.then(|| FileRotateConfig::from((2000, 5))),
872        };
873
874        let path = FileWriter::create_log_file_path(
875            &config,
876            trader_id,
877            "instance-123",
878            false,
879            fixed_rotation_time(123),
880        )
881        .unwrap();
882
883        assert_eq!(path.file_name().unwrap().to_str().unwrap(), expected);
884    }
885
886    #[rstest]
887    fn test_rotate_file_with_extension_in_name_moves_to_new_file() {
888        let temp_dir = tempdir().unwrap();
889
890        let config = FileWriterConfig {
891            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
892            file_name: Some("nautilus.log".to_string()),
893            file_format: None,
894            file_rotate: Some(FileRotateConfig::from((2000, 5))),
895        };
896
897        let mut writer = FileWriter::new(
898            "TRADER-001".to_string(),
899            "instance-123".to_string(),
900            config,
901            LevelFilter::Info,
902            false,
903            true,
904        )
905        .unwrap();
906        let first_path = writer.path.clone();
907
908        writer.rotate_file_at(fixed_rotation_time(123));
909
910        assert_ne!(writer.path, first_path);
911        assert_eq!(
912            writer
913                .file_config
914                .file_rotate
915                .as_ref()
916                .unwrap()
917                .backup_files,
918            VecDeque::from([first_path])
919        );
920    }
921
922    #[rstest]
923    #[case::file_open_fails(false)]
924    #[case::directory_create_fails(true)]
925    fn test_rotate_file_failure_keeps_active_file_until_next_boundary(
926        #[case] directory_fails: bool,
927    ) {
928        let temp_dir = tempdir().unwrap();
929
930        let config = FileWriterConfig {
931            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
932            file_name: Some("test".to_string()),
933            file_format: None,
934            file_rotate: Some(FileRotateConfig::from((2000, 5))),
935        };
936
937        let mut writer = FileWriter::new(
938            "TRADER-001".to_string(),
939            "instance-123".to_string(),
940            config,
941            LevelFilter::Info,
942            false,
943            true,
944        )
945        .unwrap();
946        let active_path = writer.path.clone();
947        writer.write(&"x".repeat(1999));
948        assert!(writer.should_rotate_file(2));
949
950        if directory_fails {
951            // A regular file in place of the log directory makes creating it fail
952            let blocking_file = temp_dir.path().join("not_a_directory");
953            std::fs::write(&blocking_file, "").unwrap();
954            writer.file_config.directory = Some(blocking_file.to_str().unwrap().to_string());
955        } else {
956            // A directory at the next rotation path makes opening the new file fail
957            std::fs::create_dir(temp_dir.path().join("test_2024-01-15_103045-123.log")).unwrap();
958        }
959
960        writer.rotate_file_at(fixed_rotation_time(123));
961
962        let rotate_config = writer.file_config.file_rotate.as_ref().unwrap();
963        assert_eq!(writer.path, active_path);
964        assert_eq!(rotate_config.cur_file_size, 0);
965        assert!(rotate_config.backup_files.is_empty());
966        assert!(!writer.should_rotate_file(2));
967    }
968
969    #[rstest]
970    fn test_rotate_file_same_millisecond_preserves_active_file() {
971        let temp_dir = tempdir().unwrap();
972
973        let config = FileWriterConfig {
974            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
975            file_name: Some("test".to_string()),
976            file_format: None,
977            file_rotate: Some(FileRotateConfig::from((2000, 0))),
978        };
979
980        let mut writer = FileWriter::new(
981            "TRADER-001".to_string(),
982            "instance-123".to_string(),
983            config,
984            LevelFilter::Info,
985            false,
986            true,
987        )
988        .unwrap();
989
990        let fixed = fixed_rotation_time(123);
991        writer.rotate_file_at(fixed);
992
993        let active_path = writer.path.clone();
994        assert!(active_path.exists());
995
996        // A second rotation within the same millisecond resolves to the same path and
997        // must not replace, enqueue, or delete the active file.
998        writer.rotate_file_at(fixed);
999
1000        assert_eq!(writer.path, active_path);
1001        assert!(active_path.exists());
1002
1003        writer.write("still logging\n");
1004        writer.flush_and_sync().unwrap();
1005
1006        assert!(active_path.exists());
1007        let contents = std::fs::read_to_string(&active_path).unwrap();
1008        assert!(contents.contains("still logging"));
1009    }
1010
1011    #[rstest]
1012    fn test_rotate_file_date_based_updates_file_and_creation_date() {
1013        let temp_dir = tempdir().unwrap();
1014
1015        let config = FileWriterConfig {
1016            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
1017            file_name: None,
1018            file_format: None,
1019            file_rotate: None,
1020        };
1021
1022        let mut writer = FileWriter::new(
1023            "TRADER-001".to_string(),
1024            "instance-123".to_string(),
1025            config,
1026            LevelFilter::Info,
1027            false,
1028            true,
1029        )
1030        .unwrap();
1031
1032        writer.rotate_file_at(fixed_rotation_time(123));
1033
1034        assert_eq!(writer.cur_file_date, utc_date(fixed_rotation_time(123)));
1035        let file_name = writer.path.file_name().unwrap().to_str().unwrap();
1036        assert_eq!(file_name, "TRADER-001_2024-01-15_instance-123.log");
1037    }
1038
1039    #[rstest]
1040    fn test_rotate_file_removes_previous_file_when_backup_count_zero() {
1041        let temp_dir = tempdir().unwrap();
1042
1043        let config = FileWriterConfig {
1044            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
1045            file_name: Some("test".to_string()),
1046            file_format: None,
1047            file_rotate: Some(FileRotateConfig::from((2000, 0))),
1048        };
1049
1050        let mut writer = FileWriter::new(
1051            "TRADER-001".to_string(),
1052            "instance-123".to_string(),
1053            config,
1054            LevelFilter::Info,
1055            false,
1056            true,
1057        )
1058        .unwrap();
1059
1060        writer.rotate_file_at(fixed_rotation_time(123));
1061        let first_path = writer.path.clone();
1062        assert!(first_path.exists());
1063
1064        writer.rotate_file_at(fixed_rotation_time(124));
1065
1066        assert_ne!(writer.path, first_path);
1067        assert!(
1068            !first_path.exists(),
1069            "previous rotated file should be removed with zero backup count"
1070        );
1071        assert!(writer.path.exists());
1072    }
1073
1074    #[rstest]
1075    #[case("Hello, World!", "Hello, World!")]
1076    #[case("Line1\nLine2", "Line1\nLine2")]
1077    #[case("Tab\there", "Tabhere")]
1078    #[case("Null\0char", "Nullchar")]
1079    #[case("DEL\u{7F}char", "DELchar")]
1080    #[case("Bell\u{07}sound", "Bellsound")]
1081    #[case("Mix\t\0\u{7F}ed", "Mixed")]
1082    fn test_strip_nonprinting_except_newline(#[case] input: &str, #[case] expected: &str) {
1083        let result = strip_nonprinting_except_newline(input);
1084        assert_eq!(result, expected);
1085    }
1086
1087    #[rstest]
1088    #[case("Plain text", "Plain text")]
1089    #[case("\x1B[31mRed\x1B[0m", "Red")]
1090    #[case("\x1B[1;32mBold Green\x1B[0m", "Bold Green")]
1091    #[case("Before\x1B[0mAfter", "BeforeAfter")]
1092    #[case("\x1B]0;Title\x07Content", "Content")]
1093    #[case("Text\t\x1B[31mRed\x1B[0m", "TextRed")]
1094    #[case("Broken\x1B[31", "Broken[31")]
1095    #[case("Broken\x1B]Title", "Broken]Title")]
1096    fn test_sanitize_file_line(#[case] input: &str, #[case] expected: &str) {
1097        let result = sanitize_file_line(input);
1098        assert_eq!(result, expected);
1099    }
1100
1101    #[rstest]
1102    fn test_sanitize_file_line_borrows_clean_input() {
1103        let result = sanitize_file_line("Plain text\n");
1104
1105        assert!(matches!(result, Cow::Borrowed(_)));
1106    }
1107
1108    #[rstest]
1109    fn test_file_writer_unwritable_directory_returns_error() {
1110        let temp_dir = tempdir().unwrap();
1111        let blocking_file = temp_dir.path().join("not_a_directory");
1112        std::fs::write(&blocking_file, "I am a file").unwrap();
1113        let directory = blocking_file.join("nested");
1114
1115        let config = FileWriterConfig {
1116            directory: Some(directory.to_str().unwrap().to_string()),
1117            file_name: Some("test".to_string()),
1118            file_format: None,
1119            file_rotate: None,
1120        };
1121
1122        let result = FileWriter::new(
1123            "TRADER-001".to_string(),
1124            "instance-123".to_string(),
1125            config,
1126            LevelFilter::Info,
1127            false,
1128            true,
1129        );
1130
1131        assert_eq!(
1132            result.unwrap_err().to_string(),
1133            format!("failed to create log directory {}", directory.display())
1134        );
1135    }
1136
1137    #[rstest]
1138    fn test_file_writer_directory_is_file_returns_error() {
1139        let temp_dir = tempdir().unwrap();
1140        let file_path = temp_dir.path().join("not_a_directory");
1141        std::fs::write(&file_path, "I am a file").unwrap();
1142
1143        let config = FileWriterConfig {
1144            directory: Some(file_path.to_str().unwrap().to_string()),
1145            file_name: Some("test".to_string()),
1146            file_format: None,
1147            file_rotate: None,
1148        };
1149
1150        let result = FileWriter::new(
1151            "TRADER-001".to_string(),
1152            "instance-123".to_string(),
1153            config,
1154            LevelFilter::Info,
1155            false,
1156            true,
1157        );
1158
1159        assert_eq!(
1160            result.unwrap_err().to_string(),
1161            format!("failed to create log directory {}", file_path.display())
1162        );
1163    }
1164
1165    #[rstest]
1166    fn test_file_writer_path_is_directory_returns_error() {
1167        let temp_dir = tempdir().unwrap();
1168        let blocking_dir = temp_dir.path().join("test.log");
1169        std::fs::create_dir(&blocking_dir).unwrap();
1170
1171        let config = FileWriterConfig {
1172            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
1173            file_name: Some("test".to_string()),
1174            file_format: None,
1175            file_rotate: None,
1176        };
1177
1178        let result = FileWriter::new(
1179            "TRADER-001".to_string(),
1180            "instance-123".to_string(),
1181            config,
1182            LevelFilter::Info,
1183            false,
1184            true,
1185        );
1186
1187        assert_eq!(
1188            result.unwrap_err().to_string(),
1189            format!("failed to open log file {}", blocking_dir.display())
1190        );
1191    }
1192
1193    #[rstest]
1194    fn test_file_writer_unrecognized_format_defaults_to_text() {
1195        let temp_dir = tempdir().unwrap();
1196
1197        let config = FileWriterConfig {
1198            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
1199            file_name: Some("test".to_string()),
1200            file_format: Some("invalid_format".to_string()),
1201            file_rotate: None,
1202        };
1203
1204        let writer = FileWriter::new(
1205            "TRADER-001".to_string(),
1206            "instance-123".to_string(),
1207            config,
1208            LevelFilter::Info,
1209            false,
1210            true,
1211        )
1212        .unwrap();
1213
1214        assert!(!writer.json_format);
1215        assert_eq!(writer.path.extension().unwrap(), "log");
1216    }
1217
1218    #[rstest]
1219    fn test_file_writer_json_format() {
1220        let temp_dir = tempdir().unwrap();
1221
1222        let config = FileWriterConfig {
1223            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
1224            file_name: Some("test".to_string()),
1225            file_format: Some("json".to_string()),
1226            file_rotate: None,
1227        };
1228
1229        let writer = FileWriter::new(
1230            "TRADER-001".to_string(),
1231            "instance-123".to_string(),
1232            config,
1233            LevelFilter::Info,
1234            false,
1235            true,
1236        )
1237        .unwrap();
1238
1239        assert!(writer.json_format);
1240        assert_eq!(writer.path.extension().unwrap(), "jsonl");
1241    }
1242
1243    #[rstest]
1244    fn test_file_writer_clear_log_file_truncates_existing_file() {
1245        let temp_dir = tempdir().unwrap();
1246
1247        let config = FileWriterConfig {
1248            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
1249            file_name: Some("test".to_string()),
1250            file_format: None,
1251            file_rotate: None,
1252        };
1253
1254        let existing_path = temp_dir.path().join("test.log");
1255        std::fs::write(&existing_path, "stale contents").unwrap();
1256        assert_eq!(
1257            std::fs::metadata(&existing_path).unwrap().len(),
1258            "stale contents".len() as u64
1259        );
1260
1261        let writer = FileWriter::new(
1262            "TRADER-001".to_string(),
1263            "instance-123".to_string(),
1264            config,
1265            LevelFilter::Info,
1266            true,
1267            true,
1268        )
1269        .unwrap();
1270
1271        assert_eq!(writer.path, existing_path);
1272        assert_eq!(std::fs::metadata(&existing_path).unwrap().len(), 0);
1273    }
1274
1275    #[rstest]
1276    fn test_file_writer_clear_log_file_false_preserves_existing_file() {
1277        let temp_dir = tempdir().unwrap();
1278
1279        let config = FileWriterConfig {
1280            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
1281            file_name: Some("test".to_string()),
1282            file_format: None,
1283            file_rotate: None,
1284        };
1285
1286        let existing_path = temp_dir.path().join("test.log");
1287        let existing_contents = "preserved contents";
1288        std::fs::write(&existing_path, existing_contents).unwrap();
1289
1290        let writer = FileWriter::new(
1291            "TRADER-001".to_string(),
1292            "instance-123".to_string(),
1293            config,
1294            LevelFilter::Info,
1295            false,
1296            true,
1297        )
1298        .unwrap();
1299
1300        assert_eq!(writer.path, existing_path);
1301        assert_eq!(
1302            std::fs::read_to_string(&existing_path).unwrap(),
1303            existing_contents
1304        );
1305    }
1306
1307    #[rstest]
1308    fn test_file_writer_sync_on_flush_can_be_disabled() {
1309        let temp_dir = tempdir().unwrap();
1310
1311        let config = FileWriterConfig {
1312            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
1313            file_name: Some("test".to_string()),
1314            file_format: None,
1315            file_rotate: None,
1316        };
1317
1318        let mut writer = FileWriter::new(
1319            "TRADER-001".to_string(),
1320            "instance-123".to_string(),
1321            config,
1322            LevelFilter::Info,
1323            false,
1324            false,
1325        )
1326        .unwrap();
1327
1328        assert!(!writer.sync_on_flush);
1329        writer.write("hello\n");
1330        writer.flush();
1331        writer.flush_and_sync().unwrap();
1332    }
1333
1334    #[rstest]
1335    fn test_stdout_writer_filters_error_level() {
1336        let writer = StdoutWriter::new(LevelFilter::Info, true, false);
1337
1338        // Error level should NOT be enabled for stdout (goes to stderr)
1339        let error_line = LogLine {
1340            timestamp: 0.into(),
1341            level: log::Level::Error,
1342            color: crate::enums::LogColor::Normal,
1343            component: ustr::Ustr::from("Test"),
1344            message: "error".to_string(),
1345            fields: SmallVec::new(),
1346        };
1347        assert!(!writer.enabled(&error_line));
1348
1349        // Info level should be enabled
1350        let info_line = LogLine {
1351            timestamp: 0.into(),
1352            level: log::Level::Info,
1353            color: crate::enums::LogColor::Normal,
1354            component: ustr::Ustr::from("Test"),
1355            message: "info".to_string(),
1356            fields: SmallVec::new(),
1357        };
1358        assert!(writer.enabled(&info_line));
1359
1360        // Debug should NOT be enabled when stdout level is Info
1361        let debug_line = LogLine {
1362            timestamp: 0.into(),
1363            level: log::Level::Debug,
1364            color: crate::enums::LogColor::Normal,
1365            component: ustr::Ustr::from("Test"),
1366            message: "debug".to_string(),
1367            fields: SmallVec::new(),
1368        };
1369        assert!(!writer.enabled(&debug_line));
1370    }
1371
1372    #[rstest]
1373    fn test_stderr_writer_only_enables_error_level() {
1374        let writer = StderrWriter::new(true);
1375
1376        let error_line = LogLine {
1377            timestamp: 0.into(),
1378            level: log::Level::Error,
1379            color: crate::enums::LogColor::Normal,
1380            component: ustr::Ustr::from("Test"),
1381            message: "error".to_string(),
1382            fields: SmallVec::new(),
1383        };
1384        assert!(writer.enabled(&error_line));
1385
1386        let warn_line = LogLine {
1387            timestamp: 0.into(),
1388            level: log::Level::Warn,
1389            color: crate::enums::LogColor::Normal,
1390            component: ustr::Ustr::from("Test"),
1391            message: "warn".to_string(),
1392            fields: SmallVec::new(),
1393        };
1394        assert!(!writer.enabled(&warn_line));
1395    }
1396}
nautilus_common/logging/writer.rs

nautilus_common/logging/
writer.rs
