mirror of
https://github.com/rustfs/rustfs.git
synced 2026-08-24 13:16:28 +00:00
refactor(obs): optimize logging with custom RollingAppender and improved cleanup (#2151)
Signed-off-by: houseme <housemecn@gmail.com> Signed-off-by: heihutu <30542132+heihutu@users.noreply.github.com> Co-authored-by: Copilot <198982749+Copilot@users.noreply.github.com> Co-authored-by: houseme <4829346+houseme@users.noreply.github.com> Co-authored-by: heihutu <30542132+heihutu@users.noreply.github.com> Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com>
This commit is contained in:
@@ -75,12 +75,25 @@ pub(super) fn build_env_filter(logger_level: &str, default_level: Option<&str>)
|
||||
.map(EnvFilter::new)
|
||||
.unwrap_or_else(|| EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new(level)));
|
||||
|
||||
// Suppress chatty infrastructure crates unless the operator explicitly
|
||||
// requests trace/debug output.
|
||||
if should_suppress_noisy_crates(logger_level, default_level, rust_log.as_deref()) {
|
||||
let directives: SmallVec<[&str; 5]> = smallvec::smallvec!["hyper", "tonic", "h2", "reqwest", "tower"];
|
||||
for directive in directives {
|
||||
filter = filter.add_directive(format!("{directive}=off").parse().unwrap());
|
||||
let directives: SmallVec<[(&str, &str); 6]> = smallvec::smallvec![
|
||||
("hyper", "off"),
|
||||
("tonic", "off"),
|
||||
("h2", "off"),
|
||||
("reqwest", "off"),
|
||||
("tower", "off"),
|
||||
// HTTP request logs are demoted to WARN to reduce volume in production.
|
||||
("rustfs::server::http", "warn"),
|
||||
];
|
||||
for (crate_name, level) in directives {
|
||||
match format!("{crate_name}={level}").parse() {
|
||||
Ok(directive) => filter = filter.add_directive(directive),
|
||||
Err(e) => {
|
||||
// The directive strings are compile-time constants, so this
|
||||
// branch should never be reached; emit a diagnostic just in case.
|
||||
eprintln!("obs: invalid log filter directive '{crate_name}={level}': {e}");
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@@ -32,6 +32,7 @@ use crate::cleaner::types::FileMatchMode;
|
||||
use crate::config::OtelConfig;
|
||||
use crate::global::OBSERVABILITY_METRIC_ENABLED;
|
||||
use crate::telemetry::filter::build_env_filter;
|
||||
use crate::telemetry::rolling::{RollingAppender, Rotation};
|
||||
use metrics::counter;
|
||||
use rustfs_config::observability::{
|
||||
DEFAULT_OBS_LOG_CLEANUP_INTERVAL_SECONDS, DEFAULT_OBS_LOG_COMPRESS_OLD_FILES, DEFAULT_OBS_LOG_COMPRESSED_FILE_RETENTION_DAYS,
|
||||
@@ -175,7 +176,7 @@ fn init_file_logging_internal(
|
||||
|
||||
// ── 3. Choose rotation strategy ──────────────────────────────────────────
|
||||
// `log_rotation_time` drives the rolling-appender rotation period.
|
||||
let rotation = config
|
||||
let rotation_str = config
|
||||
.log_rotation_time
|
||||
.as_deref()
|
||||
.unwrap_or(DEFAULT_LOG_ROTATION_TIME)
|
||||
@@ -187,28 +188,20 @@ fn init_file_logging_internal(
|
||||
_ => FileMatchMode::Suffix,
|
||||
};
|
||||
|
||||
use tracing_appender::rolling::{RollingFileAppender, Rotation};
|
||||
let file_appender = {
|
||||
let rotation = match rotation.as_str() {
|
||||
"minutely" => Rotation::MINUTELY,
|
||||
"hourly" => Rotation::HOURLY,
|
||||
_ => Rotation::DAILY,
|
||||
};
|
||||
|
||||
let mut builder = RollingFileAppender::builder()
|
||||
.rotation(rotation)
|
||||
.max_log_files(keep_files * 3); // Make sure there are some data files to archive to avoid premature deletion
|
||||
|
||||
match match_mode {
|
||||
FileMatchMode::Prefix => builder = builder.filename_prefix(log_filename),
|
||||
FileMatchMode::Suffix => builder = builder.filename_suffix(log_filename),
|
||||
}
|
||||
|
||||
builder
|
||||
.build(log_directory)
|
||||
.map_err(|e| TelemetryError::Io(format!("failed to initialize rolling file appender: {e}")))?
|
||||
let rotation = match rotation_str.as_str() {
|
||||
"minutely" => Rotation::Minutely,
|
||||
"hourly" => Rotation::Hourly,
|
||||
"daily" => Rotation::Daily,
|
||||
_ => Rotation::Daily,
|
||||
};
|
||||
|
||||
let max_single_file_size = config
|
||||
.log_max_single_file_size_bytes
|
||||
.unwrap_or(DEFAULT_OBS_LOG_MAX_SINGLE_FILE_SIZE_BYTES);
|
||||
|
||||
let file_appender =
|
||||
RollingAppender::new(log_directory, log_filename.to_string(), rotation, max_single_file_size, match_mode)?;
|
||||
|
||||
let (non_blocking, guard) = tracing_appender::non_blocking(file_appender);
|
||||
|
||||
// ── 4. Build subscriber layers ────────────────────────────────────────────
|
||||
@@ -270,7 +263,7 @@ fn init_file_logging_internal(
|
||||
|
||||
info!(
|
||||
"Init file logging at '{}', rotation: {}, keep {} files",
|
||||
log_directory, rotation, keep_files
|
||||
log_directory, rotation_str, keep_files
|
||||
);
|
||||
|
||||
Ok(OtelGuard {
|
||||
@@ -352,6 +345,7 @@ fn spawn_cleanup_task(
|
||||
// Use suffix matching for log files like "2026-03-01-06-21.rustfs.log"
|
||||
// where "rustfs.log" is the suffix.
|
||||
let file_pattern = config.log_filename.as_deref().unwrap_or(log_filename).to_string();
|
||||
let active_filename = file_pattern.clone();
|
||||
|
||||
// Determine match mode from config, defaulting to Suffix
|
||||
let match_mode = match config.log_match_mode.as_deref().map(|s| s.to_lowercase()).as_deref() {
|
||||
@@ -386,21 +380,21 @@ fn spawn_cleanup_task(
|
||||
.log_cleanup_interval_seconds
|
||||
.unwrap_or(DEFAULT_OBS_LOG_CLEANUP_INTERVAL_SECONDS);
|
||||
|
||||
let cleaner = Arc::new(LogCleaner::new(
|
||||
log_dir,
|
||||
file_pattern,
|
||||
match_mode,
|
||||
keep_files,
|
||||
max_total_size,
|
||||
max_single_file_size,
|
||||
compress,
|
||||
gzip_level,
|
||||
retention_days,
|
||||
exclude_patterns,
|
||||
delete_empty,
|
||||
min_age,
|
||||
dry_run,
|
||||
));
|
||||
let cleaner = Arc::new(
|
||||
LogCleaner::builder(log_dir, file_pattern, active_filename)
|
||||
.match_mode(match_mode)
|
||||
.keep_files(keep_files)
|
||||
.max_total_size_bytes(max_total_size)
|
||||
.max_single_file_size_bytes(max_single_file_size)
|
||||
.compress_old_files(compress)
|
||||
.gzip_compression_level(gzip_level)
|
||||
.compressed_file_retention_days(retention_days)
|
||||
.exclude_patterns(exclude_patterns)
|
||||
.delete_empty_files(delete_empty)
|
||||
.min_file_age_seconds(min_age)
|
||||
.dry_run(dry_run)
|
||||
.build(),
|
||||
);
|
||||
|
||||
tokio::spawn(async move {
|
||||
let mut interval = tokio::time::interval(Duration::from_secs(cleanup_interval));
|
||||
@@ -433,8 +427,13 @@ mod tests {
|
||||
..OtelConfig::default()
|
||||
};
|
||||
|
||||
let result = init_file_logging_internal(&config, temp_path, "info", true);
|
||||
|
||||
assert!(result.is_err());
|
||||
// We must run within a Tokio runtime because init_file_logging_internal spawns a background task.
|
||||
let rt = tokio::runtime::Runtime::new().unwrap();
|
||||
rt.block_on(async {
|
||||
let result = init_file_logging_internal(&config, temp_path, "info", true);
|
||||
// With eager file opening, an invalid filename (null byte) causes the OS to reject
|
||||
// the open() call, so the function returns Err instead of panicking.
|
||||
assert!(result.is_err(), "invalid filename must return Err, not panic");
|
||||
});
|
||||
}
|
||||
}
|
||||
|
||||
@@ -45,6 +45,7 @@ mod local;
|
||||
mod otel;
|
||||
mod recorder;
|
||||
mod resource;
|
||||
mod rolling;
|
||||
|
||||
use crate::TelemetryError;
|
||||
use crate::config::OtelConfig;
|
||||
@@ -117,8 +118,9 @@ pub(crate) fn init_telemetry(config: &OtelConfig) -> Result<OtelGuard, Telemetry
|
||||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
use super::*;
|
||||
use rustfs_config::observability::DEFAULT_OBS_ENVIRONMENT_PRODUCTION;
|
||||
use rustfs_config::{ENVIRONMENT, USE_STDOUT};
|
||||
use rustfs_config::{DEFAULT_OBS_LOG_STDOUT_ENABLED, ENVIRONMENT};
|
||||
|
||||
#[test]
|
||||
fn test_production_environment_detection() {
|
||||
@@ -160,7 +162,7 @@ mod tests {
|
||||
TestCase {
|
||||
is_production: false,
|
||||
config_use_stdout: None,
|
||||
expected_use_stdout: USE_STDOUT,
|
||||
expected_use_stdout: DEFAULT_OBS_LOG_STDOUT_ENABLED,
|
||||
description: "Non-production with no config should use default",
|
||||
},
|
||||
TestCase {
|
||||
@@ -184,7 +186,11 @@ mod tests {
|
||||
];
|
||||
|
||||
for case in &test_cases {
|
||||
let default_use_stdout = if case.is_production { false } else { USE_STDOUT };
|
||||
let default_use_stdout = if case.is_production {
|
||||
false
|
||||
} else {
|
||||
DEFAULT_OBS_LOG_STDOUT_ENABLED
|
||||
};
|
||||
let actual = case.config_use_stdout.unwrap_or(default_use_stdout);
|
||||
assert_eq!(actual, case.expected_use_stdout, "Test case failed: {}", case.description);
|
||||
}
|
||||
@@ -221,7 +227,6 @@ mod tests {
|
||||
#[test]
|
||||
fn test_otel_config_environment_defaults() {
|
||||
// Verify that environment field defaults behave correctly.
|
||||
use crate::config::OtelConfig;
|
||||
let config = OtelConfig {
|
||||
endpoint: "".to_string(),
|
||||
use_stdout: None,
|
||||
|
||||
@@ -0,0 +1,508 @@
|
||||
// Copyright 2024 RustFS Team
|
||||
//
|
||||
// Licensed under the Apache License, Version 2.0 (the "License");
|
||||
// you may not use this file except in compliance with the License.
|
||||
// You may obtain a copy of the License at
|
||||
//
|
||||
// http://www.apache.org/licenses/LICENSE-2.0
|
||||
//
|
||||
// Unless required by applicable law or agreed to in writing, software
|
||||
// distributed under the License is distributed on an "AS IS" BASIS,
|
||||
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
|
||||
// See the License for the specific language governing permissions and
|
||||
// limitations under the License.
|
||||
|
||||
//! A custom rolling file appender that supports both time-based and size-based rotation.
|
||||
//!
|
||||
//! This is a lightweight replacement for `tracing_appender::rolling::RollingFileAppender`
|
||||
//! which only supports time-based rotation. This implementation ensures that active
|
||||
//! log files do not grow indefinitely by rotating them when they exceed a configured size.
|
||||
|
||||
use crate::cleaner::types::FileMatchMode;
|
||||
use jiff::Zoned;
|
||||
use std::fs::{self, File};
|
||||
use std::io::{self, Write};
|
||||
use std::path::{Path, PathBuf};
|
||||
use std::sync::atomic::{AtomicU64, Ordering};
|
||||
use std::thread;
|
||||
use std::time::Duration;
|
||||
|
||||
#[derive(Debug, Clone, Copy)]
|
||||
pub enum Rotation {
|
||||
Minutely,
|
||||
Hourly,
|
||||
Daily,
|
||||
#[allow(dead_code)]
|
||||
Never,
|
||||
}
|
||||
|
||||
/// Global per-process counter used to disambiguate archive filenames that
|
||||
/// may otherwise collide when multiple rotations occur within the same
|
||||
/// timestamp tick.
|
||||
static ROLL_UNIQUIFIER: AtomicU64 = AtomicU64::new(0);
|
||||
|
||||
impl Rotation {
|
||||
fn check_should_roll(&self, last: i64, now: i64) -> bool {
|
||||
match self {
|
||||
Rotation::Minutely => now / 60 != last / 60,
|
||||
Rotation::Hourly => now / 3600 != last / 3600,
|
||||
Rotation::Daily => {
|
||||
// Align daily rotation with the local day boundary rather than UTC midnight.
|
||||
// We shift both timestamps by the current local offset before bucketing into days.
|
||||
let offset_secs = Zoned::now().offset().seconds() as i64;
|
||||
(now + offset_secs) / 86400 != (last + offset_secs) / 86400
|
||||
}
|
||||
Rotation::Never => false,
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
pub struct RollingAppender {
|
||||
dir: PathBuf,
|
||||
filename: String,
|
||||
rotation: Rotation,
|
||||
max_size_bytes: u64,
|
||||
match_mode: FileMatchMode,
|
||||
|
||||
file: Option<File>,
|
||||
size: u64,
|
||||
// Store as seconds since Unix epoch
|
||||
last_roll_ts: i64,
|
||||
}
|
||||
|
||||
impl RollingAppender {
|
||||
/// Create and immediately validate a new `RollingAppender`.
|
||||
///
|
||||
/// The log directory is created if it does not already exist, and the
|
||||
/// active log file is opened (or created) eagerly so that configuration
|
||||
/// errors — e.g. an invalid filename — surface at initialisation time
|
||||
/// rather than on the first write.
|
||||
///
|
||||
/// # Errors
|
||||
/// Returns an [`io::Error`] if:
|
||||
/// - `filename` is not a plain file name (absolute path, path separators,
|
||||
/// or `..` components are rejected to prevent path traversal).
|
||||
/// - The directory cannot be created.
|
||||
/// - The active log file cannot be opened/created.
|
||||
pub fn new(
|
||||
dir: impl AsRef<Path>,
|
||||
filename: String,
|
||||
rotation: Rotation,
|
||||
max_size_bytes: u64,
|
||||
match_mode: FileMatchMode,
|
||||
) -> io::Result<Self> {
|
||||
// Validate that `filename` is a plain file name: not absolute and no
|
||||
// directory components (separators or `..`). If `file_name()` equals
|
||||
// the entire path, there can be no parent-directory traversal.
|
||||
{
|
||||
let p = Path::new(&filename);
|
||||
let is_plain_name = !p.is_absolute() && p.file_name().map(|n| n == p.as_os_str()).unwrap_or(false);
|
||||
if !is_plain_name {
|
||||
return Err(io::Error::new(
|
||||
io::ErrorKind::InvalidInput,
|
||||
format!("log filename must be a plain file name with no path components, got: {filename:?}"),
|
||||
));
|
||||
}
|
||||
}
|
||||
|
||||
let mut appender = Self {
|
||||
dir: dir.as_ref().to_path_buf(),
|
||||
filename,
|
||||
rotation,
|
||||
max_size_bytes,
|
||||
match_mode,
|
||||
file: None,
|
||||
size: 0,
|
||||
last_roll_ts: Zoned::now().timestamp().as_second(),
|
||||
};
|
||||
// Eagerly open the file to validate the path and capture accurate
|
||||
// initial size / last-roll timestamp.
|
||||
appender.open_file()?;
|
||||
Ok(appender)
|
||||
}
|
||||
|
||||
fn active_file_path(&self) -> PathBuf {
|
||||
self.dir.join(&self.filename)
|
||||
}
|
||||
|
||||
fn open_file(&mut self) -> io::Result<()> {
|
||||
if self.file.is_some() {
|
||||
return Ok(());
|
||||
}
|
||||
|
||||
let path = self.active_file_path();
|
||||
// Ensure directory exists
|
||||
if let Some(parent) = path.parent() {
|
||||
fs::create_dir_all(parent)?;
|
||||
}
|
||||
|
||||
// Open in append mode
|
||||
let file = fs::OpenOptions::new().create(true).append(true).open(&path)?;
|
||||
|
||||
let meta = file.metadata()?;
|
||||
self.size = meta.len();
|
||||
|
||||
// Seed `last_roll_ts` from the file's modification time so that a
|
||||
// process restart correctly triggers time-based rotation if the active
|
||||
// file belongs to a previous period.
|
||||
if let Ok(modified) = meta.modified() {
|
||||
// Convert SystemTime to jiff::Timestamp
|
||||
if let Ok(ts) = jiff::Timestamp::try_from(modified) {
|
||||
self.last_roll_ts = ts.as_second();
|
||||
}
|
||||
}
|
||||
|
||||
self.file = Some(file);
|
||||
Ok(())
|
||||
}
|
||||
|
||||
fn should_roll(&self, write_len: u64) -> bool {
|
||||
// 1. Size-based check (Cheap, check first)
|
||||
// If max_size is set (non-zero) and writing would exceed it, roll immediately.
|
||||
if self.max_size_bytes > 0 && (self.size + write_len) > self.max_size_bytes {
|
||||
return true;
|
||||
}
|
||||
|
||||
// 2. Time-based check
|
||||
// We check this after size check to avoid unnecessary time calls if size forces a roll.
|
||||
let now = Zoned::now().timestamp().as_second();
|
||||
|
||||
self.rotation.check_should_roll(self.last_roll_ts, now)
|
||||
}
|
||||
|
||||
fn roll(&mut self) -> io::Result<()> {
|
||||
// 1. Close current file first to ensure all buffers are flushed to OS (if any)
|
||||
// and handle released.
|
||||
self.file = None;
|
||||
|
||||
let active_path = self.active_file_path();
|
||||
if !active_path.exists() {
|
||||
return Ok(());
|
||||
}
|
||||
|
||||
// 2. Generate archive name.
|
||||
// Format: YYYYMMDDHHMMSS.uuuuuu (Microsecond/Nanosecond precision)
|
||||
// We use jiff's strftime. "%Y%m%d%H%M%S%.6f" gives microsecond precision.
|
||||
let now = Zoned::now();
|
||||
let timestamp_str = now.strftime("%Y%m%d%H%M%S%.6f").to_string();
|
||||
|
||||
// Add a unique counter to prevent collisions in high-concurrency/fast-rotation scenarios.
|
||||
let counter = ROLL_UNIQUIFIER.fetch_add(1, Ordering::Relaxed);
|
||||
|
||||
// Final suffix/prefix part: timestamp + counter
|
||||
// Example: 20231027103001.123456-0
|
||||
let unique_part = format!("{}-{}", timestamp_str, counter);
|
||||
|
||||
// Match naming strategy with LogCleaner expectations.
|
||||
let archive_name = match self.match_mode {
|
||||
FileMatchMode::Suffix => {
|
||||
// Suffix mode: timestamp BEFORE filename.
|
||||
// e.g. rustfs.log -> 20231027103001.123456-0.rustfs.log
|
||||
format!("{}.{}", unique_part, self.filename)
|
||||
}
|
||||
FileMatchMode::Prefix => {
|
||||
// Prefix mode: timestamp AFTER filename.
|
||||
// e.g. rustfs -> rustfs.20231027103001.123456-0
|
||||
format!("{}.{}", self.filename, unique_part)
|
||||
}
|
||||
};
|
||||
|
||||
// 3. Rename the active file to the archive path.
|
||||
let archive_path = self.dir.join(&archive_name);
|
||||
|
||||
// Robust Rename Strategy:
|
||||
// On Windows, file locking (e.g. by AV software or indexers) can cause `rename` to fail
|
||||
// spuriously with PermissionDenied. We implement a short retry loop with backoff.
|
||||
const MAX_RETRIES: u32 = 3;
|
||||
let mut last_error = None;
|
||||
|
||||
for i in 0..MAX_RETRIES {
|
||||
match fs::rename(&active_path, &archive_path) {
|
||||
Ok(_) => {
|
||||
// Success!
|
||||
// 4. Reset state
|
||||
self.size = 0;
|
||||
self.last_roll_ts = now.timestamp().as_second();
|
||||
|
||||
// 5. Re-open (creates new active file)
|
||||
self.open_file()?;
|
||||
return Ok(());
|
||||
}
|
||||
Err(e) => {
|
||||
// Decide if we should retry based on error kind
|
||||
let should_retry = match e.kind() {
|
||||
// Windows often returns PermissionDenied for locked files
|
||||
io::ErrorKind::PermissionDenied => true,
|
||||
io::ErrorKind::Interrupted => true,
|
||||
_ => false,
|
||||
};
|
||||
|
||||
last_error = Some(e);
|
||||
|
||||
if !should_retry {
|
||||
break;
|
||||
}
|
||||
|
||||
// Exponential backoff: 10ms, 20ms, 40ms...
|
||||
thread::sleep(Duration::from_millis(10 * (1 << i)));
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// 6. Recovery Failure
|
||||
// If we exhausted retries, we MUST NOT lose log data.
|
||||
// We re-open the ACTIVE file (which is still there because rename failed).
|
||||
// The file will grow beyond max_size, but availability > strict sizing.
|
||||
eprintln!(
|
||||
"RollingAppender: Failed to rotate log file after {} retries. Error: {:?}",
|
||||
MAX_RETRIES, last_error
|
||||
);
|
||||
|
||||
// Attempt to re-open existing active file to allow continued writing
|
||||
self.open_file()?;
|
||||
|
||||
// Return the error so it can be logged/handled, even though we recovered the handle.
|
||||
Err(last_error.unwrap_or_else(|| io::Error::other("Unknown rename error")))
|
||||
}
|
||||
}
|
||||
|
||||
impl Write for RollingAppender {
|
||||
fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
|
||||
// Ensure file is open
|
||||
if self.file.is_none() {
|
||||
self.open_file()?;
|
||||
}
|
||||
|
||||
// Check rotation
|
||||
if self.should_roll(buf.len() as u64)
|
||||
&& let Err(e) = self.roll()
|
||||
{
|
||||
// If rotation fails, we log to stderr and try to continue writing to the active file
|
||||
// to avoid losing logs if possible.
|
||||
eprintln!("RollingAppender: failed to rotate log file: {}", e);
|
||||
}
|
||||
|
||||
// Ensure file is open (in case roll closed it and failed to open new one, or open_file failed above)
|
||||
if self.file.is_none() {
|
||||
self.open_file()?;
|
||||
}
|
||||
|
||||
if let Some(file) = &mut self.file {
|
||||
let n = file.write(buf)?;
|
||||
self.size += n as u64;
|
||||
Ok(n)
|
||||
} else {
|
||||
Err(io::Error::other("Failed to open log file"))
|
||||
}
|
||||
}
|
||||
|
||||
fn flush(&mut self) -> io::Result<()> {
|
||||
if let Some(file) = &mut self.file {
|
||||
file.flush()
|
||||
} else {
|
||||
Ok(())
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
use super::*;
|
||||
use std::fs;
|
||||
use tempfile::TempDir;
|
||||
|
||||
fn count_files(dir: &Path) -> usize {
|
||||
fs::read_dir(dir)
|
||||
.unwrap()
|
||||
.filter(|e| e.as_ref().unwrap().path().is_file())
|
||||
.count()
|
||||
}
|
||||
|
||||
// ── Construction ──────────────────────────────────────────────────────────
|
||||
|
||||
#[test]
|
||||
fn test_new_creates_file_eagerly() {
|
||||
let tmp = TempDir::new().unwrap();
|
||||
let _appender = RollingAppender::new(tmp.path(), "test.log".to_string(), Rotation::Daily, 0, FileMatchMode::Suffix)
|
||||
.expect("should create appender without error");
|
||||
assert!(tmp.path().join("test.log").exists(), "active log file should be created on new()");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_new_invalid_filename_returns_error() {
|
||||
let tmp = TempDir::new().unwrap();
|
||||
// Null byte is invalid on both Unix and Windows.
|
||||
let result = RollingAppender::new(tmp.path(), "invalid\0name.log".to_string(), Rotation::Daily, 0, FileMatchMode::Suffix);
|
||||
assert!(result.is_err(), "null byte in filename must produce an error");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_new_rejects_path_with_separators() {
|
||||
let tmp = TempDir::new().unwrap();
|
||||
// A filename containing path separators could escape the log directory.
|
||||
let result = RollingAppender::new(tmp.path(), "subdir/app.log".to_string(), Rotation::Daily, 0, FileMatchMode::Suffix);
|
||||
assert!(result.is_err(), "filename with path separator must be rejected");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_new_rejects_parent_directory_traversal() {
|
||||
let tmp = TempDir::new().unwrap();
|
||||
// "../secret.log" would write outside the log directory.
|
||||
let result = RollingAppender::new(tmp.path(), "../secret.log".to_string(), Rotation::Daily, 0, FileMatchMode::Suffix);
|
||||
assert!(result.is_err(), "parent-directory traversal in filename must be rejected");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_new_rejects_absolute_path_as_filename() {
|
||||
let tmp = TempDir::new().unwrap();
|
||||
let result = RollingAppender::new(tmp.path(), "/etc/app.log".to_string(), Rotation::Daily, 0, FileMatchMode::Suffix);
|
||||
assert!(result.is_err(), "absolute path as filename must be rejected");
|
||||
}
|
||||
|
||||
/// On Windows, backslash is a path separator and must be rejected.
|
||||
#[cfg(windows)]
|
||||
#[test]
|
||||
fn test_new_rejects_backslash_path_separator_on_windows() {
|
||||
let tmp = TempDir::new().unwrap();
|
||||
let result = RollingAppender::new(tmp.path(), "subdir\\app.log".to_string(), Rotation::Daily, 0, FileMatchMode::Suffix);
|
||||
assert!(result.is_err(), "backslash path separator in filename must be rejected on Windows");
|
||||
}
|
||||
|
||||
// ── Basic writes ──────────────────────────────────────────────────────────
|
||||
|
||||
#[test]
|
||||
fn test_write_stores_content() {
|
||||
let tmp = TempDir::new().unwrap();
|
||||
let mut appender =
|
||||
RollingAppender::new(tmp.path(), "test.log".to_string(), Rotation::Daily, 0, FileMatchMode::Suffix).unwrap();
|
||||
|
||||
appender.write_all(b"hello world\n").expect("write should succeed");
|
||||
appender.flush().expect("flush should succeed");
|
||||
|
||||
let content = fs::read_to_string(tmp.path().join("test.log")).unwrap();
|
||||
assert_eq!(content, "hello world\n");
|
||||
}
|
||||
|
||||
// ── Size-based rotation ────────────────────────────────────────────────────
|
||||
|
||||
#[test]
|
||||
fn test_size_rotation_creates_archive() {
|
||||
let tmp = TempDir::new().unwrap();
|
||||
// Allow only 5 bytes before rotating.
|
||||
let mut appender =
|
||||
RollingAppender::new(tmp.path(), "app.log".to_string(), Rotation::Never, 5, FileMatchMode::Suffix).unwrap();
|
||||
|
||||
// First write: 5 bytes exactly — no rotation yet.
|
||||
appender.write_all(b"12345").expect("write should succeed");
|
||||
// Second write: would push past the limit — rotation should occur first.
|
||||
appender.write_all(b"abcde").expect("write after rotation should succeed");
|
||||
appender.flush().unwrap();
|
||||
|
||||
// There should now be 2 files: the active log + 1 archive.
|
||||
assert_eq!(count_files(tmp.path()), 2, "one rotation should have produced one archive");
|
||||
|
||||
// The active file should only contain the second write.
|
||||
let content = fs::read_to_string(tmp.path().join("app.log")).unwrap();
|
||||
assert_eq!(content, "abcde");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_multiple_size_rotations_produce_unique_archives() {
|
||||
let tmp = TempDir::new().unwrap();
|
||||
// Force a rotation on every write of 4+ bytes.
|
||||
let mut appender =
|
||||
RollingAppender::new(tmp.path(), "app.log".to_string(), Rotation::Never, 3, FileMatchMode::Suffix).unwrap();
|
||||
|
||||
for _ in 0..5 {
|
||||
appender.write_all(b"abcd").expect("write should succeed");
|
||||
}
|
||||
appender.flush().unwrap();
|
||||
|
||||
let file_count = count_files(tmp.path());
|
||||
// At least 5 archives (one per rotation) plus the active file.
|
||||
assert!(
|
||||
file_count >= 5,
|
||||
"each burst write should produce a distinct archive; got {file_count} files"
|
||||
);
|
||||
}
|
||||
|
||||
// ── Archive filename format ────────────────────────────────────────────────
|
||||
|
||||
#[test]
|
||||
fn test_suffix_mode_archive_name() {
|
||||
let tmp = TempDir::new().unwrap();
|
||||
let mut appender =
|
||||
RollingAppender::new(tmp.path(), "app.log".to_string(), Rotation::Never, 3, FileMatchMode::Suffix).unwrap();
|
||||
|
||||
appender.write_all(b"1234").expect("write should succeed");
|
||||
appender.flush().unwrap();
|
||||
|
||||
let archives: Vec<_> = fs::read_dir(tmp.path())
|
||||
.unwrap()
|
||||
.filter_map(|e| e.ok())
|
||||
.map(|e| e.file_name().to_string_lossy().to_string())
|
||||
.filter(|n| n != "app.log")
|
||||
.collect();
|
||||
|
||||
assert_eq!(archives.len(), 1);
|
||||
// Suffix mode: "<timestamp>-<counter>.app.log"
|
||||
// Since timestamp contains digits and we use high precision, checking strictly is hard,
|
||||
// but it should definitely NOT be the old unix timestamp format (just digits).
|
||||
// It should contain "-" before "app.log" due to our new format.
|
||||
assert!(
|
||||
archives[0].ends_with(".app.log"),
|
||||
"archive should end with '.app.log' in Suffix mode; got '{}'",
|
||||
archives[0]
|
||||
);
|
||||
// Check for new format chars (YMD)
|
||||
// 20xx...
|
||||
assert!(
|
||||
archives[0].starts_with("20"),
|
||||
"archive should start with year (20xx); got '{}'",
|
||||
archives[0]
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_prefix_mode_archive_name() {
|
||||
let tmp = TempDir::new().unwrap();
|
||||
let mut appender =
|
||||
RollingAppender::new(tmp.path(), "app".to_string(), Rotation::Never, 3, FileMatchMode::Prefix).unwrap();
|
||||
|
||||
appender.write_all(b"1234").expect("write should succeed");
|
||||
appender.flush().unwrap();
|
||||
|
||||
let archives: Vec<_> = fs::read_dir(tmp.path())
|
||||
.unwrap()
|
||||
.filter_map(|e| e.ok())
|
||||
.map(|e| e.file_name().to_string_lossy().to_string())
|
||||
.filter(|n| n != "app")
|
||||
.collect();
|
||||
|
||||
assert_eq!(archives.len(), 1);
|
||||
// Prefix mode: "app.<timestamp>-<counter>"
|
||||
assert!(
|
||||
archives[0].starts_with("app.20"),
|
||||
"archive should start with 'app.20' in Prefix mode; got '{}'",
|
||||
archives[0]
|
||||
);
|
||||
}
|
||||
|
||||
// ── Restart with existing file ─────────────────────────────────────────────
|
||||
|
||||
#[test]
|
||||
fn test_restart_with_existing_file_reads_size() {
|
||||
let tmp = TempDir::new().unwrap();
|
||||
let log_path = tmp.path().join("app.log");
|
||||
fs::write(&log_path, b"existing content").unwrap();
|
||||
|
||||
let appender =
|
||||
RollingAppender::new(tmp.path(), "app.log".to_string(), Rotation::Daily, 0, FileMatchMode::Suffix).unwrap();
|
||||
|
||||
assert_eq!(
|
||||
appender.size,
|
||||
b"existing content".len() as u64,
|
||||
"size should reflect existing file content"
|
||||
);
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user