From 48ab6dfbd535fbd5e673f94239635c56ffa837f0 Mon Sep 17 00:00:00 2001 From: Rui Fan <1996fanrui@gmail.com> Date: Sat, 10 Aug 2024 17:52:15 +0800 Subject: [PATCH 1/3] refactor: move Rotation into one separate module and add test for it --- Cargo.toml | 1 + src/append/rolling_file/mod.rs | 3 +- src/append/rolling_file/rolling.rs | 60 +---------------- src/append/rolling_file/rotation.rs | 101 ++++++++++++++++++++++++++++ 4 files changed, 105 insertions(+), 60 deletions(-) create mode 100644 src/append/rolling_file/rotation.rs diff --git a/Cargo.toml b/Cargo.toml index f4564a5..f4f3fa4 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -56,6 +56,7 @@ serde_json = { version = "1.0", optional = true } time = { version = "0.3", features = [ "formatting", "parsing", + "macros", ], optional = true } ## Fastrace dependencies diff --git a/src/append/rolling_file/mod.rs b/src/append/rolling_file/mod.rs index a09ae3a..932bad6 100644 --- a/src/append/rolling_file/mod.rs +++ b/src/append/rolling_file/mod.rs @@ -18,11 +18,12 @@ pub use non_blocking::NonBlockingBuilder; pub use non_blocking::WorkerGuard; pub use rolling::RollingFileWriter; pub use rolling::RollingFileWriterBuilder; -pub use rolling::Rotation; +pub use rotation::Rotation; mod append; mod non_blocking; mod rolling; +mod rotation; mod worker; #[derive(Debug)] diff --git a/src/append/rolling_file/rolling.rs b/src/append/rolling_file/rolling.rs index 2f9fcdf..eee9ef8 100644 --- a/src/append/rolling_file/rolling.rs +++ b/src/append/rolling_file/rolling.rs @@ -20,13 +20,12 @@ use std::io::Write; use std::path::Path; use std::path::PathBuf; +use crate::append::rolling_file::Rotation; use anyhow::Context; use parking_lot::RwLock; use time::format_description; use time::Date; -use time::Duration; use time::OffsetDateTime; -use time::Time; /// A file writer with the ability to rotate log files at a fixed schedule. #[derive(Debug)] @@ -338,60 +337,3 @@ impl State { self.next_date_timestamp = self.rotation.next_date_timestamp(&now); } } - -/// Defines a fixed period for rolling of a log file. -#[derive(Clone, Eq, PartialEq, Debug)] -pub enum Rotation { - /// Minutely Rotation - Minutely, - /// Hourly Rotation - Hourly, - /// Daily Rotation - Daily, - /// No Rotation - Never, -} - -impl Rotation { - fn next_date_timestamp(&self, current_date: &OffsetDateTime) -> Option { - let next_date = match *self { - Rotation::Minutely => *current_date + Duration::minutes(1), - Rotation::Hourly => *current_date + Duration::hours(1), - Rotation::Daily => *current_date + Duration::days(1), - Rotation::Never => return None, - }; - - Some(self.round_date(&next_date).unix_timestamp() as usize) - } - - fn round_date(&self, date: &OffsetDateTime) -> OffsetDateTime { - match *self { - Rotation::Minutely => { - let time = Time::from_hms(date.hour(), date.minute(), 0) - .expect("invalid time; this is a bug in logforth rolling file appender"); - date.replace_time(time) - } - Rotation::Hourly => { - let time = Time::from_hms(date.hour(), 0, 0) - .expect("invalid time; this is a bug in logforth rolling file appender"); - date.replace_time(time) - } - Rotation::Daily => { - let time = Time::from_hms(0, 0, 0) - .expect("invalid time; this is a bug in logforth rolling file appender"); - date.replace_time(time) - } - Rotation::Never => unreachable!("Rotation::Never is impossible to round."), - } - } - - fn date_format(&self) -> Vec> { - match *self { - Rotation::Minutely => format_description::parse("[year]-[month]-[day]-[hour]-[minute]"), - Rotation::Hourly => format_description::parse("[year]-[month]-[day]-[hour]"), - Rotation::Daily => format_description::parse("[year]-[month]-[day]"), - Rotation::Never => format_description::parse("[year]-[month]-[day]"), - } - .expect("failed to create a formatter; this is a bug in logforth rolling file appender") - } -} diff --git a/src/append/rolling_file/rotation.rs b/src/append/rolling_file/rotation.rs new file mode 100644 index 0000000..3af92b1 --- /dev/null +++ b/src/append/rolling_file/rotation.rs @@ -0,0 +1,101 @@ +// Copyright 2024 tison +// +// 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. + +use time::format_description; +use time::Duration; +use time::OffsetDateTime; +use time::Time; + +/// Defines a fixed period for rolling of a log file. +#[derive(Clone, Eq, PartialEq, Debug)] +pub enum Rotation { + /// Minutely Rotation + Minutely, + /// Hourly Rotation + Hourly, + /// Daily Rotation + Daily, + /// No Time Rotation + Never, +} + +impl Rotation { + pub fn next_date_timestamp(&self, current_date: &OffsetDateTime) -> Option { + let next_date = match *self { + Rotation::Minutely => *current_date + Duration::minutes(1), + Rotation::Hourly => *current_date + Duration::hours(1), + Rotation::Daily => *current_date + Duration::days(1), + Rotation::Never => return None, + }; + + Some(self.round_date(&next_date).unix_timestamp() as usize) + } + + fn round_date(&self, date: &OffsetDateTime) -> OffsetDateTime { + match *self { + Rotation::Minutely => { + let time = Time::from_hms(date.hour(), date.minute(), 0) + .expect("invalid time; this is a bug in logforth rolling file appender"); + date.replace_time(time) + } + Rotation::Hourly => { + let time = Time::from_hms(date.hour(), 0, 0) + .expect("invalid time; this is a bug in logforth rolling file appender"); + date.replace_time(time) + } + Rotation::Daily => { + let time = Time::from_hms(0, 0, 0) + .expect("invalid time; this is a bug in logforth rolling file appender"); + date.replace_time(time) + } + Rotation::Never => unreachable!("Rotation::Never is impossible to round."), + } + } + + pub fn date_format(&self) -> Vec> { + match *self { + Rotation::Minutely => format_description::parse("[year]-[month]-[day]-[hour]-[minute]"), + Rotation::Hourly => format_description::parse("[year]-[month]-[day]-[hour]"), + Rotation::Daily => format_description::parse("[year]-[month]-[day]"), + Rotation::Never => format_description::parse("[year]-[month]-[day]"), + } + .expect("failed to create a formatter; this is a bug in logforth rolling file appender") + } +} + +#[cfg(test)] +mod tests { + use time::macros::datetime; + + use super::Rotation; + + #[test] + fn test_next_date_timestamp() { + let current_date = datetime!(2024-08-10 17:12:52 +8); + + assert_eq!( + Rotation::Minutely.next_date_timestamp(¤t_date), + Some(datetime!(2024-08-10 17:13:00 +8).unix_timestamp() as usize) + ); + assert_eq!( + Rotation::Hourly.next_date_timestamp(¤t_date), + Some(datetime!(2024-08-10 18:00:00 +8).unix_timestamp() as usize) + ); + assert_eq!( + Rotation::Daily.next_date_timestamp(¤t_date), + Some(datetime!(2024-08-11 00:00:00 +8).unix_timestamp() as usize) + ); + assert_eq!(Rotation::Never.next_date_timestamp(¤t_date), None); + } +} From 9b98068637bcab160d1c71763781b42081b50687 Mon Sep 17 00:00:00 2001 From: Rui Fan <1996fanrui@gmail.com> Date: Sat, 10 Aug 2024 23:53:09 +0800 Subject: [PATCH 2/3] test: add unit tests for rolling file --- .github/workflows/ci.yml | 4 +- Cargo.toml | 4 + src/append/rolling_file/clock.rs | 79 ++++++++++ src/append/rolling_file/mod.rs | 1 + src/append/rolling_file/rolling.rs | 243 +++++++++++++++++++++++++++-- 5 files changed, 317 insertions(+), 14 deletions(-) create mode 100644 src/append/rolling_file/clock.rs diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index d5d3f80..21c6cd3 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -59,7 +59,9 @@ jobs: - uses: actions/checkout@v4 - uses: Swatinem/rust-cache@v2 - name: Run unit tests - run: cargo test -- --nocapture + run: | + cargo test -- --nocapture + cargo test --all-features -- --nocapture - name: Run examples run: | cargo run --example simple_stdio diff --git a/Cargo.toml b/Cargo.toml index f4f3fa4..a5a2c3a 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -59,6 +59,10 @@ time = { version = "0.3", features = [ "macros", ], optional = true } +[dev-dependencies] +rand = "0.8.5" +tempfile = "3.3" + ## Fastrace dependencies [dependencies.fastrace] optional = true diff --git a/src/append/rolling_file/clock.rs b/src/append/rolling_file/clock.rs new file mode 100644 index 0000000..4b33e38 --- /dev/null +++ b/src/append/rolling_file/clock.rs @@ -0,0 +1,79 @@ +// Copyright 2024 tison +// +// 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. + +use time::OffsetDateTime; + +#[derive(Debug)] +pub enum Clock { + DefaultClock, + #[cfg(test)] + ManualClock(ManualClock), +} + +impl Clock { + pub fn now(&self) -> OffsetDateTime { + match self { + Clock::DefaultClock => OffsetDateTime::now_utc(), + #[cfg(test)] + Clock::ManualClock(clock) => clock.now(), + } + } + + #[cfg(test)] + pub fn set_now(&mut self, new_time: OffsetDateTime) { + if let Clock::ManualClock(clock) = self { + clock.set_now(new_time); + } + } +} + +/// The time could be reset. +#[derive(Debug)] +#[cfg(test)] +pub struct ManualClock { + fixed_time: OffsetDateTime, +} + +#[cfg(test)] +impl ManualClock { + pub fn new(fixed_time: OffsetDateTime) -> ManualClock { + ManualClock { fixed_time } + } + + fn now(&self) -> OffsetDateTime { + self.fixed_time + } + + pub fn set_now(&mut self, new_time: OffsetDateTime) { + self.fixed_time = new_time; + } +} + +#[cfg(test)] +mod tests { + use time::macros::datetime; + + use super::*; + + #[test] + fn test_manual_clock_adjusting() { + let mut clock = ManualClock { + fixed_time: datetime!(2023-01-01 12:00:00 UTC), + }; + assert_eq!(clock.now(), datetime!(2023-01-01 12:00:00 UTC)); + + clock.set_now(datetime!(2024-01-01 12:00:00 UTC)); + assert_eq!(clock.now(), datetime!(2024-01-01 12:00:00 UTC)); + } +} diff --git a/src/append/rolling_file/mod.rs b/src/append/rolling_file/mod.rs index 932bad6..903364a 100644 --- a/src/append/rolling_file/mod.rs +++ b/src/append/rolling_file/mod.rs @@ -21,6 +21,7 @@ pub use rolling::RollingFileWriterBuilder; pub use rotation::Rotation; mod append; +mod clock; mod non_blocking; mod rolling; mod rotation; diff --git a/src/append/rolling_file/rolling.rs b/src/append/rolling_file/rolling.rs index eee9ef8..74f039f 100644 --- a/src/append/rolling_file/rolling.rs +++ b/src/append/rolling_file/rolling.rs @@ -20,13 +20,15 @@ use std::io::Write; use std::path::Path; use std::path::PathBuf; -use crate::append::rolling_file::Rotation; use anyhow::Context; use parking_lot::RwLock; use time::format_description; use time::Date; use time::OffsetDateTime; +use crate::append::rolling_file::clock::Clock; +use crate::append::rolling_file::Rotation; + /// A file writer with the ability to rotate log files at a fixed schedule. #[derive(Debug)] pub struct RollingFileWriter { @@ -39,15 +41,11 @@ impl RollingFileWriter { pub fn builder() -> RollingFileWriterBuilder { RollingFileWriterBuilder::new() } - - fn now(&self) -> OffsetDateTime { - OffsetDateTime::now_utc() - } } impl Write for RollingFileWriter { fn write(&mut self, buf: &[u8]) -> io::Result { - let now = self.now(); + let now = self.state.clock.now(); let writer = self.writer.get_mut(); if self.state.should_rollover_on_date(now) { self.state.advance_date(now); @@ -77,6 +75,7 @@ pub struct RollingFileWriterBuilder { suffix: Option, max_size: usize, max_files: Option, + clock: Clock, } impl Default for RollingFileWriterBuilder { @@ -94,6 +93,7 @@ impl RollingFileWriterBuilder { suffix: None, max_size: usize::MAX, max_files: None, + clock: Clock::DefaultClock, } } @@ -138,6 +138,12 @@ impl RollingFileWriterBuilder { self } + #[cfg(test)] + fn clock(mut self, clock: Clock) -> Self { + self.clock = clock; + self + } + pub fn build(self, dir: impl AsRef) -> anyhow::Result { let Self { rotation, @@ -145,11 +151,11 @@ impl RollingFileWriterBuilder { suffix, max_size, max_files, + clock, } = self; let directory = dir.as_ref().to_path_buf(); - let now = OffsetDateTime::now_utc(); let (state, writer) = State::new( - now, rotation, directory, prefix, suffix, max_size, max_files, + rotation, directory, prefix, suffix, max_size, max_files, clock, )?; Ok(RollingFileWriter { state, writer }) } @@ -162,29 +168,29 @@ struct State { log_filename_suffix: Option, date_format: Vec>, rotation: Rotation, - current_date: OffsetDateTime, current_count: usize, current_filesize: usize, next_date_timestamp: Option, max_size: usize, max_files: Option, + clock: Clock, } impl State { fn new( - now: OffsetDateTime, rotation: Rotation, dir: impl AsRef, log_filename_prefix: Option, log_filename_suffix: Option, max_size: usize, max_files: Option, + clock: Clock, ) -> anyhow::Result<(Self, RwLock)> { let log_dir = dir.as_ref().to_path_buf(); let date_format = rotation.date_format(); + let now = clock.now(); let next_date_timestamp = rotation.next_date_timestamp(&now); - let current_date = now; let current_count = 0; let current_filesize = 0; @@ -193,13 +199,13 @@ impl State { log_filename_prefix, log_filename_suffix, date_format, - current_date, current_count, current_filesize, next_date_timestamp, rotation, max_size, max_files, + clock, }; let file = state.create_log_writer(now, 0)?; @@ -331,9 +337,220 @@ impl State { } fn advance_date(&mut self, now: OffsetDateTime) { - self.current_date = now; self.current_count = 0; self.current_filesize = 0; self.next_date_timestamp = self.rotation.next_date_timestamp(&now); } } +#[cfg(test)] +mod tests { + use std::cmp::min; + use std::fs; + use std::io::Write; + use std::ops::Add; + + use rand::distributions::Alphanumeric; + use rand::Rng; + use tempfile::TempDir; + use time::macros::datetime; + use time::Duration; + + use crate::append::rolling_file::clock::Clock; + use crate::append::rolling_file::clock::ManualClock; + use crate::append::rolling_file::RollingFileWriterBuilder; + use crate::append::rolling_file::Rotation; + + #[test] + fn test_file_rolling_via_file_size() { + test_file_rolling_for_specific_file_size(3, 1000); + test_file_rolling_for_specific_file_size(3, 10000); + test_file_rolling_for_specific_file_size(10, 8888); + test_file_rolling_for_specific_file_size(10, 10000); + test_file_rolling_for_specific_file_size(20, 6666); + test_file_rolling_for_specific_file_size(20, 10000); + } + fn test_file_rolling_for_specific_file_size(max_files: usize, max_size: usize) { + let temp_dir = TempDir::new().expect("failed to create a temporary directory"); + + let mut writer = RollingFileWriterBuilder::new() + .rotation(Rotation::Never) + .filename_prefix("test_prefix") + .filename_suffix("log") + .max_log_files(max_files) + .max_file_size(max_size) + .build(&temp_dir) + .unwrap(); + + for i in 1..=(max_files * 2) { + let mut expected_file_size = 0; + while expected_file_size < max_size { + let rand_str = generate_random_string(); + expected_file_size += rand_str.len(); + assert_eq!(writer.write(rand_str.as_bytes()).unwrap(), rand_str.len()); + assert_eq!(writer.state.current_filesize, expected_file_size); + } + + writer.flush().unwrap(); + assert_eq!( + fs::read_dir(&writer.state.log_dir).unwrap().count(), + min(i, max_files) + ); + } + } + + #[test] + fn test_file_rolling_via_time_rotation() { + test_file_rolling_for_specific_time_rotation( + Rotation::Minutely, + Duration::minutes(1), + Duration::seconds(1), + ); + test_file_rolling_for_specific_time_rotation( + Rotation::Hourly, + Duration::hours(1), + Duration::minutes(1), + ); + test_file_rolling_for_specific_time_rotation( + Rotation::Daily, + Duration::days(1), + Duration::hours(1), + ); + } + + fn test_file_rolling_for_specific_time_rotation( + rotation: Rotation, + rotation_duration: Duration, + write_interval: Duration, + ) { + let temp_dir = TempDir::new().expect("failed to create a temporary directory"); + let max_files = 10; + + let start_time = datetime!(2024-08-10 00:00:00 +0); + let mut writer = RollingFileWriterBuilder::new() + .rotation(rotation) + .filename_prefix("test_prefix") + .filename_suffix("log") + .max_log_files(max_files) + .max_file_size(usize::MAX) + .clock(Clock::ManualClock(ManualClock::new(start_time))) + .build(&temp_dir) + .unwrap(); + + let mut cur_time = start_time; + + for i in 1..=(max_files * 2) { + let mut expected_file_size = 0; + let end_time = cur_time.add(rotation_duration); + while cur_time < end_time { + writer.state.clock.set_now(cur_time); + + let rand_str = generate_random_string(); + expected_file_size += rand_str.len(); + + assert_eq!(writer.write(rand_str.as_bytes()).unwrap(), rand_str.len()); + assert_eq!(writer.state.current_filesize, expected_file_size); + + cur_time = cur_time.add(write_interval); + } + + writer.flush().unwrap(); + assert_eq!( + fs::read_dir(&writer.state.log_dir).unwrap().count(), + min(i, max_files) + ); + } + } + + #[test] + fn test_file_rolling_via_file_size_and_time_rotation() { + test_file_size_and_time_rotation_for_specific_time_rotation( + Rotation::Minutely, + Duration::minutes(1), + Duration::seconds(1), + ); + test_file_size_and_time_rotation_for_specific_time_rotation( + Rotation::Hourly, + Duration::hours(1), + Duration::minutes(1), + ); + test_file_size_and_time_rotation_for_specific_time_rotation( + Rotation::Daily, + Duration::days(1), + Duration::hours(1), + ); + } + + fn test_file_size_and_time_rotation_for_specific_time_rotation( + rotation: Rotation, + rotation_duration: Duration, + write_interval: Duration, + ) { + let temp_dir = TempDir::new().expect("failed to create a temporary directory"); + let max_files = 10; + // Small file size and too many files to ensure both of file size and time rotation can be + // triggered. + let total_files = 100; + let file_size = 500; + + let start_time = datetime!(2024-08-10 00:00:00 +0); + let mut writer = RollingFileWriterBuilder::new() + .rotation(rotation) + .filename_prefix("test_prefix") + .filename_suffix("log") + .max_log_files(max_files) + .max_file_size(file_size) + .clock(Clock::ManualClock(ManualClock::new(start_time))) + .build(&temp_dir) + .unwrap(); + + let mut cur_time = start_time; + let mut end_time = cur_time.add(rotation_duration); + let mut time_rotation_trigger = false; + let mut file_size_rotation_trigger = false; + + for i in 1..=total_files { + let mut expected_file_size = 0; + loop { + writer.state.clock.set_now(cur_time); + + let rand_str = generate_random_string(); + expected_file_size += rand_str.len(); + + assert_eq!(writer.write(rand_str.as_bytes()).unwrap(), rand_str.len()); + assert_eq!(writer.state.current_filesize, expected_file_size); + + cur_time = cur_time.add(write_interval); + + if cur_time >= end_time { + end_time = end_time.add(rotation_duration); + time_rotation_trigger = true; + break; + } + if expected_file_size >= file_size { + file_size_rotation_trigger = true; + break; + } + } + + writer.flush().unwrap(); + assert_eq!( + fs::read_dir(&writer.state.log_dir).unwrap().count(), + min(i, max_files) + ); + } + assert!(file_size_rotation_trigger); + assert!(time_rotation_trigger); + } + + fn generate_random_string() -> String { + let mut rng = rand::thread_rng(); + let len = rng.gen_range(50..=100); + let random_string: String = std::iter::repeat(()) + .map(|()| rng.sample(Alphanumeric)) + .map(char::from) + .take(len) + .collect(); + + random_string + } +} From 2f2bd9aee439e2dce66cfd051d44cac217e9bc97 Mon Sep 17 00:00:00 2001 From: tison Date: Sun, 11 Aug 2024 16:21:35 +0800 Subject: [PATCH 3/3] Update .github/workflows/ci.yml --- .github/workflows/ci.yml | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 21c6cd3..802c04c 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -59,9 +59,7 @@ jobs: - uses: actions/checkout@v4 - uses: Swatinem/rust-cache@v2 - name: Run unit tests - run: | - cargo test -- --nocapture - cargo test --all-features -- --nocapture + run: cargo test --all-features -- --nocapture - name: Run examples run: | cargo run --example simple_stdio