appender: replace chrono with time (#1652)

## Motivation

This PR continues the work started in
https://github.com/tokio-rs/tracing/pull/1646 to replace `chrono` with
`time`. I'll refer to @hawkw's motivation:

> Currently, `tracing-subscriber` supports the `chrono` crate for
> timestamp formatting, via a default-on feature flag. When this code
> was initially added to `tracing-subscriber`, the `time` crate did not
> have support for the timestamp formatting options we needed.
>
> Unfortunately, the `chrono` crate's maintenance status is now in
> question (see #1598). Furthermore, `chrono` depends on version 0.1 of
> the `time` crate, which contains a security vulnerability
> (https://rustsec.org/advisories/RUSTSEC-2020-0071.html). This
> vulnerability is fixed in more recent releases of `time`, but `chrono`
> still uses v0.1.

## Solution

I've replaced chrono with time 0.3. Unfortunately, some of chrono's
builders for DateTimes are not present in `time`, which required the
usage of `macro_rules!` macros to construct some of the hard-coded
times. I also took the opportunity to tidy some of the tests and change
the internal representation of `Rotation::NEVER` from year 9,999 to an
`Option::None`.

This branch changes `tracing-appender`'s MSRV from Rust 1.42 to Rust
1.51, the MSRV for the `time` crate when certain required feature flags
are enabled. This does *not* effect the MSRV for other crates in this
repository.
This commit is contained in:
David Barsky 2021-10-22 13:46:33 -04:00 committed by Eliza Weisman
parent 60a2644fcb
commit c62dac9f73
6 changed files with 140 additions and 203 deletions

View File

@ -42,7 +42,24 @@ jobs:
uses: actions-rs/cargo@v1 uses: actions-rs/cargo@v1
with: with:
command: check command: check
args: --all args: --all --exclude=tracing-appender
# TODO: remove this once tracing's MSRV is bumped.
check-msrv-appender:
# Run `cargo check` on our minimum supported Rust version (1.51.0).
runs-on: ubuntu-latest
steps:
- uses: actions/checkout@main
- uses: actions-rs/toolchain@v1
with:
toolchain: 1.51.0
profile: minimal
override: true
- name: Check
uses: actions-rs/cargo@v1
with:
command: check
args: --lib=tracing-appender
check: check:
# Run `cargo check` first to ensure that the pushed code at least compiles. # Run `cargo check` first to ensure that the pushed code at least compiles.

View File

@ -21,14 +21,15 @@ edition = "2018"
[dependencies] [dependencies]
crossbeam-channel = "0.5.0" crossbeam-channel = "0.5.0"
chrono = { version = "0.4.16", default-features = false, features = ["clock", "std"] } time = { version = "0.3", default-features = false, features = ["formatting"] }
[dependencies.tracing-subscriber] [dependencies.tracing-subscriber]
path = "../tracing-subscriber" path = "../tracing-subscriber"
version = "0.2.7" version = "0.2.7"
default-features = false default-features = false
features = ["fmt"] features = ["fmt", "std"]
[dev-dependencies] [dev-dependencies]
tracing = { path = "../tracing", version = "0.1" } tracing = { path = "../tracing", version = "0.1" }
time = { version = "0.3", default-features = false, features = ["formatting", "parsing"] }
tempfile = "3" tempfile = "3"

View File

@ -36,7 +36,7 @@ allows events and spans to be recorded in a non-blocking manner through a
dedicated logging thread. It also provides a [`RollingFileAppender`][file_appender] dedicated logging thread. It also provides a [`RollingFileAppender`][file_appender]
that can be used with _or_ without the non-blocking writer. that can be used with _or_ without the non-blocking writer.
*Compiler support: [requires `rustc` 1.42+][msrv]* *Compiler support: [requires `rustc` 1.51+][msrv]*
[msrv]: #supported-rust-versions [msrv]: #supported-rust-versions
@ -145,17 +145,17 @@ fn main() {
## Supported Rust Versions ## Supported Rust Versions
Tracing is built against the latest stable release. The minimum supported `tracing-appender` is built against the latest stable release. The minimum supported
version is 1.42. The current Tracing version is not guaranteed to build on Rust version is 1.51. The current `tracing-appender` version is not guaranteed to build on
versions earlier than the minimum supported version. Rust versions earlier than the minimum supported version.
Tracing follows the same compiler support policies as the rest of the Tokio Tracing follows the same compiler support policies as the rest of the Tokio
project. The current stable Rust compiler and the three most recent minor project. The current stable Rust compiler and the three most recent minor
versions before it will always be supported. For example, if the current stable versions before it will always be supported. For example, if the current
compiler version is 1.45, the minimum supported version will not be increased stable compiler version is 1.45, the minimum supported version will not be
past 1.42, three minor versions prior. Increasing the minimum supported compiler increased past 1.42, three minor versions prior. Increasing the minimum
version is not considered a semver breaking change as long as doing so complies supported compiler version is not considered a semver breaking change as
with this policy. long as doing so complies with this policy.
## License ## License

View File

@ -2,23 +2,23 @@ use std::io::{BufWriter, Write};
use std::{fs, io}; use std::{fs, io};
use crate::rolling::Rotation; use crate::rolling::Rotation;
use chrono::prelude::*;
use std::fmt::Debug; use std::fmt::Debug;
use std::fs::{File, OpenOptions}; use std::fs::{File, OpenOptions};
use std::path::Path; use std::path::Path;
use time::OffsetDateTime;
#[derive(Debug)] #[derive(Debug)]
pub(crate) struct InnerAppender { pub(crate) struct InnerAppender {
log_directory: String, log_directory: String,
log_filename_prefix: String, log_filename_prefix: String,
writer: BufWriter<File>, writer: BufWriter<File>,
next_date: DateTime<Utc>, next_date: Option<OffsetDateTime>,
rotation: Rotation, rotation: Rotation,
} }
impl io::Write for InnerAppender { impl io::Write for InnerAppender {
fn write(&mut self, buf: &[u8]) -> io::Result<usize> { fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
let now = Utc::now(); let now = OffsetDateTime::now_utc();
self.write_timestamped(buf, now) self.write_timestamped(buf, now)
} }
@ -32,7 +32,7 @@ impl InnerAppender {
log_directory: &Path, log_directory: &Path,
log_filename_prefix: &Path, log_filename_prefix: &Path,
rotation: Rotation, rotation: Rotation,
now: DateTime<Utc>, now: OffsetDateTime,
) -> io::Result<Self> { ) -> io::Result<Self> {
let log_directory = log_directory.to_str().unwrap(); let log_directory = log_directory.to_str().unwrap();
let log_filename_prefix = log_filename_prefix.to_str().unwrap(); let log_filename_prefix = log_filename_prefix.to_str().unwrap();
@ -49,7 +49,7 @@ impl InnerAppender {
}) })
} }
fn write_timestamped(&mut self, buf: &[u8], date: DateTime<Utc>) -> io::Result<usize> { fn write_timestamped(&mut self, buf: &[u8], date: OffsetDateTime) -> io::Result<usize> {
// Even if refresh_writer fails, we still have the original writer. Ignore errors // Even if refresh_writer fails, we still have the original writer. Ignore errors
// and proceed with the write. // and proceed with the write.
let buf_len = buf.len(); let buf_len = buf.len();
@ -57,7 +57,7 @@ impl InnerAppender {
self.writer.write_all(buf).map(|_| buf_len) self.writer.write_all(buf).map(|_| buf_len)
} }
fn refresh_writer(&mut self, now: DateTime<Utc>) { fn refresh_writer(&mut self, now: OffsetDateTime) {
if self.should_rollover(now) { if self.should_rollover(now) {
let filename = self.rotation.join_date(&self.log_filename_prefix, &now); let filename = self.rotation.join_date(&self.log_filename_prefix, &now);
@ -75,8 +75,12 @@ impl InnerAppender {
} }
} }
fn should_rollover(&self, date: DateTime<Utc>) -> bool { fn should_rollover(&self, date: OffsetDateTime) -> bool {
date >= self.next_date // the `None` case means that the `InnerAppender` *never* rorates log files.
match self.next_date {
None => false,
Some(next_date) => date >= next_date,
}
} }
} }

View File

@ -7,7 +7,7 @@
//! a dedicated logging thread. It also provides a [`RollingFileAppender`][file_appender] that can //! a dedicated logging thread. It also provides a [`RollingFileAppender`][file_appender] that can
//! be used with _or_ without the non-blocking writer. //! be used with _or_ without the non-blocking writer.
//! //!
//! *Compiler support: [requires `rustc` 1.42+][msrv]* //! *Compiler support: [requires `rustc` 1.51+][msrv]*
//! //!
//! [msrv]: #supported-rust-versions //! [msrv]: #supported-rust-versions
//! [file_appender]: ./rolling/struct.RollingFileAppender.html //! [file_appender]: ./rolling/struct.RollingFileAppender.html
@ -110,8 +110,8 @@
//! //!
//! ## Supported Rust Versions //! ## Supported Rust Versions
//! //!
//! Tracing is built against the latest stable release. The minimum supported //! `tracing-appender` is built against the latest stable release. The minimum supported
//! version is 1.42. The current Tracing version is not guaranteed to build on //! version is 1.51. The current `tracing-appender` version is not guaranteed to build on
//! Rust versions earlier than the minimum supported version. //! Rust versions earlier than the minimum supported version.
//! //!
//! Tracing follows the same compiler support policies as the rest of the Tokio //! Tracing follows the same compiler support policies as the rest of the Tokio

View File

@ -31,10 +31,9 @@
//! # } //! # }
//! ``` //! ```
use crate::inner::InnerAppender; use crate::inner::InnerAppender;
use chrono::{DateTime, Datelike, TimeZone, Timelike, Utc};
use std::fmt::Debug;
use std::io; use std::io;
use std::path::Path; use std::path::Path;
use time::{format_description, Duration, OffsetDateTime, Time};
/// A file appender with the ability to rotate log files at a fixed schedule. /// A file appender with the ability to rotate log files at a fixed schedule.
/// ///
@ -95,7 +94,7 @@ impl RollingFileAppender {
directory.as_ref(), directory.as_ref(),
file_name_prefix.as_ref(), file_name_prefix.as_ref(),
rotation, rotation,
Utc::now(), OffsetDateTime::now_utc(),
) )
.expect("Failed to create appender"), .expect("Failed to create appender"),
} }
@ -305,42 +304,69 @@ impl Rotation {
/// Provides a rotation that never rotates. /// Provides a rotation that never rotates.
pub const NEVER: Self = Self(RotationKind::Never); pub const NEVER: Self = Self(RotationKind::Never);
pub(crate) fn next_date(&self, current_date: &DateTime<Utc>) -> DateTime<Utc> { pub(crate) fn next_date(&self, current_date: &OffsetDateTime) -> Option<OffsetDateTime> {
let unrounded_next_date = match *self { let unrounded_next_date = match *self {
Rotation::MINUTELY => *current_date + chrono::Duration::minutes(1), Rotation::MINUTELY => *current_date + Duration::minutes(1),
Rotation::HOURLY => *current_date + chrono::Duration::hours(1), Rotation::HOURLY => *current_date + Duration::hours(1),
Rotation::DAILY => *current_date + chrono::Duration::days(1), Rotation::DAILY => *current_date + Duration::days(1),
Rotation::NEVER => Utc.ymd(9999, 1, 1).and_hms(1, 0, 0), Rotation::NEVER => return None,
}; };
self.round_date(&unrounded_next_date) Some(self.round_date(&unrounded_next_date))
} }
pub(crate) fn round_date(&self, date: &DateTime<Utc>) -> DateTime<Utc> { // note that this method will panic if passed a `Rotation::NEVER`.
pub(crate) fn round_date(&self, date: &OffsetDateTime) -> OffsetDateTime {
match *self { match *self {
Rotation::MINUTELY => Utc.ymd(date.year(), date.month(), date.day()).and_hms( Rotation::MINUTELY => {
date.hour(), let time = Time::from_hms(date.hour(), date.minute(), 0)
date.minute(), .expect("Invalid time; this is a bug in tracing-appender");
0, date.replace_time(time)
),
Rotation::HOURLY => {
Utc.ymd(date.year(), date.month(), date.day())
.and_hms(date.hour(), 0, 0)
} }
Rotation::DAILY => Utc Rotation::HOURLY => {
.ymd(date.year(), date.month(), date.day()) let time = Time::from_hms(date.hour(), 0, 0)
.and_hms(0, 0, 0), .expect("Invalid time; this is a bug in tracing-appender");
date.replace_time(time)
}
Rotation::DAILY => {
let time = Time::from_hms(0, 0, 0)
.expect("Invalid time; this is a bug in tracing-appender");
date.replace_time(time)
}
// Rotation::NEVER is impossible to round.
Rotation::NEVER => { Rotation::NEVER => {
Utc.ymd(date.year(), date.month(), date.day()) unreachable!("Rotation::NEVER is impossible to round.")
.and_hms(date.hour(), 0, 0)
} }
} }
} }
pub(crate) fn join_date(&self, filename: &str, date: &DateTime<Utc>) -> String { pub(crate) fn join_date(&self, filename: &str, date: &OffsetDateTime) -> String {
match *self { match *self {
Rotation::MINUTELY => format!("{}.{}", filename, date.format("%F-%H-%M")), Rotation::MINUTELY => {
Rotation::HOURLY => format!("{}.{}", filename, date.format("%F-%H")), let format = format_description::parse("[year]-[month]-[day]-[hour]-[minute]")
Rotation::DAILY => format!("{}.{}", filename, date.format("%F")), .expect("Unable to create a formatter; this is a bug in tracing-appender");
let date = date
.format(&format)
.expect("Unable to format OffsetDateTime; this is a bug in tracing-appender");
format!("{}.{}", filename, date)
}
Rotation::HOURLY => {
let format = format_description::parse("[year]-[month]-[day]-[hour]")
.expect("Unable to create a formatter; this is a bug in tracing-appender");
let date = date
.format(&format)
.expect("Unable to format OffsetDateTime; this is a bug in tracing-appender");
format!("{}.{}", filename, date)
}
Rotation::DAILY => {
let format = format_description::parse("[year]-[month]-[day]")
.expect("Unable to create a formatter; this is a bug in tracing-appender");
let date = date
.format(&format)
.expect("Unable to format OffsetDateTime; this is a bug in tracing-appender");
format!("{}.{}", filename, date)
}
Rotation::NEVER => filename.to_string(), Rotation::NEVER => filename.to_string(),
} }
} }
@ -408,172 +434,61 @@ mod test {
} }
#[test] #[test]
fn test_next_date_minutely() { fn test_rotations() {
let r = Rotation::MINUTELY; // per-minute basis
let now = OffsetDateTime::now_utc();
let next = Rotation::MINUTELY.next_date(&now).unwrap();
assert_eq!((now + Duration::MINUTE).minute(), next.minute());
let mock_now = Utc.ymd(2020, 2, 1).and_hms(0, 0, 0); // per-hour basis
let next = r.next_date(&mock_now); let now = OffsetDateTime::now_utc();
assert_eq!(mock_now.with_minute(1).unwrap(), next); let next = Rotation::HOURLY.next_date(&now).unwrap();
assert_eq!((now + Duration::HOUR).hour(), next.hour());
let mock_now = Utc.ymd(2020, 2, 1).and_hms(0, 20, 30); // daily-basis
let next = r.next_date(&mock_now); let now = OffsetDateTime::now_utc();
assert_eq!( let next = Rotation::DAILY.next_date(&now).unwrap();
mock_now assert_eq!((now + Duration::DAY).day(), next.day());
.with_hour(0)
.unwrap()
.with_minute(21)
.unwrap()
.with_second(0)
.unwrap(),
next
);
let mock_now = Utc.ymd(2020, 2, 1).and_hms(0, 59, 0); // never
let next = r.next_date(&mock_now); let now = OffsetDateTime::now_utc();
assert_eq!(mock_now.with_hour(1).unwrap().with_minute(0).unwrap(), next); let next = Rotation::NEVER.next_date(&now);
assert!(next.is_none());
let mock_now = Utc.ymd(2020, 2, 1).and_hms(23, 59, 0);
let next = r.next_date(&mock_now);
assert_eq!(
mock_now
.with_day(2)
.unwrap()
.with_hour(0)
.unwrap()
.with_minute(0)
.unwrap(),
next
);
let mock_now = Utc.ymd(2020, 12, 31).and_hms(23, 59, 0);
let next = r.next_date(&mock_now);
assert_eq!(Utc.ymd(2021, 1, 1).and_hms(0, 0, 0), next);
} }
#[test] #[test]
fn test_next_date_hourly() { #[should_panic(
let r = Rotation::HOURLY; expected = "internal error: entered unreachable code: Rotation::NEVER is impossible to round."
)]
let mock_now = Utc.ymd(2020, 2, 1).and_hms(0, 0, 0); fn test_never_date_rounding() {
let next = r.next_date(&mock_now); let now = OffsetDateTime::now_utc();
assert_eq!(mock_now.with_hour(1).unwrap(), next); let _ = Rotation::NEVER.round_date(&now);
let mock_now = Utc.ymd(2020, 2, 1).and_hms(0, 20, 0);
let next = r.next_date(&mock_now);
assert_eq!(mock_now.with_hour(1).unwrap().with_minute(0).unwrap(), next);
let mock_now = Utc.ymd(2020, 2, 1).and_hms(1, 0, 0);
let next = r.next_date(&mock_now);
assert_eq!(mock_now.with_hour(2).unwrap(), next);
let mock_now = Utc.ymd(2020, 2, 1).and_hms(23, 0, 0);
let next = r.next_date(&mock_now);
assert_eq!(mock_now.with_day(2).unwrap().with_hour(0).unwrap(), next);
let mock_now = Utc.ymd(2020, 12, 31).and_hms(23, 0, 0);
let next = r.next_date(&mock_now);
assert_eq!(Utc.ymd(2021, 1, 1).and_hms(0, 0, 0), next);
} }
#[test] #[test]
fn test_next_date_daily() { fn test_path_concatination() {
let r = Rotation::DAILY; let format = format_description::parse(
"[year]-[month]-[day] [hour]:[minute]:[second] [offset_hour \
sign:mandatory]:[offset_minute]:[offset_second]",
)
.unwrap();
let mock_now = Utc.ymd(2020, 8, 1).and_hms(0, 0, 0); let now = OffsetDateTime::parse("2020-02-01 10:01:00 +00:00:00", &format).unwrap();
let next = r.next_date(&mock_now);
assert_eq!(mock_now.with_day(2).unwrap().with_hour(0).unwrap(), next);
let mock_now = Utc.ymd(2020, 8, 1).and_hms(0, 20, 5); // per-minute
let next = r.next_date(&mock_now); let path = Rotation::MINUTELY.join_date("app.log", &now);
assert_eq!(Utc.ymd(2020, 8, 2).and_hms(0, 0, 0), next); assert_eq!("app.log.2020-02-01-10-01", path);
let mock_now = Utc.ymd(2020, 8, 31).and_hms(11, 0, 0); // per-hour
let next = r.next_date(&mock_now); let path = Rotation::HOURLY.join_date("app.log", &now);
assert_eq!(Utc.ymd(2020, 9, 1).and_hms(0, 0, 0), next); assert_eq!("app.log.2020-02-01-10", path);
let mock_now = Utc.ymd(2020, 12, 31).and_hms(23, 0, 0); // per-day
let next = r.next_date(&mock_now); let path = Rotation::DAILY.join_date("app.log", &now);
assert_eq!(Utc.ymd(2021, 1, 1).and_hms(0, 0, 0), next); assert_eq!("app.log.2020-02-01", path);
}
#[test] // never
fn test_round_date_minutely() { let path = Rotation::NEVER.join_date("app.log", &now);
let r = Rotation::MINUTELY; assert_eq!("app.log", path);
let mock_now = Utc.ymd(2020, 2, 1).and_hms(10, 3, 1);
assert_eq!(
Utc.ymd(2020, 2, 1).and_hms(10, 3, 0),
r.round_date(&mock_now)
);
let mock_now = Utc.ymd(2020, 2, 1).and_hms(10, 3, 0);
assert_eq!(mock_now, r.round_date(&mock_now));
}
#[test]
fn test_round_date_hourly() {
let r = Rotation::HOURLY;
let mock_now = Utc.ymd(2020, 2, 1).and_hms(10, 3, 1);
assert_eq!(
Utc.ymd(2020, 2, 1).and_hms(10, 0, 0),
r.round_date(&mock_now)
);
let mock_now = Utc.ymd(2020, 2, 1).and_hms(10, 0, 0);
assert_eq!(mock_now, r.round_date(&mock_now));
}
#[test]
fn test_rotation_path_minutely() {
let r = Rotation::MINUTELY;
let mock_now = Utc.ymd(2020, 2, 1).and_hms(10, 3, 1);
let path = r.join_date("MyApplication.log", &mock_now);
assert_eq!("MyApplication.log.2020-02-01-10-03", path);
}
#[test]
fn test_rotation_path_hourly() {
let r = Rotation::HOURLY;
let mock_now = Utc.ymd(2020, 2, 1).and_hms(10, 3, 1);
let path = r.join_date("MyApplication.log", &mock_now);
assert_eq!("MyApplication.log.2020-02-01-10", path);
}
#[test]
fn test_rotation_path_daily() {
let r = Rotation::DAILY;
let mock_now = Utc.ymd(2020, 2, 1).and_hms(10, 3, 1);
let path = r.join_date("MyApplication.log", &mock_now);
assert_eq!("MyApplication.log.2020-02-01", path);
}
#[test]
fn test_round_date_daily() {
let r = Rotation::DAILY;
let mock_now = Utc.ymd(2020, 2, 1).and_hms(10, 3, 1);
assert_eq!(
Utc.ymd(2020, 2, 1).and_hms(0, 0, 0),
r.round_date(&mock_now)
);
let mock_now = Utc.ymd(2020, 2, 1).and_hms(0, 0, 0);
assert_eq!(mock_now, r.round_date(&mock_now));
}
#[test]
fn test_next_date_never() {
let r = Rotation::NEVER;
let mock_now = Utc.ymd(2020, 2, 1).and_hms(0, 0, 0);
let next = r.next_date(&mock_now);
assert_eq!(next, Utc.ymd(9999, 1, 1).and_hms(1, 0, 0));
}
#[test]
fn test_join_date_never() {
let r = Rotation::NEVER;
let mock_now = Utc.ymd(2020, 2, 1).and_hms(0, 0, 0);
let joined_date = r.join_date("Hello.log", &mock_now);
assert_eq!(joined_date, "Hello.log");
} }
} }