Skip to main content

mountpoint_s3_fs/
logging.rs

1use std::backtrace::Backtrace;
2use std::fs::{DirBuilder, OpenOptions};
3use std::os::unix::fs::DirBuilderExt;
4use std::os::unix::prelude::OpenOptionsExt;
5use std::panic::{self, PanicHookInfo};
6use std::path::{Path, PathBuf};
7use std::thread;
8
9use anyhow::Context;
10use rand::RngExt;
11use signal_hook::consts::SIGUSR2;
12use signal_hook::iterator::{Handle as SignalsHandle, Signals};
13use time::OffsetDateTime;
14use time::format_description::FormatItem;
15use time::macros;
16use tracing::Span;
17use tracing_log::log::warn;
18use tracing_subscriber::filter::{EnvFilter, LevelFilter};
19use tracing_subscriber::layer::SubscriberExt;
20use tracing_subscriber::util::SubscriberInitExt;
21
22use mountpoint_s3_client::config::{AWSCRT_LOG_TARGET, RustLogAdapter};
23
24use crate::metrics::metrics_tracing_span_layer;
25
26#[cfg(test)]
27mod testing;
28
29mod envfilter;
30use envfilter::{ToggleableHandle, toggleable};
31
32#[cfg(feature = "event_log")]
33pub mod error_logger;
34mod syslog;
35use self::syslog::SyslogLayer;
36
37/// Configuration for Mountpoint logging.
38///
39/// This configuration struct is safe to use across forks.
40#[derive(Debug)]
41pub struct LoggingConfig {
42    /// File to write logs into. If unspecified, logs will be routed to syslog.
43    pub log_file: Option<PathBuf>,
44    /// Whether to duplicate logs to stdout in addition to syslog or the log directory.
45    pub log_to_stdout: bool,
46    /// The default filter directive (in the sense of [tracing_subscriber::filter::EnvFilter]) to
47    /// use for logs. Will be overridden by the `MOUNTPOINT_LOG` environment variable if set.
48    pub default_filter: String,
49}
50
51#[derive(Default)]
52/// A handle for logging that cleans up all allocated resources on drop.
53pub struct LoggingHandle {
54    _toggle_signal_handle: Option<ToggleSignalHandle>,
55}
56
57/// Set up all our logging infrastructure.
58///
59/// This method:
60/// - initializes the `tracing` subscriber for capturing log output
61/// - sets up the logging adapters for the CRT and for metrics
62/// - installs a panic hook to capture panics and log them with `tracing`
63/// - sets up a signal listener and toggles the logging verbosity each time it receives a `USR2` signal
64pub fn init_logging(config: LoggingConfig) -> anyhow::Result<LoggingHandle> {
65    let handle = init_tracing_subscriber(config)?;
66    install_panic_hook();
67    Ok(handle)
68}
69
70/// Record the object name in the current [Span].
71pub fn record_name(name: &str) {
72    Span::current().record("name", name);
73}
74
75/// For a given log directory, prepare a file name for this Mountpoint.
76///
77/// This may include a randomly generated component and return different results between invocations.
78pub fn prepare_log_file_name(log_directory: &Path) -> PathBuf {
79    let timestamp = log_file_name_time_suffix();
80
81    let random_suffix: String = rand::rng()
82        .sample_iter(&rand::distr::Alphanumeric)
83        .take(6)
84        .map(char::from)
85        .collect();
86    let file_name = format!("mountpoint-s3-{timestamp}.{random_suffix}.log");
87
88    log_directory.join(file_name)
89}
90
91fn log_file_name_time_suffix() -> String {
92    const TIMESTAMP_FORMAT: &[FormatItem<'static>] =
93        macros::format_description!("[year]-[month]-[day]T[hour]-[minute]-[second]Z");
94    OffsetDateTime::now_utc()
95        .format(TIMESTAMP_FORMAT)
96        .expect("couldn't format timestamp for log file name")
97}
98
99fn tracing_panic_hook(panic_info: &PanicHookInfo) {
100    let location = panic_info
101        .location()
102        .map(|l| format!("{l}"))
103        .unwrap_or_else(|| String::from("<unknown>"));
104
105    let payload = panic_info.payload();
106    let payload = if let Some(s) = payload.downcast_ref::<&'static str>() {
107        *s
108    } else if let Some(s) = payload.downcast_ref::<String>() {
109        s.as_str()
110    } else {
111        "<unknown payload>"
112    };
113
114    let thd = thread::current();
115
116    let backtrace = Backtrace::force_capture();
117
118    tracing::error!("panic on {thd:?} at {location}: {payload}");
119    tracing::error!("backtrace:\n{backtrace}");
120}
121
122fn install_panic_hook() {
123    let old_hook = panic::take_hook();
124    panic::set_hook(Box::new(move |panic_info| {
125        tracing_panic_hook(panic_info);
126        old_hook(panic_info);
127    }))
128}
129
130fn init_tracing_subscriber(config: LoggingConfig) -> anyhow::Result<LoggingHandle> {
131    // Don't create the files or subscribers if we'll never emit any logs
132    let default_filter = make_default_filter(config.default_filter.clone())();
133    if default_filter.max_level_hint() == Some(LevelFilter::OFF) {
134        return Ok(LoggingHandle::default());
135    }
136
137    RustLogAdapter::try_init().context("failed to initialize CRT logger")?;
138
139    let file_layer = if let Some(log_file_path) = &config.log_file {
140        // log directories and files created by Mountpoint should not be writable by other users
141        let mut dir_builder = DirBuilder::new();
142        dir_builder.recursive(true).mode(0o750);
143        let mut file_options = OpenOptions::new();
144        file_options.mode(0o640).append(true).create(true);
145
146        if let Some(parent_dir) = log_file_path.parent() {
147            dir_builder.create(parent_dir).context("failed to create log folder")?;
148        }
149        let file = file_options.open(log_file_path).context("failed to create log file")?;
150
151        let file_layer = tracing_subscriber::fmt::layer()
152            .with_ansi(false)
153            .with_thread_ids(true)
154            .with_writer(file);
155        Some(file_layer)
156    } else {
157        None
158    };
159
160    let syslog_layer: Option<SyslogLayer> = if config.log_file.is_none() {
161        // Don't fail if syslog isn't available on the system, since it's a default
162        SyslogLayer::new().ok()
163    } else {
164        None
165    };
166
167    let console_layer = if config.log_to_stdout {
168        Some(
169            tracing_subscriber::fmt::layer()
170                .with_ansi(supports_color::on(supports_color::Stream::Stdout).is_some())
171                .with_thread_ids(true),
172        )
173    } else {
174        None
175    };
176
177    let (filter, filter_handle) = toggleable(vec![
178        // Default logging verbosity (i.e., the one configured using `--debug`, `--debug-crt`, or `MOUNTPOINT_LOG` environment variable)
179        make_default_filter(config.default_filter),
180        // Debug logging for all except CRT (i.e., `debug,awscrt=off`)
181        make_filter(LevelFilter::DEBUG, LevelFilter::OFF),
182        // Debug logging for all (i.e., `debug,awscrt=debug`)
183        make_filter(LevelFilter::DEBUG, LevelFilter::DEBUG),
184        // Trace logging for all except CRT (i.e., `trace,awscrt=off`)
185        make_filter(LevelFilter::TRACE, LevelFilter::OFF),
186        // Trace logging for all (i.e., `trace,awscrt=trace`)
187        make_filter(LevelFilter::TRACE, LevelFilter::TRACE),
188    ]);
189
190    let toggle_signal_handle = toggle_filter_on_signals(vec![SIGUSR2], filter_handle)?;
191
192    tracing_subscriber::registry()
193        .with(filter)
194        .with(syslog_layer)
195        .with(file_layer)
196        .with(console_layer)
197        .with(metrics_tracing_span_layer())
198        .init();
199
200    Ok(LoggingHandle {
201        _toggle_signal_handle: Some(toggle_signal_handle),
202    })
203}
204
205/// Create a default logging filter from the `MOUNTPOINT_LOG` environment variable or the default config
206/// if that variable is unset.
207fn make_default_filter(default_directives: String) -> Box<dyn FnMut() -> EnvFilter + Send> {
208    Box::new(move || {
209        EnvFilter::try_from_env("MOUNTPOINT_LOG").unwrap_or_else(|_| EnvFilter::new(default_directives.clone()))
210    })
211}
212
213/// Create a logging filter using provided global and CRT [level](LevelFilter)s.
214fn make_filter(level: LevelFilter, crt_level: LevelFilter) -> Box<dyn FnMut() -> EnvFilter + Send> {
215    Box::new(move || EnvFilter::new(format!("{level},{AWSCRT_LOG_TARGET}={crt_level}")))
216}
217
218/// Creates a new thread to listen specified Unix signals, and toggles the log filter each time it receives a signal.
219/// Returns a [handle](ToggleSignalHandle), and cleans up signal listener and the created thread once the handle is dropped.
220fn toggle_filter_on_signals<S: 'static>(
221    signals: Vec<Signal>,
222    mut toggle_handle: ToggleableHandle<S>,
223) -> anyhow::Result<ToggleSignalHandle> {
224    let mut signals = Signals::new(signals)?;
225    let signals_handle = signals.handle();
226
227    let thread_handle = thread::spawn(move || {
228        for _ in &mut signals.forever() {
229            match toggle_handle.next() {
230                Ok(desc) => {
231                    warn!("Changed log verbosity to {desc}");
232                }
233                Err(err) => {
234                    warn!("Failed to change log verbosity: {err}");
235                }
236            }
237        }
238    });
239
240    Ok(ToggleSignalHandle {
241        signals_handle,
242        thread_handle: Some(thread_handle),
243    })
244}
245
246/// An Unix signal.
247type Signal = libc::c_int;
248
249/// A handle returned by [toggle_filter_on_signals] which cleans up all allocated resources on [drop](ToggleSignalHandle::drop).
250struct ToggleSignalHandle {
251    signals_handle: SignalsHandle,
252    thread_handle: Option<thread::JoinHandle<()>>,
253}
254
255impl Drop for ToggleSignalHandle {
256    fn drop(&mut self) {
257        if !self.signals_handle.is_closed() {
258            self.signals_handle.close();
259        }
260        if let Some(handle) = self.thread_handle.take() {
261            _ = handle.join();
262        }
263    }
264}