Add random 6-character suffix to log file names

doc/LOGGING.md

@@ -20,6 +20,9 @@ You can direct logs to a file instead of syslog by providing a destination direc
 
 The directory will be created if it doesn't exist.
 A new log file will be created for each execution of `mount-s3`.
+
+Log file names are not considered stable and may change in the future.
+
 Both the directory and log files are created with read/write access for the process owner and read access for the process owner's group.
 Log files are not automatically rotated or cleaned up.
 

mountpoint-s3/CHANGELOG.md

@@ -1,5 +1,11 @@
 ## Unreleased
 
+### Breaking changes
+
+* When configured to log to a directory, Mountpoint now includes a random string following the timestamp in the file name.
+  Previously, multiple Mountpoint processes would write to the same log file causing log entries to be interleaved.
+  ([#1041](https://github.com/awslabs/mountpoint-s3/pull/1041))
+
 ## v1.9.1 (September 19, 2024)
 
 ### Other changes

mountpoint-s3/Cargo.toml

@@ -31,6 +31,7 @@ linked-hash-map = "0.5.6"
 metrics = "0.22.1"
 nix = { version = "0.29.0", default-features = false, features = ["fs", "process", "signal", "user"] }
 owo-colors = { version = "4.0.0", features = ["supports-colors"] }
+rand = "0.8.5"
 regex = "1.7.1"
 serde = { version = "1.0.190", features = ["derive"] }
 serde_json = "1.0.95"

mountpoint-s3/src/cli.rs

@@ -31,7 +31,7 @@ use crate::data_cache::{CacheLimit, DiskDataCache, DiskDataCacheConfig, ExpressD
 use crate::fs::{CacheConfig, S3FilesystemConfig, ServerSideEncryption, TimeToLive};
 use crate::fuse::session::FuseSession;
 use crate::fuse::S3FuseFilesystem;
-use crate::logging::{init_logging, LoggingConfig};
+use crate::logging::{init_logging, prepare_log_file_name, LoggingConfig};
 use crate::mem_limiter::MINIMUM_MEM_LIMIT;
 use crate::prefetch::{caching_prefetch, default_prefetch, Prefetch};
 use crate::prefix::Prefix;
@@ -438,30 +438,6 @@ impl CliArgs {
         None
     }
 
-    fn logging_config(&self) -> LoggingConfig {
-        let default_filter = if self.no_log {
-            String::from("off")
-        } else {
-            let mut filter = if self.debug {
-                String::from("debug")
-            } else {
-                String::from("warn")
-            };
-            let crt_verbosity = if self.debug_crt { "debug" } else { "off" };
-            filter.push_str(&format!(",{}={}", AWSCRT_LOG_TARGET, crt_verbosity));
-            if self.log_metrics {
-                filter.push_str(&format!(",{}=info", metrics::TARGET_NAME));
-            }
-            filter
-        };
-
-        LoggingConfig {
-            log_directory: self.log_directory.clone(),
-            log_to_stdout: self.foreground,
-            default_filter,
-        }
-    }
-
     /// Human-readable description of the bucket being mounted
     fn bucket_description(&self) -> String {
         if let Some(prefix) = self.prefix.as_ref() {
@@ -501,6 +477,36 @@ impl CliArgs {
     }
 }
 
+/// Generates a logging configuration based on the CLI arguments.
+///
+/// This includes random string generation which can change with each invocation,
+/// so once created the [LoggingConfig] should be cloned if another owned copy is required.
+fn logging_config(cli_args: &CliArgs) -> LoggingConfig {
+    let default_filter = if cli_args.no_log {
+        String::from("off")
+    } else {
+        let mut filter = if cli_args.debug {
+            String::from("debug")
+        } else {
+            String::from("warn")
+        };
+        let crt_verbosity = if cli_args.debug_crt { "debug" } else { "off" };
+        filter.push_str(&format!(",{}={}", AWSCRT_LOG_TARGET, crt_verbosity));
+        if cli_args.log_metrics {
+            filter.push_str(&format!(",{}=info", metrics::TARGET_NAME));
+        }
+        filter
+    };
+
+    let log_file = cli_args.log_directory.as_ref().map(|dir| prepare_log_file_name(dir));
+
+    LoggingConfig {
+        log_file,
+        log_to_stdout: cli_args.foreground,
+        default_filter,
+    }
+}
+
 pub fn main<ClientBuilder, Client, Runtime>(client_builder: ClientBuilder) -> anyhow::Result<()>
 where
     ClientBuilder: FnOnce(&CliArgs) -> anyhow::Result<(Client, Runtime, S3Personality)>,
@@ -515,7 +521,7 @@ where
     );
 
     if args.foreground {
-        init_logging(args.logging_config()).context("failed to initialize logging")?;
+        init_logging(logging_config(&args)).context("failed to initialize logging")?;
 
         let _metrics = metrics::install();
 
@@ -532,17 +538,20 @@ where
         // child process will report its status via this pipe.
         let (read_fd, write_fd) = nix::unistd::pipe().context("Failed to create a pipe")?;
 
+        // Prepare logging configuration up front, so the values are shared between the two processes.
+        let logging_config = logging_config(&args);
+
         // Don't share args across the fork. It should just be plain data, so probably fine to be
         // copy-on-write, but just in case we ever add something more fancy to the struct.
         drop(args);
 
         // SAFETY: Child process has full ownership of its resources.
-        // There is no shared data between parent and child processes.
+        // There is no shared data between parent and child processes other than logging configuration.
         let pid = unsafe { nix::unistd::fork() };
         match pid.expect("Failed to fork mount process") {
             ForkResult::Child => {
                 let args = CliArgs::parse();
-                init_logging(args.logging_config()).context("failed to initialize logging")?;
+                init_logging(logging_config).context("failed to initialize logging")?;
 
                 let _metrics = metrics::install();
 
@@ -584,9 +593,7 @@ where
                 }
             }
             ForkResult::Parent { child } => {
-                let args = CliArgs::parse();
-
-                init_logging(args.logging_config()).context("failed to initialize logging")?;
+                init_logging(logging_config).context("failed to initialize logging")?;
 
                 // close unused file descriptor, we only read from this end.
                 drop(write_fd);

mountpoint-s3/src/logging.rs

@@ -3,12 +3,13 @@ use std::fs::{DirBuilder, OpenOptions};
 use std::os::unix::fs::DirBuilderExt;
 use std::os::unix::prelude::OpenOptionsExt;
 use std::panic::{self, PanicInfo};
-use std::path::PathBuf;
+use std::path::{Path, PathBuf};
 use std::thread;
 
 use crate::metrics::metrics_tracing_span_layer;
 use anyhow::Context;
 use mountpoint_s3_crt::common::rust_log_adapter::RustLogAdapter;
+use rand::Rng;
 use time::format_description::FormatItem;
 use time::macros;
 use time::OffsetDateTime;
@@ -21,11 +22,13 @@ use tracing_subscriber::{Layer, Registry};
 mod syslog;
 use self::syslog::SyslogLayer;
 
-/// Configuration for Mountpoint logging
+/// Configuration for Mountpoint logging.
+///
+/// This configuration struct is safe to use across forks.
 #[derive(Debug)]
 pub struct LoggingConfig {
-    /// A directory to create log files in. If unspecified, logs will be routed to syslog.
-    pub log_directory: Option<PathBuf>,
+    /// File to write logs into. If unspecified, logs will be routed to syslog.
+    pub log_file: Option<PathBuf>,
     /// Whether to duplicate logs to stdout in addition to syslog or the log directory.
     pub log_to_stdout: bool,
     /// The default filter directive (in the sense of [tracing_subscriber::filter::EnvFilter]) to
@@ -45,6 +48,28 @@ pub fn init_logging(config: LoggingConfig) -> anyhow::Result<()> {
     Ok(())
 }
 
+/// For a given log directory, prepare a file name for this Mountpoint.
+///
+/// This may include a randomly generated component and return different results between invocations.
+pub fn prepare_log_file_name(log_directory: &Path) -> PathBuf {
+    let timestamp = {
+        const TIMESTAMP_FORMAT: &[FormatItem<'static>] =
+            macros::format_description!("[year]-[month]-[day]T[hour]-[minute]-[second]Z");
+        OffsetDateTime::now_utc()
+            .format(TIMESTAMP_FORMAT)
+            .expect("couldn't format timestamp for log file name")
+    };
+
+    let random_suffix: String = rand::thread_rng()
+        .sample_iter(&rand::distributions::Alphanumeric)
+        .take(6)
+        .map(char::from)
+        .collect();
+    let file_name = format!("mountpoint-s3-{timestamp}.{random_suffix}.log");
+
+    log_directory.join(file_name)
+}
+
 fn tracing_panic_hook(panic_info: &PanicInfo) {
     let location = panic_info
         .location()
@@ -92,23 +117,17 @@ fn init_tracing_subscriber(config: LoggingConfig) -> anyhow::Result<()> {
 
     RustLogAdapter::try_init().context("failed to initialize CRT logger")?;
 
-    let file_layer = if let Some(path) = &config.log_directory {
-        const LOG_FILE_NAME_FORMAT: &[FormatItem<'static>] =
-            macros::format_description!("mountpoint-s3-[year]-[month]-[day]T[hour]-[minute]-[second]Z.log");
-        let filename = OffsetDateTime::now_utc()
-            .format(LOG_FILE_NAME_FORMAT)
-            .context("couldn't format log file name")?;
-
-        // log directories and files created by Mountpoint should not be accessible by other users
+    let file_layer = if let Some(log_file_path) = &config.log_file {
+        // log directories and files created by Mountpoint should not be writable by other users
         let mut dir_builder = DirBuilder::new();
         dir_builder.recursive(true).mode(0o750);
         let mut file_options = OpenOptions::new();
         file_options.mode(0o640).append(true).create(true);
 
-        dir_builder.create(path).context("failed to create log folder")?;
-        let file = file_options
-            .open(path.join(filename))
-            .context("failed to create log file")?;
+        if let Some(parent_dir) = log_file_path.parent() {
+            dir_builder.create(parent_dir).context("failed to create log folder")?;
+        }
+        let file = file_options.open(log_file_path).context("failed to create log file")?;
 
         let file_layer = tracing_subscriber::fmt::layer()
             .with_ansi(false)
@@ -119,7 +138,7 @@ fn init_tracing_subscriber(config: LoggingConfig) -> anyhow::Result<()> {
         None
     };
 
-    let syslog_layer: Option<Filtered<_, _, Registry>> = if config.log_directory.is_none() {
+    let syslog_layer: Option<Filtered<_, _, Registry>> = if config.log_file.is_none() {
         // TODO decide how to configure the filter for syslog
         let env_filter = create_env_filter(&config.default_filter);
         // Don't fail if syslog isn't available on the system, since it's a default