ant_logging/
lib.rs

1// Copyright 2024 MaidSafe.net limited.
2//
3// This SAFE Network Software is licensed to you under The General Public License (GPL), version 3.
4// Unless required by applicable law or agreed to in writing, the SAFE Network Software distributed
5// under the GPL Licence is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
6// KIND, either express or implied. Please review the Licences for the specific language governing
7// permissions and limitations relating to use of the SAFE Network Software.
8
9// Allow expect usage in logging initialization
10#![allow(clippy::expect_used)]
11// Allow enum variant names that end with Error as they come from external derives
12#![allow(clippy::enum_variant_names)]
13
14mod appender;
15mod error;
16mod layers;
17#[cfg(feature = "process-metrics")]
18pub mod metrics;
19
20use crate::error::Result;
21use layers::TracingLayers;
22use serde::{Deserialize, Serialize};
23use std::path::PathBuf;
24use tracing::info;
25use tracing_core::dispatcher::DefaultGuard;
26use tracing_subscriber::{prelude::__tracing_subscriber_SubscriberExt, util::SubscriberInitExt};
27
28pub use error::Error;
29pub use layers::ReloadHandle;
30pub use tracing_appender::non_blocking::WorkerGuard;
31
32// re-exporting the tracing crate's Level as it is used in our public API
33pub use tracing_core::Level;
34
35#[derive(Debug, Clone)]
36pub enum LogOutputDest {
37    Stderr,
38    Stdout,
39    Path(PathBuf),
40}
41
42impl LogOutputDest {
43    pub fn parse_from_str(val: &str) -> Result<Self> {
44        match val {
45            "stdout" => Ok(LogOutputDest::Stdout),
46            "data-dir" => {
47                // Get the current timestamp and format it to be human readable
48                let timestamp = chrono::Local::now().format("%Y-%m-%d_%H-%M-%S").to_string();
49
50                // Get the data directory path and append the timestamp to the log file name
51                let dir = match dirs_next::data_dir() {
52                    Some(dir) => dir
53                        .join("autonomi")
54                        .join("client")
55                        .join("logs")
56                        .join(format!("log_{timestamp}")),
57                    None => {
58                        return Err(Error::LoggingConfiguration(
59                            "could not obtain data directory path".to_string(),
60                        ));
61                    }
62                };
63                Ok(LogOutputDest::Path(dir))
64            }
65            // The path should be a directory, but we can't use something like `is_dir` to check
66            // because the path doesn't need to exist. We can create it for the user.
67            value => Ok(LogOutputDest::Path(PathBuf::from(value))),
68        }
69    }
70}
71
72impl std::fmt::Display for LogOutputDest {
73    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
74        match self {
75            LogOutputDest::Stderr => write!(f, "stderr"),
76            LogOutputDest::Stdout => write!(f, "stdout"),
77            LogOutputDest::Path(p) => write!(f, "{}", p.to_string_lossy()),
78        }
79    }
80}
81
82#[derive(Debug, Clone, Copy, Serialize, Deserialize, PartialEq, Eq)]
83pub enum LogFormat {
84    Default,
85    Json,
86}
87
88impl LogFormat {
89    pub fn parse_from_str(val: &str) -> Result<Self> {
90        match val {
91            "default" => Ok(LogFormat::Default),
92            "json" => Ok(LogFormat::Json),
93            _ => Err(Error::LoggingConfiguration(
94                "The only valid values for this argument are \"default\" or \"json\"".to_string(),
95            )),
96        }
97    }
98
99    pub fn as_str(&self) -> &'static str {
100        match self {
101            LogFormat::Default => "default",
102            LogFormat::Json => "json",
103        }
104    }
105}
106
107pub struct LogBuilder {
108    default_logging_targets: Vec<(String, Level)>,
109    output_dest: LogOutputDest,
110    format: LogFormat,
111    max_log_files: Option<usize>,
112    max_archived_log_files: Option<usize>,
113    /// Setting this would print the ant_logging related updates to stdout.
114    print_updates_to_stdout: bool,
115}
116
117impl LogBuilder {
118    /// Create a new builder
119    /// Provide the default_logging_targets that are used if the `ANT_LOG` env variable is not set.
120    ///
121    /// By default, we use log to the StdOut with the default format.
122    pub fn new(default_logging_targets: Vec<(String, Level)>) -> Self {
123        Self {
124            default_logging_targets,
125            output_dest: LogOutputDest::Stderr,
126            format: LogFormat::Default,
127            max_log_files: None,
128            max_archived_log_files: None,
129            print_updates_to_stdout: true,
130        }
131    }
132
133    /// Set the logging output destination
134    pub fn output_dest(&mut self, output_dest: LogOutputDest) {
135        self.output_dest = output_dest;
136    }
137
138    /// Set the logging format
139    pub fn format(&mut self, format: LogFormat) {
140        self.format = format
141    }
142
143    /// The max number of uncompressed log files to store
144    pub fn max_log_files(&mut self, files: usize) {
145        self.max_log_files = Some(files);
146    }
147
148    /// The max number of compressed files to store
149    pub fn max_archived_log_files(&mut self, files: usize) {
150        self.max_archived_log_files = Some(files);
151    }
152
153    /// Setting this to false would prevent ant_logging from printing things to stdout.
154    pub fn print_updates_to_stdout(&mut self, print: bool) {
155        self.print_updates_to_stdout = print;
156    }
157
158    /// Inits node logging, returning the NonBlocking guard if present.
159    /// This guard should be held for the life of the program.
160    ///
161    /// Logging should be instantiated only once.
162    pub fn initialize(self) -> Result<(ReloadHandle, Option<WorkerGuard>)> {
163        let mut layers = TracingLayers::default();
164
165        let reload_handle = layers.fmt_layer(
166            self.default_logging_targets.clone(),
167            &self.output_dest,
168            self.format,
169            self.max_log_files,
170            self.max_archived_log_files,
171            self.print_updates_to_stdout,
172        )?;
173
174        #[cfg(feature = "otlp")]
175        {
176            match std::env::var("OTEL_EXPORTER_OTLP_ENDPOINT") {
177                Ok(_) => layers.otlp_layer(self.default_logging_targets)?,
178                Err(_) => println!(
179                    "The OTLP feature is enabled but the OTEL_EXPORTER_OTLP_ENDPOINT variable is not \
180                set, so traces will not be submitted."
181                ),
182            }
183        }
184
185        if tracing_subscriber::registry()
186            .with(layers.layers)
187            .try_init()
188            .is_err()
189        {
190            eprintln!("Tried to initialize and set global default subscriber more than once");
191        }
192
193        Ok((reload_handle, layers.log_appender_guard))
194    }
195
196    /// Logs to the data_dir with per-test log files. Should be called from a single threaded tokio/non-tokio context.
197    /// Each test gets its own log file based on the test name.
198    ///
199    /// This function creates separate log files for each test to avoid mixing logs from different tests.
200    /// The test file name is automatically detected from the test module path.
201    /// subscriber.set_default() should be used if under a single threaded tokio / single threaded non-tokio context.
202    /// Refer here for more details: <https://github.com/tokio-rs/tracing/discussions/1626>
203    pub fn init_single_threaded_tokio_test() -> (Option<WorkerGuard>, DefaultGuard) {
204        let test_name = std::thread::current()
205            .name()
206            .unwrap_or("unknown_test")
207            .to_string();
208
209        // Auto-detect test file name from the test name
210        let test_file_name = Self::extract_test_file_name(&test_name);
211
212        let layers = Self::get_test_layers(&test_name, &test_file_name);
213        let log_guard = tracing_subscriber::registry()
214            .with(layers.layers)
215            .set_default();
216
217        info!("Running test: {test_name}");
218        (layers.log_appender_guard, log_guard)
219    }
220
221    /// Logs to the data_dir. Should be called from a multi threaded tokio context.
222    /// The test file name is automatically detected from the test module path.
223    ///
224    /// subscriber.init() should be used under multi threaded tokio context. If you have 1+ multithreaded tokio tests under
225    /// the same integration test, this might result in loss of logs. Hence use .init() (instead of .try_init()) to panic
226    /// if called more than once.
227    pub fn init_multi_threaded_tokio_test() -> Option<WorkerGuard> {
228        let test_name = std::thread::current()
229            .name()
230            .unwrap_or("unknown_test")
231            .to_string();
232
233        // Auto-detect test file name from the test name
234        let test_file_name = Self::extract_test_file_name(&test_name);
235
236        let layers = Self::get_test_layers(&test_name, &test_file_name);
237        tracing_subscriber::registry()
238        .with(layers.layers)
239        .try_init()
240        .expect("You have tried to init multi_threaded tokio logging twice\nRefer ant_logging::get_test_layers docs for more.");
241
242        layers.log_appender_guard
243    }
244
245    /// Extract the test file name from the test name.
246    /// Test names typically follow the pattern: module::path::test_name
247    /// We extract the module path and use it as the test file name.
248    fn extract_test_file_name(test_name: &str) -> String {
249        // Try to extract from structured test name first (e.g., "ant_bootstrap::tests::test_something")
250        if let Some(module_name) = Self::extract_from_structured_test_name(test_name) {
251            return module_name;
252        }
253
254        // For integration tests, try to extract from the current executable name
255        if let Some(integration_test_name) = Self::extract_from_executable_name() {
256            return integration_test_name;
257        }
258
259        // Fallback to the full test name if all parsing methods fail
260        test_name.to_string()
261    }
262
263    /// Extract module name from structured test names like "ant_bootstrap::tests::test_something"
264    fn extract_from_structured_test_name(test_name: &str) -> Option<String> {
265        let parts: Vec<&str> = test_name.split("::").collect();
266        if parts.len() >= 2 {
267            Some(parts[0].to_string())
268        } else {
269            None
270        }
271    }
272
273    /// Extract test name from the current executable for integration tests
274    fn extract_from_executable_name() -> Option<String> {
275        let current_exe = std::env::current_exe().ok()?;
276        let file_name = current_exe.file_name()?;
277        let exe_name = file_name.to_string_lossy();
278
279        // Integration test binaries are typically named like "test_name-<hash>"
280        // Extract the test file name part before the first dash
281        exe_name.split('-').next().map(|s| s.to_string())
282    }
283
284    /// Initialize just the fmt_layer for testing purposes with per-test log files.
285    ///
286    /// Each test gets its own log file based on the test name to avoid mixing logs.
287    /// Also overwrites the ANT_LOG variable to log everything including the test_file_name
288    fn get_test_layers(test_name: &str, test_file_name: &str) -> TracingLayers {
289        // overwrite ANT_LOG
290        // Use a more inclusive pattern to capture all logs from the test module
291        // For integration tests, we need to capture logs from the test file itself
292        let log_pattern = if test_file_name.contains("_tests") || test_file_name.contains("test_") {
293            // For integration tests, include the test file name directly
294            format!("{test_file_name}=TRACE,all,autonomi=DEBUG,all")
295        } else {
296            // For unit tests, use the original pattern
297            format!("{test_file_name}=TRACE,{test_file_name}::tests=TRACE,all,autonomi=DEBUG,all")
298        };
299
300        println!("Setting ANT_LOG to: {log_pattern}");
301
302        // SAFETY: This is called during test initialization before any other threads
303        // are spawned, so there's no risk of data races. Setting ANT_LOG is necessary
304        // to configure logging levels for test execution.
305        #[allow(unsafe_code)]
306        unsafe {
307            std::env::set_var("ANT_LOG", log_pattern);
308        }
309
310        let output_dest = match dirs_next::data_dir() {
311            Some(dir) => {
312                // Get the current timestamp and format it to be human readable
313                let timestamp = chrono::Local::now().format("%Y-%m-%d_%H-%M-%S").to_string();
314                // Create unique filename using test name and timestamp
315                let test_name = test_name.replace("::", "_").replace(" ", "_");
316                let path = dir
317                    .join("autonomi")
318                    .join("client")
319                    .join("logs")
320                    .join(format!("log_{timestamp}_{test_name}"));
321                LogOutputDest::Path(path)
322            }
323            None => LogOutputDest::Stdout,
324        };
325
326        println!("Logging test {test_name:?} from {test_file_name:?} to {output_dest:?}");
327
328        let mut layers = TracingLayers::default();
329
330        let _reload_handle = layers
331            .fmt_layer(vec![], &output_dest, LogFormat::Default, None, None, false)
332            .expect("Failed to get TracingLayers");
333        layers
334    }
335}
336
337#[cfg(test)]
338mod tests {
339    use crate::{ReloadHandle, layers::LogFormatter};
340    use color_eyre::Result;
341    use tracing::{Level, trace, warn};
342    use tracing_subscriber::{
343        Layer, Registry,
344        filter::Targets,
345        fmt as tracing_fmt,
346        layer::{Filter, SubscriberExt},
347        reload,
348        util::SubscriberInitExt,
349    };
350    use tracing_test::internal::global_buf;
351
352    #[test]
353    // todo: break down the TracingLayers so that we can plug in the writer without having to rewrite the whole function
354    // here.
355    fn reload_handle_should_change_log_levels() -> Result<()> {
356        // A mock write that writes to stdout + collects events to a global buffer. We can later read from this buffer.
357        let mock_writer = tracing_test::internal::MockWriter::new(global_buf());
358
359        // Constructing the fmt layer manually.
360        let layer = tracing_fmt::layer()
361            .with_ansi(false)
362            .with_target(false)
363            .event_format(LogFormatter)
364            .with_writer(mock_writer)
365            .boxed();
366
367        let test_target = "ant_logging::tests".to_string();
368        // to enable logs just for the test.
369        let target_filters: Box<dyn Filter<Registry> + Send + Sync> =
370            Box::new(Targets::new().with_targets(vec![(test_target.clone(), Level::TRACE)]));
371
372        // add the reload layer
373        let (filter, handle) = reload::Layer::new(target_filters);
374        let reload_handle = ReloadHandle(handle);
375        let layer = layer.with_filter(filter);
376        tracing_subscriber::registry().with(layer).try_init()?;
377
378        // Span is not controlled by the ReloadHandle. So we can set any span here.
379        let _span = tracing::info_span!("info span");
380
381        trace!("First trace event");
382
383        {
384            let buf = global_buf().lock().unwrap();
385
386            let events: Vec<&str> = std::str::from_utf8(&buf)
387                .expect("Logs contain invalid UTF8")
388                .lines()
389                .collect();
390            assert_eq!(events.len(), 1);
391            assert!(events[0].contains("First trace event"));
392        }
393
394        reload_handle.modify_log_level("ant_logging::tests=WARN")?;
395
396        // trace should not be logged now.
397        trace!("Second trace event");
398        warn!("First warn event");
399
400        {
401            let buf = global_buf().lock().unwrap();
402
403            let events: Vec<&str> = std::str::from_utf8(&buf)
404                .expect("Logs contain invalid UTF8")
405                .lines()
406                .collect();
407
408            assert_eq!(events.len(), 2);
409            assert!(events[0].contains("First trace event"));
410            assert!(events[1].contains("First warn event"));
411        }
412
413        Ok(())
414    }
415}
ant_logging/lib.rs

ant_logging/
lib.rs
