From 8e52ef2bbeaf963b2e5e26268b194dd8eb683d37 Mon Sep 17 00:00:00 2001 From: emabee Date: Fri, 2 Sep 2022 11:34:15 +0200 Subject: [PATCH] [0.23.1] Fix #116 - fix panic if `Naming::Timestamps` and `FileSpec::o_suffix(None)` are used and rotation happens within a second - Bump MSRV to 1.59 (because the `time` crate did this) - minor stuff --- .github/workflows/ci_test.yml | 2 +- CHANGELOG.md | 7 ++ Cargo.toml | 4 +- README.md | 2 +- scripts/cleanup.rs | 2 + scripts/qualify.rs | 6 +- src/primary_writer/std_writer.rs | 6 +- src/threads.rs | 2 +- src/writers/file_log_writer/builder.rs | 4 +- src/writers/file_log_writer/state.rs | 99 ++++++++++++++------------ src/writers/syslog_writer.rs | 1 - tests/test_restart_with_no_suffix.rs | 38 ++++++++++ tests/test_utils.rs | 5 +- 13 files changed, 118 insertions(+), 60 deletions(-) create mode 100644 tests/test_restart_with_no_suffix.rs diff --git a/.github/workflows/ci_test.yml b/.github/workflows/ci_test.yml index 0dadbe4..18a54f4 100644 --- a/.github/workflows/ci_test.yml +++ b/.github/workflows/ci_test.yml @@ -57,7 +57,7 @@ jobs: strategy: matrix: os: [ ubuntu-latest, windows-latest, macos-latest ] - rust: [ stable, 1.57.0 ] + rust: [ stable, 1.59.0 ] runs-on: ${{ matrix.os }} steps: - uses: actions/checkout@v2 diff --git a/CHANGELOG.md b/CHANGELOG.md index 8442d79..ef3e9cc 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,13 @@ All notable changes to this project will be documented in this file. The format is based on [Keep a Changelog](http://keepachangelog.com/en/1.0.0/) and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). +## [0.23.1] - 2022-09-02 + +Fix a panic that can happen if `Naming::Timestamps` and `FileSpec::o_suffix(None)` are used and +rotation happens within a second ([issue-116](https://github.com/emabee/flexi_logger/issues/116)). + +Bump MSRV to 1.59 (because the `time` crate did this). + ## [0.23.0] - 2022-08-04 Switch to edition 2021, use latest patch of `time` version "0.3", diff --git a/Cargo.toml b/Cargo.toml index 571fe77..a0dfc98 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "flexi_logger" -version = "0.23.0" +version = "0.23.1" authors = ["emabee "] categories = ["development-tools::debugging"] description = """ @@ -15,7 +15,7 @@ keywords = ["file", "logger"] license = "MIT OR Apache-2.0" readme = "README.md" repository = "https://github.com/emabee/flexi_logger" -rust-version = "1.57.0" +rust-version = "1.59.0" [lib] doctest = false diff --git a/README.md b/README.md index b4f7e55..e0606d9 100644 --- a/README.md +++ b/README.md @@ -58,7 +58,7 @@ See ## Minimal rust version -The earliest supported rust version is currently "1.57.0". +The earliest supported rust version is currently "1.59.0". ## Crate Features diff --git a/scripts/cleanup.rs b/scripts/cleanup.rs index 5f01a4e..a8202e8 100644 --- a/scripts/cleanup.rs +++ b/scripts/cleanup.rs @@ -12,6 +12,8 @@ fn main() { "./*.log", "./*.seclog", "./*logspec.toml", + "./log_files/**/.DS_Store", + "./log_files/**/test_restart_with_no_suffix-*", "./log_files/**/*.alerts", "./log_files/**/*.csv", "./log_files/**/*.err", diff --git a/scripts/qualify.rs b/scripts/qualify.rs index 9d92ce2..9569b3c 100644 --- a/scripts/qualify.rs +++ b/scripts/qualify.rs @@ -47,8 +47,8 @@ fn main() { // Build in important variants std::fs::remove_file("Cargo.lock").ok(); - run_command!("cargo", "+1.57.0", "build", "--no-default-features"); - run_command!("cargo", "+1.57.0", "build", "--all-features"); + run_command!("cargo", "+1.59.0", "build", "--no-default-features"); + run_command!("cargo", "+1.59.0", "build", "--all-features"); std::fs::remove_file("Cargo.lock").ok(); run_command!("cargo", "build"); @@ -65,7 +65,7 @@ fn main() { run_command!("cargo", "+nightly", "clippy", "--all-targets", "--all-features", "--", "-D", "warnings"); // Run tests in important variants - run_command!("cargo", "+1.57.0", "test", "--all-features"); + run_command!("cargo", "+1.59.0", "test", "--all-features"); run_command!("cargo", "test", "--release", "--all-features"); run_command!("cargo", "test", "--no-default-features"); run_command!("cargo", "test", "--release"); diff --git a/src/primary_writer/std_writer.rs b/src/primary_writer/std_writer.rs index fd16a3f..f025121 100644 --- a/src/primary_writer/std_writer.rs +++ b/src/primary_writer/std_writer.rs @@ -217,9 +217,9 @@ impl LogWriter for StdWriter { for tuple in expected { buf.clear(); reader.read_line(&mut buf).unwrap(); - assert!(buf.contains(&tuple.0), "Did not find tuple.0 = {}", tuple.0); - assert!(buf.contains(&tuple.1), "Did not find tuple.1 = {}", tuple.1); - assert!(buf.contains(&tuple.2), "Did not find tuple.2 = {}", tuple.2); + assert!(buf.contains(tuple.0), "Did not find tuple.0 = {}", tuple.0); + assert!(buf.contains(tuple.1), "Did not find tuple.1 = {}", tuple.1); + assert!(buf.contains(tuple.2), "Did not find tuple.2 = {}", tuple.2); } buf.clear(); reader.read_line(&mut buf).unwrap(); diff --git a/src/threads.rs b/src/threads.rs index dcf359d..c4b978d 100644 --- a/src/threads.rs +++ b/src/threads.rs @@ -84,7 +84,7 @@ pub(crate) fn start_specfile_watcher_thread( let debouncing_delay = std::time::Duration::from_millis(1000); let mut watcher = watcher(tx, debouncing_delay)?; watcher.watch( - &specfile.parent().unwrap(/*cannot fail*/), + specfile.parent().unwrap(/*cannot fail*/), RecursiveMode::NonRecursive, )?; diff --git a/src/writers/file_log_writer/builder.rs b/src/writers/file_log_writer/builder.rs index 9ed275e..47e7997 100644 --- a/src/writers/file_log_writer/builder.rs +++ b/src/writers/file_log_writer/builder.rs @@ -235,8 +235,8 @@ impl FileLogWriterBuilder { // make sure the folder exists or create it let dir = self.file_spec.get_directory(); let p_directory = Path::new(&dir); - std::fs::create_dir_all(&p_directory)?; - if !std::fs::metadata(&p_directory)?.is_dir() { + std::fs::create_dir_all(p_directory)?; + if !std::fs::metadata(p_directory)?.is_dir() { return Err(FlexiLoggerError::OutputBadDirectory); }; diff --git a/src/writers/file_log_writer/state.rs b/src/writers/file_log_writer/state.rs index a7a4f83..fdddca6 100644 --- a/src/writers/file_log_writer/state.rs +++ b/src/writers/file_log_writer/state.rs @@ -149,7 +149,7 @@ fn try_roll_state_from_criterion( } // max_size, current_size Criterion::AgeOrSize(age, size) => { let written_bytes = if config.append { - std::fs::metadata(&p_path)?.len() + std::fs::metadata(p_path)?.len() } else { 0 }; @@ -384,7 +384,7 @@ impl State { pub fn reopen_outputfile(&mut self) -> Result<(), std::io::Error> { if let Inner::Active(_, ref mut file, ref p_path) = self.inner { - match OpenOptions::new().create(true).append(true).open(&p_path) { + match OpenOptions::new().create(true).append(true).open(p_path) { Ok(f) => { // proved to work on standard windows, linux, mac *file = Box::new(f); @@ -397,7 +397,7 @@ impl State { *file = Box::new(OpenOptions::new().create(true).append(true).open(&dummy)?); remove_file(&dummy)?; - *file = Box::new(OpenOptions::new().create(true).append(true).open(&p_path)?); + *file = Box::new(OpenOptions::new().create(true).append(true).open(p_path)?); } } } @@ -453,21 +453,21 @@ fn validate_logs_in_file( .read_line(&mut buf) .expect("validate_logs: can't read file"); assert!( - buf.contains(&tuple.0), + buf.contains(tuple.0), "Did not find tuple.0 = {} in file {}; {}", tuple.0, path.display(), warning ); assert!( - buf.contains(&tuple.1), + buf.contains(tuple.1), "Did not find tuple.1 = {} in file {}; {}", tuple.1, path.display(), warning ); assert!( - buf.contains(&tuple.2), + buf.contains(tuple.2), "Did not find tuple.2 = {} in file {}; {}", tuple.2, path.display(), @@ -625,7 +625,7 @@ pub(crate) fn remove_or_compress_too_old_logfiles_impl( } // Moves the current file to the timestamp of the CURRENT file's creation date. -// If the rotation comes very fast, the new timestamp would be equal to the old one. +// If the rotation comes very fast, the new timestamp can be equal to the old one. // To avoid file collisions, we insert an additional string to the filename (".restart-"). // The number is incremented in case of repeated collisions. // Cleaning up can leave some restart-files with higher numbers; if we still are in the same @@ -634,15 +634,37 @@ fn rotate_output_file_to_date( creation_date: &OffsetDateTime, config: &FileLogWriterConfig, ) -> Result<(), std::io::Error> { - const INFIX_DATE: &[FormatItem<'static>] = - format_description!("_r[year]-[month]-[day]_[hour]-[minute]-[second]"); - let current_path = config.file_spec.as_pathbuf(Some(CURRENT_INFIX)); + let rotated_path = determine_new_name_for_rotate_output_file_to_date( + &config.file_spec, + config.use_utc, + creation_date, + ); + match std::fs::rename(¤t_path, &rotated_path) { + Ok(()) => Ok(()), + Err(e) => { + if e.kind() == std::io::ErrorKind::NotFound { + // current did not exist, so we had nothing to do + Ok(()) + } else { + Err(e) + } + } + } +} + +fn determine_new_name_for_rotate_output_file_to_date( + file_spec: &FileSpec, + use_utc: bool, + creation_date: &OffsetDateTime, +) -> PathBuf { + const INFIX_DATE: &[FormatItem<'static>] = + format_description!("_r[year]-[month]-[day]_[hour]-[minute]-[second]"); let infix_date_string = { // use utc if configured let mut infix_date: OffsetDateTime = *creation_date; - if config.use_utc { + if use_utc { let (h, m, s) = creation_date.offset().as_hms(); if h != 0 || m != 0 || s != 0 { infix_date -= @@ -651,36 +673,36 @@ fn rotate_output_file_to_date( } infix_date.format(INFIX_DATE).unwrap() }; - - let mut rotated_path = config.file_spec.as_pathbuf(Some(&infix_date_string)); - + let mut rotated_path = file_spec.as_pathbuf(Some(&infix_date_string)); // Search for rotated_path as is and for restart-siblings; // if any exists, find highest restart and add 1, else continue without restart let mut pattern = rotated_path.clone(); - pattern.set_extension(""); + if file_spec.o_suffix.is_some() { + pattern.set_extension(""); + } let mut pattern = pattern.to_string_lossy().to_string(); pattern.push_str(".restart-*"); - - let file_list = glob::glob(&pattern).unwrap(/*ok*/); - let mut vec: Vec = file_list.map(Result::unwrap).collect(); - vec.sort_unstable(); - - if (*rotated_path).exists() || !vec.is_empty() { - let mut number = if vec.is_empty() { + let mut restart_siblings: Vec = + glob::glob(&pattern).unwrap(/*ok*/).map(Result::unwrap).collect(); + restart_siblings.sort_unstable(); + if (*rotated_path).exists() || !restart_siblings.is_empty() { + let mut number = if restart_siblings.is_empty() { 0 } else { - rotated_path = vec.pop().unwrap(/*ok*/); - let file_stem = rotated_path - .file_stem() - .unwrap(/*ok*/) - .to_string_lossy() - .to_string(); - let index = file_stem.find(".restart-").unwrap(/*ok*/); - file_stem[(index + 9)..].parse::().unwrap(/*ok*/) + rotated_path = restart_siblings.pop().unwrap(/*ok*/); + let file_stem_string = if file_spec.o_suffix.is_some() { + rotated_path + .file_stem().unwrap(/*ok*/) + .to_string_lossy().to_string() + } else { + rotated_path.to_string_lossy().to_string() + }; + let index = file_stem_string.find(".restart-").unwrap(/*ok*/); + file_stem_string[(index + 9)..].parse::().unwrap(/*ok*/) }; while (*rotated_path).exists() { - rotated_path = config.file_spec.as_pathbuf(Some( + rotated_path = file_spec.as_pathbuf(Some( &infix_date_string .clone() .add(&format!(".restart-{:04}", number)), @@ -688,18 +710,7 @@ fn rotate_output_file_to_date( number += 1; } } - - match std::fs::rename(¤t_path, &rotated_path) { - Ok(()) => Ok(()), - Err(e) => { - if e.kind() == std::io::ErrorKind::NotFound { - // current did not exist, so we had nothing to do - Ok(()) - } else { - Err(e) - } - } - } + rotated_path } // Moves the current file to the name with the next rotate_idx and returns the next rotate_idx. @@ -772,7 +783,7 @@ mod platform { } // create new symlink - if let Err(e) = std::os::unix::fs::symlink(&logfile, link) { + if let Err(e) = std::os::unix::fs::symlink(logfile, link) { eprint_err(ERRCODE::Symlink, "cannot create symlink to logfile", &e); } } diff --git a/src/writers/syslog_writer.rs b/src/writers/syslog_writer.rs index 1b74683..cfc7fc3 100644 --- a/src/writers/syslog_writer.rs +++ b/src/writers/syslog_writer.rs @@ -257,7 +257,6 @@ impl LogWriter for SyslogWriter { match &self.syslog_type { SyslogType::Rfc3164 => { - #[allow(clippy::write_literal)] write!( cb.buf, "<{pri}>{timestamp} {tag}[{procid}]: {msg}", diff --git a/tests/test_restart_with_no_suffix.rs b/tests/test_restart_with_no_suffix.rs new file mode 100644 index 0000000..a79e6e5 --- /dev/null +++ b/tests/test_restart_with_no_suffix.rs @@ -0,0 +1,38 @@ +mod test_utils; + +use flexi_logger::{Cleanup, Criterion, FileSpec, Logger, Naming}; +use log::*; + +const COUNT: u8 = 2; + +#[test] +fn test_write_modes() { + if let Some(value) = test_utils::dispatch(COUNT) { + std::thread::sleep(std::time::Duration::from_millis(1000)); + work(value) + } +} + +fn work(value: u8) { + let directory = test_utils::dir(); + let file_spec = FileSpec::default() + .directory(&directory) + .o_suffix(match value { + 0 => None, + 1 => Some("log".to_string()), + COUNT..=std::u8::MAX => { + unreachable!("got unexpected value {}", value) + } + }); + + let _ = Logger::try_with_str("debug") + .unwrap() + .log_to_file(file_spec) + .rotate(Criterion::Size(100), Naming::Timestamps, Cleanup::Never) + .start() + .unwrap_or_else(|e| panic!("Logger initialization failed with {}", e)); + + for _ in 0..100 { + error!("This is an error message"); + } +} diff --git a/tests/test_utils.rs b/tests/test_utils.rs index a66bd29..710ebd2 100644 --- a/tests/test_utils.rs +++ b/tests/test_utils.rs @@ -38,8 +38,9 @@ pub fn add_prog_name(pb: &mut PathBuf) { pb.push(progname); } -// launch child process from same executable and sets there an additional environment variable -// or finds this environment variable and returns its value +// launch child processes from same executable and set for each of them an environment variable +// with a specific number, and then return None, +// or, in child processes, find this environment variable and return its value pub fn dispatch(count: u8) -> Option { match std::env::var(CTRL_INDEX) { Err(_) => {