[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

@@ -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

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",

Cargo.toml

@@ -1,6 +1,6 @@
 [package]
 name = "flexi_logger"
-version = "0.23.0"
+version = "0.23.1"
 authors = ["emabee <meinolf.block@sap.com>"]
 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

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
 

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",

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");

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();

src/threads.rs

@@ -84,7 +84,7 @@ pub(crate) fn start_specfile_watcher_thread<S: LogSpecSubscriber>(
     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,
     )?;
 

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);
         };
 

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-<number>").
 // 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(&current_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,55 +673,44 @@ 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<PathBuf> = 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<PathBuf> =
+        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::<usize>().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::<usize>().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)),
             ));
             number += 1;
         }
     }
-
-    match std::fs::rename(&current_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);
         }
     }

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}",

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");
+    }
+}

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<u8> {
     match std::env::var(CTRL_INDEX) {
         Err(_) => {