From d7850e34cc430e2c46354c50da3cc9dba71ac7e5 Mon Sep 17 00:00:00 2001 From: Sammy <41593264+stegaBOB@users.noreply.github.com> Date: Tue, 11 Jul 2023 23:40:37 -0500 Subject: [PATCH] feat: custom log rotation duration --- tracing-appender/src/rolling.rs | 209 +++++++++++++++++++++++++++++++- 1 file changed, 207 insertions(+), 2 deletions(-) diff --git a/tracing-appender/src/rolling.rs b/tracing-appender/src/rolling.rs index 3c9a61a47..8dca37885 100644 --- a/tracing-appender/src/rolling.rs +++ b/tracing-appender/src/rolling.rs @@ -16,7 +16,10 @@ //! - [`Rotation::daily()`][daily]: A new log file in the format of `some_directory/log_file_name_prefix.yyyy-MM-dd` //! will be created daily //! - [`Rotation::never()`][never()]: This will result in log file located at `some_directory/log_file_name` -//! +//! - [`Rotation::custom()`][custom()]: The new log file format depends on the duration resolution. +//! For example, if the duration is less than or equal to a second, then the name will be formatted as +//! `some_directory/log_file_name_prefix.yyyy-MM-dd-HH-mm-ss-sss`. But if the duration is greater than or +//! equal to an hour, then the name will be formatted as `some_directory/log_file_name_prefix.yyyy-MM-dd-HH`. //! //! # Examples //! @@ -33,6 +36,7 @@ use std::{ io::{self, Write}, path::{Path, PathBuf}, sync::atomic::{AtomicUsize, Ordering}, + time::Duration as StdDuration, }; use time::{format_description, Date, Duration, OffsetDateTime, Time}; @@ -70,7 +74,6 @@ pub use builder::{Builder, InitError}; /// /// // Log all events to a rolling log file. /// let logfile = tracing_appender::rolling::hourly("/logs", "myapp-logs"); - /// // Log `INFO` and above to stdout. /// let stdout = std::io::stdout.with_max_level(tracing::Level::INFO); /// @@ -401,6 +404,48 @@ pub fn never(directory: impl AsRef, file_name: impl AsRef) -> Rollin RollingFileAppender::new(Rotation::NEVER, directory, file_name) } +/// Creates a rotating file appender with a custom duration interval. +/// +/// The appender returned by `rolling::custom` can be used with `non_blocking` to create +/// a non-blocking, daily file appender. +/// +/// A `RollingFileAppender` has a fixed rotation whose frequency is +/// defined by [`Rotation`]. The `directory` and +/// `file_name_prefix` arguments determine the location and file name's _prefix_ +/// of the log file. `RollingFileAppender` automatically appends the current date in UTC. +/// +/// # Examples +/// +/// ``` rust +/// # #[clippy::allow(needless_doctest_main)] +/// # use std::time::Duration; +/// fn main () { +/// # fn doc() -> Result<(), String>{ +/// let appender = tracing_appender::rolling::custom("/some/path", "rolling.log", Duration::from_secs(2 * 60))?; +/// let (non_blocking_appender, _guard) = tracing_appender::non_blocking(appender); +/// +/// let collector = tracing_subscriber::fmt().with_writer(non_blocking_appender); +/// +/// tracing::collect::with_default(collector.finish(), || { +/// tracing::event!(tracing::Level::INFO, "Hello"); +/// }); +/// # +/// # Ok(()) +/// # } +/// } +/// ``` +/// +/// This will result in a log file located at `/some/path/rolling.log.`. +/// Refer to the module documentation for how `` is formatted. +pub fn custom( + directory: impl AsRef, + file_name_prefix: impl AsRef, + duration: StdDuration, +) -> Result { + Rotation::custom(duration) + .map(|rotation| RollingFileAppender::new(rotation, directory, file_name_prefix)) +} + /// Defines a fixed period for rolling of a log file. /// /// To use a `Rotation`, pick one of the following options: @@ -435,6 +480,14 @@ pub fn never(directory: impl AsRef, file_name: impl AsRef) -> Rollin /// use tracing_appender::rolling::Rotation; /// let rotation = tracing_appender::rolling::Rotation::NEVER; /// # } +/// +/// ### Custom Rotation +/// ```rust +/// # fn docs() { +/// use std::time::Duration; +/// use tracing_appender::rolling::Rotation; +/// let rotation = tracing_appender::rolling::Rotation::custom(Duration::from_secs(2 * 60)); +/// # } /// ``` #[derive(Clone, Eq, PartialEq, Debug)] pub struct Rotation(RotationKind); @@ -445,6 +498,7 @@ enum RotationKind { Hourly, Daily, Never, + Custom(Duration), } impl Rotation { @@ -456,6 +510,27 @@ impl Rotation { pub const DAILY: Self = Self(RotationKind::Daily); /// Provides a rotation that never rotates. pub const NEVER: Self = Self(RotationKind::Never); + /// Custom duration overflow limit, should be approximately 10 years + const MAX_CUSTOM_DURATION: u64 = 3600 * 24 * 365 * 10; + + /// Provides a custom rotation + /// + /// This method returns an error if the duration parameter is greater than 10 years. + pub fn custom(duration: StdDuration) -> Result { + if duration.as_secs() > Self::MAX_CUSTOM_DURATION { + // 10 years... Ridiculous, but we need to cap it somewhere to avoid overflow. + return Err("Custom Rotation duration must be less than 10 years".to_string()); + } + + let duration = Duration::new( + // primitive cast is safe because we limit the duration to about 10 years + duration.as_secs() as i64, + // primitive cast is safe as nanos max is 1e9, whilst i32 max is around 2e9 + duration.subsec_nanos() as i32, + ); + + Ok(Self(RotationKind::Custom(duration))) + } pub(crate) fn next_date(&self, current_date: &OffsetDateTime) -> Option { let unrounded_next_date = match *self { @@ -463,6 +538,9 @@ impl Rotation { Rotation::HOURLY => *current_date + Duration::hours(1), Rotation::DAILY => *current_date + Duration::days(1), Rotation::NEVER => return None, + // This is safe from overflow because we only create a `Rotation::Custom` if the + // duration is positive and less than 10 years. + Self(RotationKind::Custom(duration)) => *current_date + duration, }; Some(self.round_date(&unrounded_next_date)) } @@ -485,6 +563,27 @@ impl Rotation { .expect("Invalid time; this is a bug in tracing-appender"); date.replace_time(time) } + Self(RotationKind::Custom(duration)) => { + let date_nanos = date.unix_timestamp_nanos(); + let duration_nanos = duration.whole_nanoseconds(); + debug_assert!(duration_nanos > 0); + + // find how many nanoseconds after the next rotation time we are. + // Use Euclidean division to properly handle negative date values. + // This is safe because `Duration` is always positive. + let nanos_above = date_nanos.rem_euclid(duration_nanos); + let round_nanos = date_nanos - nanos_above; + + // `0 <= nanos_above < duration_nanos` (by euclidean division definition) + // `date_nanos - 0 >= date_nanos - nanos_above > date_nanos - duration_nanos` (by algebra) + // thus, `date_nanos >= round_nanos > date_nanos - duration_nanos` + // `date_nanos` is already a valid `OffsetDateTime`, and + // `date_nanos - duration_nanos` equals the `current_date` from `Rotation::next_date`. + // Since `round_nanos` is between these two valid values, it must also be a valid + // input to `OffsetDateTime::from_unix_timestamp_nanos`. + OffsetDateTime::from_unix_timestamp_nanos(round_nanos) + .expect("Invalid time; this is a bug in tracing-appender") + } // Rotation::NEVER is impossible to round. Rotation::NEVER => { unreachable!("Rotation::NEVER is impossible to round.") @@ -498,6 +597,21 @@ impl Rotation { 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]"), + Self(RotationKind::Custom(duration)) => { + if duration >= Duration::DAY { + format_description::parse("[year]-[month]-[day]") + } else if duration >= Duration::HOUR { + format_description::parse("[year]-[month]-[day]-[hour]") + } else if duration >= Duration::MINUTE { + format_description::parse("[year]-[month]-[day]-[hour]-[minute]") + } else if duration >= Duration::SECOND { + format_description::parse("[year]-[month]-[day]-[hour]-[minute]-[second]") + } else { + format_description::parse( + "[year]-[month]-[day]-[hour]-[minute]-[second]-[subsecond]", + ) + } + } } .expect("Unable to create a formatter; this is a bug in tracing-appender") } @@ -709,6 +823,7 @@ mod test { use super::*; use std::fs; use std::io::Write; + use time::ext::NumericalDuration; fn find_str_in_log(dir_path: &Path, expected_value: &str) -> bool { let dir_contents = fs::read_dir(dir_path).expect("Failed to read directory"); @@ -766,6 +881,14 @@ mod test { test_appender(Rotation::NEVER, "never.log"); } + #[test] + fn write_custom_log() { + test_appender( + Rotation::custom(20.minutes().unsigned_abs()).unwrap(), + "custom.log", + ); + } + #[test] fn test_rotations() { // per-minute basis @@ -789,6 +912,36 @@ mod test { assert!(next.is_none()); } + #[test] + fn test_custom_rotations() { + let now = OffsetDateTime::now_utc().replace_time(Time::from_hms(0, 0, 20).unwrap()); + let duration = StdDuration::from_secs(20); + let next = Rotation::custom(duration).unwrap().next_date(&now).unwrap(); + assert_eq!(now + 20.seconds(), next); + + let now = OffsetDateTime::now_utc().replace_time(Time::from_hms(1, 0, 20).unwrap()); + let duration = StdDuration::from_secs(120 * 60); + let next = Rotation::custom(duration).unwrap().next_date(&now).unwrap(); + assert_eq!(now + 59.minutes() + 40.seconds(), next); + + let now = OffsetDateTime::UNIX_EPOCH + 50.days() + 11.hours(); + let duration = Duration::days(7).unsigned_abs(); + let next = Rotation::custom(duration).unwrap().next_date(&now).unwrap(); + assert_eq!(now + 5.days() + 13.hours(), next); + + // negative timestamps, -23 hours, 59 minutes + let now = OffsetDateTime::UNIX_EPOCH - 23.hours() - 59.minutes(); + let duration = Duration::minutes(30).unsigned_abs(); + let next = Rotation::custom(duration).unwrap().next_date(&now).unwrap(); + assert_eq!(now + 29.minutes(), next); + + // negative timestamps, -12 hours + let now = OffsetDateTime::UNIX_EPOCH - 12.hours(); + let duration = Duration::days(1).unsigned_abs(); + let next = Rotation::custom(duration).unwrap().next_date(&now).unwrap(); + assert_eq!(now + 12.hours(), next); + } + #[test] #[should_panic( expected = "internal error: entered unreachable code: Rotation::NEVER is impossible to round." @@ -798,6 +951,14 @@ mod test { let _ = Rotation::NEVER.round_date(&now); } + #[test] + fn test_custom_duration_overflow() { + let ten_years = StdDuration::from_secs(Rotation::MAX_CUSTOM_DURATION); + assert!(Rotation::custom(ten_years).is_ok()); + let more_than_ten_years = ten_years.saturating_add(StdDuration::from_secs(1)); + assert!(Rotation::custom(more_than_ten_years).is_err()); + } + #[test] fn test_path_concatenation() { let format = format_description::parse( @@ -808,6 +969,7 @@ mod test { let directory = tempfile::tempdir().expect("failed to create tempdir"); let now = OffsetDateTime::parse("2020-02-01 10:01:00 +00:00:00", &format).unwrap(); + let now = now + Duration::nanoseconds(12345); struct TestCase { expected: &'static str, @@ -915,6 +1077,49 @@ mod test { prefix: None, suffix: Some("log"), }, + // custom + TestCase { + expected: "2020-02-01-10-01-00-000012345", + rotation: Rotation::custom(100.nanoseconds().unsigned_abs()).unwrap(), + prefix: None, + suffix: None, + }, + TestCase { + expected: "2020-02-01-10-01-00", + rotation: Rotation::custom(1.seconds().unsigned_abs()).unwrap(), + prefix: None, + suffix: None, + }, + TestCase { + expected: "2020-02-01-10-01", + rotation: Rotation::custom(30.minutes().unsigned_abs()).unwrap(), + prefix: None, + suffix: None, + }, + TestCase { + expected: "2020-02-01-10", + rotation: Rotation::custom(1.hours().unsigned_abs()).unwrap(), + prefix: None, + suffix: None, + }, + TestCase { + expected: "2020-02-01-10", + rotation: Rotation::custom(12.hours().unsigned_abs()).unwrap(), + prefix: None, + suffix: None, + }, + TestCase { + expected: "2020-02-01", + rotation: Rotation::custom(1.days().unsigned_abs()).unwrap(), + prefix: None, + suffix: None, + }, + TestCase { + expected: "2020-02-01", + rotation: Rotation::custom(100.weeks().unsigned_abs()).unwrap(), + prefix: None, + suffix: None, + }, ]; for test_case in test_cases { test(test_case)