Skip to content

Commit

Permalink
feat: custom log rotation duration
Browse files Browse the repository at this point in the history
  • Loading branch information
@stegaBOB @gibbz00
stegaBOB authored and gibbz00 committed Nov 7, 2024
1 parent 91fedc1 commit d7850e3
Showing 1 changed file with 207 additions and 2 deletions.
209 changes: 207 additions & 2 deletions tracing-appender/src/rolling.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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
//!
Expand All @@ -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};

Expand Down Expand Up @@ -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);
///
Expand Down Expand Up @@ -401,6 +404,48 @@ pub fn never(directory: impl AsRef<Path>, file_name: impl AsRef<Path>) -> 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.<timestamp>`.
/// Refer to the module documentation for how `<timestamp>` is formatted.
pub fn custom(
directory: impl AsRef<Path>,
file_name_prefix: impl AsRef<Path>,
duration: StdDuration,
) -> Result<RollingFileAppender, String> {
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:
Expand Down Expand Up @@ -435,6 +480,14 @@ pub fn never(directory: impl AsRef<Path>, file_name: impl AsRef<Path>) -> 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);
Expand All @@ -445,6 +498,7 @@ enum RotationKind {
Hourly,
Daily,
Never,
Custom(Duration),
}

impl Rotation {
Expand All @@ -456,13 +510,37 @@ 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<Self, String> {
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<OffsetDateTime> {
let unrounded_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,
// 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))
}
Expand All @@ -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.")
Expand All @@ -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")
}
Expand Down Expand Up @@ -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");
Expand Down Expand Up @@ -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
Expand All @@ -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."
Expand All @@ -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(
Expand All @@ -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,
Expand Down Expand Up @@ -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)
Expand Down

0 comments on commit d7850e3

Please sign in to comment.