Skip to main content

nautilus_common/logging/
macros.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//! Colored logging macros for enhanced log output with automatic color mapping.
17
18/// Logs a trace message with automatic color mapping or custom color and component.
19///
20/// # Usage
21/// ```rust
22/// // Automatic color (normal)
23/// log_trace!("Processing tick data");
24///
25/// // Custom color
26/// log_trace!("Processing tick data", color = LogColor::Cyan);
27///
28/// // Custom component
29/// log_trace!("Processing data", component = "DataEngine");
30///
31/// // Both color and component (flexible order)
32/// log_trace!("Data processed", color = LogColor::Cyan, component = "DataEngine");
33/// log_trace!("Data processed", component = "DataEngine", color = LogColor::Cyan);
34/// ```
35#[macro_export]
36macro_rules! log_trace {
37    // Component only
38    ($msg:literal, component = $component:expr) => {
39        log::trace!(component = $component; $msg);
40    };
41    ($fmt:literal, $($args:expr),+, component = $component:expr) => {
42        log::trace!(component = $component; $fmt, $($args),+);
43    };
44
45    // Color only
46    ($msg:literal, color = $color:expr) => {
47        log::trace!(color = $color as u8; $msg);
48    };
49    ($fmt:literal, $($args:expr),+, color = $color:expr) => {
50        log::trace!(color = $color as u8; $fmt, $($args),+);
51    };
52
53    // Both color and component (color first)
54    ($msg:literal, color = $color:expr, component = $component:expr) => {
55        log::trace!(component = $component, color = $color as u8; $msg);
56    };
57    ($fmt:literal, $($args:expr),+, color = $color:expr, component = $component:expr) => {
58        log::trace!(component = $component, color = $color as u8; $fmt, $($args),+);
59    };
60
61    // Both color and component (component first)
62    ($msg:literal, component = $component:expr, color = $color:expr) => {
63        log::trace!(component = $component, color = $color as u8; $msg);
64    };
65    ($fmt:literal, $($args:expr),+, component = $component:expr, color = $color:expr) => {
66        log::trace!(component = $component, color = $color as u8; $fmt, $($args),+);
67    };
68
69    // Default (no color or component - auto-capture module path)
70    ($msg:literal) => {
71        log::trace!(component = module_path!(), color = $crate::enums::LogColor::Normal as u8; $msg);
72    };
73    ($fmt:literal, $($args:expr),+) => {
74        log::trace!(component = module_path!(), color = $crate::enums::LogColor::Normal as u8; $fmt, $($args),+);
75    };
76}
77
78/// Logs a debug message with automatic color mapping or custom color and component.
79///
80/// # Usage
81/// ```rust
82/// // Automatic color (normal)
83/// log_debug!("Validating order: {}", order_id);
84///
85/// // Custom color
86/// log_debug!("Validating order: {}", order_id, color = LogColor::Blue);
87///
88/// // Custom component
89/// log_debug!("Validating order", component = "RiskEngine");
90///
91/// // Both color and component (flexible order)
92/// log_debug!("Order validated", color = LogColor::Blue, component = "RiskEngine");
93/// log_debug!("Order validated", component = "RiskEngine", color = LogColor::Blue);
94/// ```
95#[macro_export]
96macro_rules! log_debug {
97    // Both color and component (color first)
98    ($msg:literal, color = $color:expr, component = $component:expr) => {
99        log::debug!(component = $component, color = $color as u8; $msg);
100    };
101    ($fmt:literal, $arg1:expr, color = $color:expr, component = $component:expr) => {
102        log::debug!(component = $component, color = $color as u8; $fmt, $arg1);
103    };
104    ($fmt:literal, $arg1:expr, $arg2:expr, color = $color:expr, component = $component:expr) => {
105        log::debug!(component = $component, color = $color as u8; $fmt, $arg1, $arg2);
106    };
107
108    // Both color and component (component first)
109    ($msg:literal, component = $component:expr, color = $color:expr) => {
110        log::debug!(component = $component, color = $color as u8; $msg);
111    };
112    ($fmt:literal, $arg1:expr, component = $component:expr, color = $color:expr) => {
113        log::debug!(component = $component, color = $color as u8; $fmt, $arg1);
114    };
115    ($fmt:literal, $arg1:expr, $arg2:expr, component = $component:expr, color = $color:expr) => {
116        log::debug!(component = $component, color = $color as u8; $fmt, $arg1, $arg2);
117    };
118
119    // Component only
120    ($msg:literal, component = $component:expr) => {
121        log::debug!(component = $component; $msg);
122    };
123    ($fmt:literal, $arg1:expr, component = $component:expr) => {
124        log::debug!(component = $component; $fmt, $arg1);
125    };
126    ($fmt:literal, $arg1:expr, $arg2:expr, component = $component:expr) => {
127        log::debug!(component = $component; $fmt, $arg1, $arg2);
128    };
129
130    // Color only
131    ($msg:literal, color = $color:expr) => {
132        log::debug!(color = $color as u8; $msg);
133    };
134    ($fmt:literal, $arg1:expr, color = $color:expr) => {
135        log::debug!(color = $color as u8; $fmt, $arg1);
136    };
137    ($fmt:literal, $arg1:expr, $arg2:expr, color = $color:expr) => {
138        log::debug!(color = $color as u8; $fmt, $arg1, $arg2);
139    };
140    ($fmt:literal, $arg1:expr, $arg2:expr, $arg3:expr, color = $color:expr) => {
141        log::debug!(color = $color as u8; $fmt, $arg1, $arg2, $arg3);
142    };
143
144    // Default (no color or component - auto-capture module path)
145    ($msg:literal) => {
146        log::debug!(component = module_path!(), color = $crate::enums::LogColor::Normal as u8; $msg);
147    };
148    ($fmt:literal, $($args:expr),+) => {
149        log::debug!(component = module_path!(), color = $crate::enums::LogColor::Normal as u8; $fmt, $($args),+);
150    };
151}
152
153/// Logs an info message with automatic color mapping or custom color and component.
154///
155/// # Usage
156/// ```rust
157/// // Automatic color (normal)
158/// log_info!("Order {} filled successfully", order_id);
159///
160/// // Custom color (e.g., green for success)
161/// log_info!("Order {} filled successfully", order_id, color = LogColor::Green);
162///
163/// // Custom component
164/// log_info!("Processing order", component = "OrderManager");
165///
166/// // Both color and component (flexible order)
167/// log_info!("Order filled", color = LogColor::Green, component = "OrderManager");
168/// log_info!("Order filled", component = "OrderManager", color = LogColor::Green);
169/// ```
170#[macro_export]
171macro_rules! log_info {
172    // Both color and component (color first)
173    ($msg:literal, color = $color:expr, component = $component:expr) => {
174        log::info!(component = $component, color = $color as u8; $msg);
175    };
176    ($fmt:literal, $arg1:expr, color = $color:expr, component = $component:expr) => {
177        log::info!(component = $component, color = $color as u8; $fmt, $arg1);
178    };
179    ($fmt:literal, $arg1:expr, $arg2:expr, color = $color:expr, component = $component:expr) => {
180        log::info!(component = $component, color = $color as u8; $fmt, $arg1, $arg2);
181    };
182
183    // Both color and component (component first)
184    ($msg:literal, component = $component:expr, color = $color:expr) => {
185        log::info!(component = $component, color = $color as u8; $msg);
186    };
187    ($fmt:literal, $arg1:expr, component = $component:expr, color = $color:expr) => {
188        log::info!(component = $component, color = $color as u8; $fmt, $arg1);
189    };
190    ($fmt:literal, $arg1:expr, $arg2:expr, component = $component:expr, color = $color:expr) => {
191        log::info!(component = $component, color = $color as u8; $fmt, $arg1, $arg2);
192    };
193
194    // Component only
195    ($msg:literal, component = $component:expr) => {
196        log::info!(component = $component; $msg);
197    };
198    ($fmt:literal, $arg1:expr, component = $component:expr) => {
199        log::info!(component = $component; $fmt, $arg1);
200    };
201    ($fmt:literal, $arg1:expr, $arg2:expr, component = $component:expr) => {
202        log::info!(component = $component; $fmt, $arg1, $arg2);
203    };
204
205    // Color only
206    ($msg:literal, color = $color:expr) => {
207        log::info!(color = $color as u8; $msg);
208    };
209    ($fmt:literal, $arg1:expr, color = $color:expr) => {
210        log::info!(color = $color as u8; $fmt, $arg1);
211    };
212    ($fmt:literal, $arg1:expr, $arg2:expr, color = $color:expr) => {
213        log::info!(color = $color as u8; $fmt, $arg1, $arg2);
214    };
215    ($fmt:literal, $arg1:expr, $arg2:expr, $arg3:expr, color = $color:expr) => {
216        log::info!(color = $color as u8; $fmt, $arg1, $arg2, $arg3);
217    };
218
219    // Default (no color or component - auto-capture module path)
220    ($msg:literal) => {
221        log::info!(component = module_path!(), color = $crate::enums::LogColor::Normal as u8; $msg);
222    };
223    ($fmt:literal, $($args:expr),+) => {
224        log::info!(component = module_path!(), color = $crate::enums::LogColor::Normal as u8; $fmt, $($args),+);
225    };
226}
227
228/// Logs a warning message with automatic yellow color or custom color and component.
229///
230/// # Usage
231/// ```rust
232/// // Automatic color (yellow)
233/// log_warn!("Position size approaching limit");
234///
235/// // Custom color
236/// log_warn!("Custom warning message", color = LogColor::Magenta);
237///
238/// // Custom component
239/// log_warn!("Risk limit exceeded", component = "RiskEngine");
240///
241/// // Both color and component (flexible order)
242/// log_warn!("Warning message", color = LogColor::Magenta, component = "RiskEngine");
243/// log_warn!("Warning message", component = "RiskEngine", color = LogColor::Magenta);
244/// ```
245#[macro_export]
246macro_rules! log_warn {
247    // Both color and component (color first)
248    ($msg:literal, color = $color:expr, component = $component:expr) => {
249        log::warn!(component = $component, color = $color as u8; $msg);
250    };
251    ($fmt:literal, $arg1:expr, color = $color:expr, component = $component:expr) => {
252        log::warn!(component = $component, color = $color as u8; $fmt, $arg1);
253    };
254    ($fmt:literal, $arg1:expr, $arg2:expr, color = $color:expr, component = $component:expr) => {
255        log::warn!(component = $component, color = $color as u8; $fmt, $arg1, $arg2);
256    };
257
258    // Both color and component (component first)
259    ($msg:literal, component = $component:expr, color = $color:expr) => {
260        log::warn!(component = $component, color = $color as u8; $msg);
261    };
262    ($fmt:literal, $arg1:expr, component = $component:expr, color = $color:expr) => {
263        log::warn!(component = $component, color = $color as u8; $fmt, $arg1);
264    };
265    ($fmt:literal, $arg1:expr, $arg2:expr, component = $component:expr, color = $color:expr) => {
266        log::warn!(component = $component, color = $color as u8; $fmt, $arg1, $arg2);
267    };
268
269    // Component only
270    ($msg:literal, component = $component:expr) => {
271        log::warn!(component = $component, color = $crate::enums::LogColor::Yellow as u8; $msg);
272    };
273    ($fmt:literal, $arg1:expr, component = $component:expr) => {
274        log::warn!(component = $component, color = $crate::enums::LogColor::Yellow as u8; $fmt, $arg1);
275    };
276    ($fmt:literal, $arg1:expr, $arg2:expr, component = $component:expr) => {
277        log::warn!(component = $component, color = $crate::enums::LogColor::Yellow as u8; $fmt, $arg1, $arg2);
278    };
279
280    // Color only
281    ($msg:literal, color = $color:expr) => {
282        log::warn!(color = $color as u8; $msg);
283    };
284    ($fmt:literal, $arg1:expr, color = $color:expr) => {
285        log::warn!(color = $color as u8; $fmt, $arg1);
286    };
287    ($fmt:literal, $arg1:expr, $arg2:expr, color = $color:expr) => {
288        log::warn!(color = $color as u8; $fmt, $arg1, $arg2);
289    };
290    ($fmt:literal, $arg1:expr, $arg2:expr, $arg3:expr, color = $color:expr) => {
291        log::warn!(color = $color as u8; $fmt, $arg1, $arg2, $arg3);
292    };
293
294    // Default (automatic yellow color, no component - auto-capture module path)
295    ($msg:literal) => {
296        log::warn!(component = module_path!(), color = $crate::enums::LogColor::Yellow as u8; $msg);
297    };
298    ($fmt:literal, $($args:expr),+) => {
299        log::warn!(component = module_path!(), color = $crate::enums::LogColor::Yellow as u8; $fmt, $($args),+);
300    };
301}
302
303/// Logs an error message with automatic red color or custom color and component.
304///
305/// # Usage
306/// ```rust
307/// // Automatic color (red)
308/// log_error!("Failed to connect to exchange: {}", error);
309///
310/// // Custom color
311/// log_error!("Custom error message", color = LogColor::Magenta);
312///
313/// // Custom component
314/// log_error!("Connection failed", component = "DataEngine");
315///
316/// // Both color and component (flexible order)
317/// log_error!("Critical error", color = LogColor::Magenta, component = "DataEngine");
318/// log_error!("Critical error", component = "DataEngine", color = LogColor::Magenta);
319/// ```
320#[macro_export]
321macro_rules! log_error {
322    // Both color and component (color first)
323    ($msg:literal, color = $color:expr, component = $component:expr) => {
324        log::error!(component = $component, color = $color as u8; $msg);
325    };
326    ($fmt:literal, $arg1:expr, color = $color:expr, component = $component:expr) => {
327        log::error!(component = $component, color = $color as u8; $fmt, $arg1);
328    };
329    ($fmt:literal, $arg1:expr, $arg2:expr, color = $color:expr, component = $component:expr) => {
330        log::error!(component = $component, color = $color as u8; $fmt, $arg1, $arg2);
331    };
332
333    // Both color and component (component first)
334    ($msg:literal, component = $component:expr, color = $color:expr) => {
335        log::error!(component = $component, color = $color as u8; $msg);
336    };
337    ($fmt:literal, $arg1:expr, component = $component:expr, color = $color:expr) => {
338        log::error!(component = $component, color = $color as u8; $fmt, $arg1);
339    };
340    ($fmt:literal, $arg1:expr, $arg2:expr, component = $component:expr, color = $color:expr) => {
341        log::error!(component = $component, color = $color as u8; $fmt, $arg1, $arg2);
342    };
343
344    // Component only
345    ($msg:literal, component = $component:expr) => {
346        log::error!(component = $component, color = $crate::enums::LogColor::Red as u8; $msg);
347    };
348    ($fmt:literal, $arg1:expr, component = $component:expr) => {
349        log::error!(component = $component, color = $crate::enums::LogColor::Red as u8; $fmt, $arg1);
350    };
351    ($fmt:literal, $arg1:expr, $arg2:expr, component = $component:expr) => {
352        log::error!(component = $component, color = $crate::enums::LogColor::Red as u8; $fmt, $arg1, $arg2);
353    };
354
355    // Color only
356    ($msg:literal, color = $color:expr) => {
357        log::error!(color = $color as u8; $msg);
358    };
359    ($fmt:literal, $arg1:expr, color = $color:expr) => {
360        log::error!(color = $color as u8; $fmt, $arg1);
361    };
362    ($fmt:literal, $arg1:expr, $arg2:expr, color = $color:expr) => {
363        log::error!(color = $color as u8; $fmt, $arg1, $arg2);
364    };
365    ($fmt:literal, $arg1:expr, $arg2:expr, $arg3:expr, color = $color:expr) => {
366        log::error!(color = $color as u8; $fmt, $arg1, $arg2, $arg3);
367    };
368
369    // Default (automatic red color, no component - auto-capture module path)
370    ($msg:literal) => {
371        log::error!(component = module_path!(), color = $crate::enums::LogColor::Red as u8; $msg);
372    };
373    ($fmt:literal, $($args:expr),+) => {
374        log::error!(component = module_path!(), color = $crate::enums::LogColor::Red as u8; $fmt, $($args),+);
375    };
376}
377
378// Re-exports
379pub use log_debug;
380pub use log_error;
381pub use log_info;
382pub use log_trace;
383pub use log_warn;
384
385// Gated out under `cfg(madsim)`: both tests drive the file-logging writer thread,
386// which is itself gated out under simulation (see `Logger::init_with_config`), so log
387// events are dropped and these tests would hang on `wait_until` waiting for a log file
388// that is never written. Logging is outside the determinism contract.
389#[cfg(all(test, not(all(feature = "simulation", madsim))))]
390mod tests {
391    use std::{thread::sleep, time::Duration};
392
393    use nautilus_core::UUID4;
394    use nautilus_model::identifiers::TraderId;
395    use rstest::*;
396    use tempfile::tempdir;
397
398    use crate::{
399        enums::LogColor,
400        logging::{
401            logger::{Logger, LoggerConfig},
402            logging_clock_set_static_mode, logging_clock_set_static_time,
403            writer::FileWriterConfig,
404        },
405        testing::wait_until,
406    };
407
408    #[rstest]
409    fn test_colored_logging_macros() {
410        let config = LoggerConfig::from_spec("stdout=Trace;fileout=Trace;is_colored").unwrap();
411
412        let temp_dir = tempdir().expect("Failed to create temporary directory");
413        let file_config = FileWriterConfig {
414            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
415            ..Default::default()
416        };
417
418        let log_guard = Logger::init_with_config(
419            TraderId::from("TRADER-001"),
420            UUID4::new(),
421            config,
422            file_config,
423        )
424        .expect("Failed to initialize logger");
425
426        logging_clock_set_static_mode();
427        logging_clock_set_static_time(1_650_000_000_000_000);
428
429        // Test automatic color mappings using explicit components to ensure they're written
430        log_trace!("This is a trace message", component = "TestComponent");
431        log_debug!("This is a debug message", component = "TestComponent");
432        log_info!("This is an info message", component = "TestComponent");
433        log_warn!("This is a warning message", component = "TestComponent");
434        log_error!("This is an error message", component = "TestComponent");
435
436        // Test custom colors
437        log_info!(
438            "Success message",
439            color = LogColor::Green,
440            component = "TestComponent"
441        );
442        log_info!(
443            "Information message",
444            color = LogColor::Blue,
445            component = "TestComponent"
446        );
447        log_warn!(
448            "Custom warning",
449            component = "TestComponent",
450            color = LogColor::Magenta
451        );
452
453        // Test component only
454        log_info!("Component test", component = "TestComponent");
455        log_warn!("Component warning", component = "TestComponent");
456
457        // Test both color and component (different orders)
458        log_info!(
459            "Color then component",
460            color = LogColor::Cyan,
461            component = "TestComponent"
462        );
463
464        // Allow time for logs to be written
465        sleep(Duration::from_millis(200));
466
467        drop(log_guard);
468
469        // Wait until log file exists and has contents
470        let mut log_contents = String::new();
471        wait_until(
472            || {
473                if let Some(log_file) = std::fs::read_dir(&temp_dir)
474                    .expect("Failed to read directory")
475                    .filter_map(Result::ok)
476                    .find(|entry| entry.path().is_file())
477                {
478                    let log_file_path = log_file.path();
479                    log_contents =
480                        std::fs::read_to_string(log_file_path).expect("Failed to read log file");
481                    !log_contents.is_empty()
482                } else {
483                    false
484                }
485            },
486            Duration::from_secs(3),
487        );
488
489        // Debug: print file contents if test is failing
490        if !log_contents.contains("This is a trace message") {
491            println!("File contents:\n{log_contents}");
492        }
493
494        // Verify that all log levels are present
495        assert!(log_contents.contains("This is a trace message"));
496        assert!(log_contents.contains("This is a debug message"));
497        assert!(log_contents.contains("This is an info message"));
498        assert!(log_contents.contains("This is a warning message"));
499        assert!(log_contents.contains("This is an error message"));
500        assert!(log_contents.contains("Success message"));
501        assert!(log_contents.contains("Information message"));
502        assert!(log_contents.contains("Custom warning"));
503
504        // Verify component and color combinations
505        assert!(log_contents.contains("Component test"));
506        assert!(log_contents.contains("Component warning"));
507        assert!(log_contents.contains("Color then component"));
508    }
509
510    #[rstest]
511    fn test_default_macro_captures_module_path() {
512        // This test verifies that log macros without explicit component
513        // auto-capture module_path!() as the component.
514        //
515        // The module path for this test is: nautilus_common::logging::macros::tests
516        // We configure a module filter and verify the log is filtered/passed accordingly.
517
518        let config = LoggerConfig::from_spec(
519            "stdout=Off;fileout=Trace;nautilus_common::logging::macros=Debug",
520        )
521        .unwrap();
522
523        let temp_dir = tempdir().expect("Failed to create temporary directory");
524        let file_config = FileWriterConfig {
525            directory: Some(temp_dir.path().to_str().unwrap().to_string()),
526            ..Default::default()
527        };
528
529        let log_guard = Logger::init_with_config(
530            TraderId::from("TRADER-PATH"),
531            UUID4::new(),
532            config,
533            file_config,
534        )
535        .expect("Failed to initialize logger");
536
537        logging_clock_set_static_mode();
538        logging_clock_set_static_time(1_650_000_000_000_000);
539
540        // Call macros WITHOUT explicit component - should auto-capture module_path!()
541        log_info!("Auto-captured module path message");
542        log_debug!("Debug level auto-captured");
543
544        // This trace should be filtered (module filter is Debug, Trace > Debug)
545        log_trace!("Trace should be filtered SHOULD_NOT_APPEAR");
546
547        sleep(Duration::from_millis(200));
548        drop(log_guard);
549
550        let mut log_contents = String::new();
551        wait_until(
552            || {
553                if let Some(log_file) = std::fs::read_dir(&temp_dir)
554                    .expect("Failed to read directory")
555                    .filter_map(Result::ok)
556                    .find(|entry| entry.path().is_file())
557                {
558                    log_contents =
559                        std::fs::read_to_string(log_file.path()).expect("Failed to read log file");
560                    !log_contents.is_empty()
561                } else {
562                    false
563                }
564            },
565            Duration::from_secs(3),
566        );
567
568        assert!(
569            log_contents.contains("nautilus_common::logging::macros"),
570            "Component should contain module path, was:\n{log_contents}"
571        );
572        assert!(
573            log_contents.contains("Auto-captured module path message"),
574            "Info message should pass"
575        );
576        assert!(
577            log_contents.contains("Debug level auto-captured"),
578            "Debug message should pass"
579        );
580        assert!(
581            !log_contents.contains("SHOULD_NOT_APPEAR"),
582            "Trace should be filtered by module filter"
583        );
584    }
585}