From 6614b2f9ed680de1143e662ba0a56fe29db17060 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Mon, 18 Oct 2021 13:42:44 -0700 Subject: [PATCH] subscriber: replace `chrono` with `time` for timestamp formatting (#1646) ## 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 maintainance 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 Fortunately, the `time` crate now has its own timestamp formatting support. This branch replaces the `ChronoLocal` and `ChronoUtc` timestamp formatters with new `LocalTime` and `UtcTime` formatters. These formatters use the `time` crate's formatting APIs rather than `chrono`'s. This removes the vulnerable dependency on `time` 0.1 Additionally, the new `time` APIs are feature flagged as an _opt-in_ feature, rather than as an _opt-out_ feature. This should make it easier to avoid accidentally depending on the `time` crate when more sophisticated timestamp formatting is _not_ required. In a follow-up branch, we could also add support for `humantime` as an option for timestamp formatting. Naturally, since this removes existing APIs, this is a breaking change, and will thus require publishing `tracing-subscriber` 0.3. We'll want to do some other breaking changes as well. Fixes #1598. --- examples/Cargo.toml | 2 +- tracing-subscriber/Cargo.toml | 9 +- tracing-subscriber/benches/reload.rs | 7 +- tracing-subscriber/src/fmt/fmt_subscriber.rs | 15 +- tracing-subscriber/src/fmt/format/json.rs | 44 +-- tracing-subscriber/src/fmt/format/mod.rs | 11 +- tracing-subscriber/src/fmt/mod.rs | 15 +- tracing-subscriber/src/fmt/time/mod.rs | 128 +------- tracing-subscriber/src/fmt/time/time_crate.rs | 276 ++++++++++++++++++ tracing-subscriber/src/fmt/writer.rs | 44 ++- tracing-subscriber/src/lib.rs | 8 +- 11 files changed, 368 insertions(+), 191 deletions(-) create mode 100644 tracing-subscriber/src/fmt/time/time_crate.rs diff --git a/examples/Cargo.toml b/examples/Cargo.toml index 0cef263d96..8815831f1e 100644 --- a/examples/Cargo.toml +++ b/examples/Cargo.toml @@ -15,7 +15,7 @@ tracing-core = { path = "../tracing-core", version = "0.2"} tracing-error = { path = "../tracing-error" } tracing-flame = { path = "../tracing-flame" } tracing-tower = { version = "0.1.0", path = "../tracing-tower" } -tracing-subscriber = { path = "../tracing-subscriber", version = "0.3", features = ["json", "chrono"] } +tracing-subscriber = { path = "../tracing-subscriber", version = "0.3", features = ["json"] } tracing-futures = { version = "0.3", path = "../tracing-futures", features = ["futures-01"] } tracing-attributes = { path = "../tracing-attributes", version = "0.2"} tracing-log = { path = "../tracing-log", version = "0.2", features = ["env_logger"] } diff --git a/tracing-subscriber/Cargo.toml b/tracing-subscriber/Cargo.toml index db9bf35797..abe7c88ece 100644 --- a/tracing-subscriber/Cargo.toml +++ b/tracing-subscriber/Cargo.toml @@ -23,12 +23,15 @@ keywords = ["logging", "tracing", "metrics", "subscriber"] [features] -default = ["env-filter", "smallvec", "fmt", "ansi", "chrono", "tracing-log", "json"] +default = ["env-filter", "smallvec", "fmt", "ansi", "tracing-log", "json"] env-filter = ["matchers", "regex", "lazy_static", "tracing"] fmt = ["registry"] ansi = ["fmt", "ansi_term"] registry = ["sharded-slab", "thread_local"] json = ["tracing-serde", "serde", "serde_json"] +# Enables support for local time when using the `time` crate timestamp +# formatters. +local-time = ["time/local-offset"] [dependencies] tracing-core = { path = "../tracing-core", version = "0.2" } @@ -43,7 +46,7 @@ lazy_static = { optional = true, version = "1" } # fmt tracing-log = { path = "../tracing-log", version = "0.2", optional = true, default-features = false, features = ["log-tracer", "std"] } ansi_term = { version = "0.12", optional = true } -chrono = { version = "0.4.16", optional = true, default-features = false, features = ["clock", "std"] } +time = { version = "0.3", features = ["formatting"], optional = true } # only required by the json feature serde_json = { version = "1.0", optional = true } @@ -65,6 +68,8 @@ criterion = { version = "0.3", default_features = false } regex = { version = "1", default-features = false, features = ["std"] } tracing-futures = { path = "../tracing-futures", version = "0.3", default-features = false, features = ["std-future", "std"] } tokio = { version = "0.2", features = ["rt-core", "macros"] } +# Enable the `time` crate's `macros` feature, for examples. +time = { version = "0.3", features = ["formatting", "macros"] } [badges] maintenance = { status = "experimental" } diff --git a/tracing-subscriber/benches/reload.rs b/tracing-subscriber/benches/reload.rs index ae060f6160..71d50888bb 100644 --- a/tracing-subscriber/benches/reload.rs +++ b/tracing-subscriber/benches/reload.rs @@ -3,7 +3,6 @@ use tracing_subscriber::{ filter::LevelFilter, fmt::{ format::{DefaultFields, Format, Full}, - time::ChronoLocal, Collector, CollectorBuilder, }, EnvFilter, @@ -15,8 +14,7 @@ use support::NoWriter; /// Prepare a real-world-inspired collector and use it to measure the performance impact of /// reloadable collectors. -fn mk_builder( -) -> CollectorBuilder, EnvFilter, fn() -> NoWriter> { +fn mk_builder() -> CollectorBuilder, EnvFilter, fn() -> NoWriter> { let filter = EnvFilter::default() .add_directive("this=off".parse().unwrap()) .add_directive("also=off".parse().unwrap()) @@ -28,9 +26,6 @@ fn mk_builder( Collector::builder() .with_env_filter(filter) .with_writer(NoWriter::new as _) - .with_timer(ChronoLocal::with_format( - "%Y-%m-%d %H:%M:%S%.3f".to_string(), - )) .with_ansi(true) .with_target(true) .with_level(true) diff --git a/tracing-subscriber/src/fmt/fmt_subscriber.rs b/tracing-subscriber/src/fmt/fmt_subscriber.rs index c89556e6af..257c5c43f5 100644 --- a/tracing-subscriber/src/fmt/fmt_subscriber.rs +++ b/tracing-subscriber/src/fmt/fmt_subscriber.rs @@ -191,15 +191,18 @@ where { /// Use the given [`timer`] for span and event timestamps. /// - /// See [`time`] for the provided timer implementations. + /// See the [`time` module] for the provided timer implementations. /// - /// Note that using the `chrono` feature flag enables the - /// additional time formatters [`ChronoUtc`] and [`ChronoLocal`]. + /// Note that using the `"time`"" feature flag enables the + /// additional time formatters [`UtcTime`] and [`LocalTime`], which use the + /// [`time` crate] to provide more sophisticated timestamp formatting + /// options. /// - /// [`time`]: mod@super::time /// [`timer`]: super::time::FormatTime - /// [`ChronoUtc`]: super::time::ChronoUtc - /// [`ChronoLocal`]: super::time::ChronoLocal + /// [`time` module]: mod@super::time + /// [`UtcTime`]: super::time::UtcTime + /// [`LocalTime`]: super::time::LocalTime + /// [`time` crate]: https://docs.rs/time/0.3 pub fn with_timer(self, timer: T2) -> Subscriber, W> { Subscriber { fmt_event: self.fmt_event.with_timer(timer), diff --git a/tracing-subscriber/src/fmt/format/json.rs b/tracing-subscriber/src/fmt/format/json.rs index 5e5f509d96..98beff6f46 100644 --- a/tracing-subscriber/src/fmt/format/json.rs +++ b/tracing-subscriber/src/fmt/format/json.rs @@ -1,7 +1,10 @@ use super::{Format, FormatEvent, FormatFields, FormatTime}; use crate::{ field::{RecordFields, VisitOutput}, - fmt::fmt_subscriber::{FmtContext, FormattedFields}, + fmt::{ + fmt_subscriber::{FmtContext, FormattedFields}, + writer::WriteAdaptor, + }, registry::LookupSpan, }; use serde::ser::{SerializeMap, Serializer as _}; @@ -9,7 +12,6 @@ use serde_json::Serializer; use std::{ collections::BTreeMap, fmt::{self, Write}, - io, }; use tracing_core::{ field::{self, Field}, @@ -471,44 +473,6 @@ impl<'a> field::Visit for JsonVisitor<'a> { }; } } - -/// A bridge between `fmt::Write` and `io::Write`. -/// -/// This is needed because tracing-subscriber's FormatEvent expects a fmt::Write -/// while serde_json's Serializer expects an io::Write. -struct WriteAdaptor<'a> { - fmt_write: &'a mut dyn fmt::Write, -} - -impl<'a> WriteAdaptor<'a> { - fn new(fmt_write: &'a mut dyn fmt::Write) -> Self { - Self { fmt_write } - } -} - -impl<'a> io::Write for WriteAdaptor<'a> { - fn write(&mut self, buf: &[u8]) -> io::Result { - let s = - std::str::from_utf8(buf).map_err(|e| io::Error::new(io::ErrorKind::InvalidData, e))?; - - self.fmt_write - .write_str(s) - .map_err(|e| io::Error::new(io::ErrorKind::Other, e))?; - - Ok(s.as_bytes().len()) - } - - fn flush(&mut self) -> io::Result<()> { - Ok(()) - } -} - -impl<'a> fmt::Debug for WriteAdaptor<'a> { - fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { - f.pad("WriteAdaptor { .. }") - } -} - #[cfg(test)] mod test { use super::*; diff --git a/tracing-subscriber/src/fmt/format/mod.rs b/tracing-subscriber/src/fmt/format/mod.rs index 00fa4f89bf..458fed7f8d 100644 --- a/tracing-subscriber/src/fmt/format/mod.rs +++ b/tracing-subscriber/src/fmt/format/mod.rs @@ -362,13 +362,16 @@ impl Format { /// /// See [`time` module] for the provided timer implementations. /// - /// Note that using the `chrono` feature flag enables the - /// additional time formatters [`ChronoUtc`] and [`ChronoLocal`]. + /// Note that using the `"time"` feature flag enables the + /// additional time formatters [`UtcTime`] and [`LocalTime`], which use the + /// [`time` crate] to provide more sophisticated timestamp formatting + /// options. /// /// [`timer`]: super::time::FormatTime /// [`time` module]: mod@super::time - /// [`ChronoUtc`]: super::time::ChronoUtc - /// [`ChronoLocal`]: super::time::ChronoLocal + /// [`UtcTime`]: super::time::UtcTime + /// [`LocalTime`]: super::time::LocalTime + /// [`time` crate]: https://docs.rs/time/0.3 pub fn with_timer(self, timer: T2) -> Format { Format { format: self.format, diff --git a/tracing-subscriber/src/fmt/mod.rs b/tracing-subscriber/src/fmt/mod.rs index f1171dbbd6..5d1a11e523 100644 --- a/tracing-subscriber/src/fmt/mod.rs +++ b/tracing-subscriber/src/fmt/mod.rs @@ -611,15 +611,18 @@ where { /// Use the given [`timer`] for log message timestamps. /// - /// See [`time`] for the provided timer implementations. + /// See the [`time` module] for the provided timer implementations. /// - /// Note that using the `chrono` feature flag enables the - /// additional time formatters [`ChronoUtc`] and [`ChronoLocal`]. + /// Note that using the `"time`"" feature flag enables the + /// additional time formatters [`UtcTime`] and [`LocalTime`], which use the + /// [`time` crate] to provide more sophisticated timestamp formatting + /// options. /// - /// [`time`]: mod@time /// [`timer`]: time::FormatTime - /// [`ChronoUtc`]: time::ChronoUtc - /// [`ChronoLocal`]: time::ChronoLocal + /// [`time` module]: mod@time + /// [`UtcTime`]: time::UtcTime + /// [`LocalTime`]: time::LocalTime + /// [`time` crate]: https://docs.rs/time/0.3 pub fn with_timer(self, timer: T2) -> CollectorBuilder, F, W> { CollectorBuilder { filter: self.filter, diff --git a/tracing-subscriber/src/fmt/time/mod.rs b/tracing-subscriber/src/fmt/time/mod.rs index 708080f651..52e789fc60 100644 --- a/tracing-subscriber/src/fmt/time/mod.rs +++ b/tracing-subscriber/src/fmt/time/mod.rs @@ -2,9 +2,15 @@ use std::fmt; use std::time::Instant; -#[cfg(not(feature = "chrono"))] mod datetime; +#[cfg(feature = "time")] +#[cfg_attr(docsrs, doc(cfg(feature = "time")))] +mod time_crate; +#[cfg(feature = "time")] +#[cfg_attr(docsrs, doc(cfg(feature = "time")))] +pub use time_crate::{LocalTime, UtcTime}; + /// A type that can measure and format the current time. /// /// This trait is used by `Format` to include a timestamp with each `Event` when it is logged. @@ -81,9 +87,6 @@ impl FormatTime for fn(&mut dyn fmt::Write) -> fmt::Result { } /// Retrieve and print the current wall-clock time. -/// -/// If the `chrono` feature is enabled, the current time is printed in a human-readable format like -/// "Jun 25 14:27:12.955". Otherwise the `Debug` implementation of `std::time::SystemTime` is used. #[derive(Debug, Clone, Copy, Eq, PartialEq, Default)] pub struct SystemTime; @@ -109,14 +112,6 @@ impl From for Uptime { } } -#[cfg(feature = "chrono")] -impl FormatTime for SystemTime { - fn format_time(&self, w: &mut dyn fmt::Write) -> fmt::Result { - write!(w, "{}", chrono::Local::now().format("%b %d %H:%M:%S%.3f")) - } -} - -#[cfg(not(feature = "chrono"))] impl FormatTime for SystemTime { fn format_time(&self, w: &mut dyn fmt::Write) -> fmt::Result { write!( @@ -133,112 +128,3 @@ impl FormatTime for Uptime { write!(w, "{:4}.{:09}s", e.as_secs(), e.subsec_nanos()) } } - -/// The RFC 3339 format is used by default and using -/// this struct allows chrono to bypass the parsing -/// used when a custom format string is provided -#[cfg(feature = "chrono")] -#[derive(Debug, Clone, Eq, PartialEq)] -enum ChronoFmtType { - Rfc3339, - Custom(String), -} - -#[cfg(feature = "chrono")] -impl Default for ChronoFmtType { - fn default() -> Self { - ChronoFmtType::Rfc3339 - } -} - -/// Retrieve and print the current UTC time. -#[cfg(feature = "chrono")] -#[cfg_attr(docsrs, doc(cfg(feature = "chrono")))] -#[derive(Debug, Clone, Eq, PartialEq, Default)] -pub struct ChronoUtc { - format: ChronoFmtType, -} - -#[cfg(feature = "chrono")] -#[cfg_attr(docsrs, doc(cfg(feature = "chrono")))] -impl ChronoUtc { - /// Format the time using the [`RFC 3339`] format - /// (a subset of [`ISO 8601`]). - /// - /// [`RFC 3339`]: https://tools.ietf.org/html/rfc3339 - /// [`ISO 8601`]: https://en.wikipedia.org/wiki/ISO_8601 - pub fn rfc3339() -> Self { - ChronoUtc { - format: ChronoFmtType::Rfc3339, - } - } - - /// Format the time using the given format string. - /// - /// See [`chrono::format::strftime`] - /// for details on the supported syntax. - /// - pub fn with_format(format_string: String) -> Self { - ChronoUtc { - format: ChronoFmtType::Custom(format_string), - } - } -} - -#[cfg(feature = "chrono")] -#[cfg_attr(docsrs, doc(cfg(feature = "chrono")))] -impl FormatTime for ChronoUtc { - fn format_time(&self, w: &mut dyn fmt::Write) -> fmt::Result { - let time = chrono::Utc::now(); - match self.format { - ChronoFmtType::Rfc3339 => write!(w, "{}", time.to_rfc3339()), - ChronoFmtType::Custom(ref format_str) => write!(w, "{}", time.format(format_str)), - } - } -} - -/// Retrieve and print the current local time. -#[cfg(feature = "chrono")] -#[cfg_attr(docsrs, doc(cfg(feature = "chrono")))] -#[derive(Debug, Clone, Eq, PartialEq, Default)] -pub struct ChronoLocal { - format: ChronoFmtType, -} - -#[cfg(feature = "chrono")] -#[cfg_attr(docsrs, doc(cfg(feature = "chrono")))] -impl ChronoLocal { - /// Format the time using the [`RFC 3339`] format - /// (a subset of [`ISO 8601`]). - /// - /// [`RFC 3339`]: https://tools.ietf.org/html/rfc3339 - /// [`ISO 8601`]: https://en.wikipedia.org/wiki/ISO_8601 - pub fn rfc3339() -> Self { - ChronoLocal { - format: ChronoFmtType::Rfc3339, - } - } - - /// Format the time using the given format string. - /// - /// See [`chrono::format::strftime`] - /// for details on the supported syntax. - /// - pub fn with_format(format_string: String) -> Self { - ChronoLocal { - format: ChronoFmtType::Custom(format_string), - } - } -} - -#[cfg(feature = "chrono")] -#[cfg_attr(docsrs, doc(cfg(feature = "chrono")))] -impl FormatTime for ChronoLocal { - fn format_time(&self, w: &mut dyn fmt::Write) -> fmt::Result { - let time = chrono::Local::now(); - match self.format { - ChronoFmtType::Rfc3339 => write!(w, "{}", time.to_rfc3339()), - ChronoFmtType::Custom(ref format_str) => write!(w, "{}", time.format(format_str)), - } - } -} diff --git a/tracing-subscriber/src/fmt/time/time_crate.rs b/tracing-subscriber/src/fmt/time/time_crate.rs new file mode 100644 index 0000000000..360764f5bb --- /dev/null +++ b/tracing-subscriber/src/fmt/time/time_crate.rs @@ -0,0 +1,276 @@ +use crate::fmt::{time::FormatTime, writer::WriteAdaptor}; +use std::fmt; +use time::{format_description::well_known, formatting::Formattable, OffsetDateTime}; + +/// Formats the current [local time] using a [formatter] from the [`time` crate]. +/// +/// To format the current [UTC time] instead, use the [`UtcTime`] type. +/// +/// [local time]: https://docs.rs/time/0.3/time/struct.OffsetDateTime.html#method.now_local +/// [UTC time]: https://docs.rs/time/0.3/time/struct.OffsetDateTime.html#method.now_utc +/// [formatter]: https://docs.rs/time/0.3/time/formatting/trait.Formattable.html +/// [`time` crate]: https://docs.rs/time/0.3/time/ +#[derive(Clone, Debug)] +#[cfg_attr(docsrs, doc(cfg(all(feature = "time", feature = "local-time"))))] +#[cfg(feature = "local-time")] +pub struct LocalTime { + format: F, +} + +/// Formats the current [UTC time] using a [formatter] from the [`time` crate]. +/// +/// To format the current [local time] instead, use the [`LocalTime`] type. +/// +/// [local time]: https://docs.rs/time/0.3/time/struct.OffsetDateTime.html#method.now_local +/// [UTC time]: https://docs.rs/time/0.3/time/struct.OffsetDateTime.html#method.now_utc +/// [formatter]: https://docs.rs/time/0.3/time/formatting/trait.Formattable.html +/// [`time` crate]: https://docs.rs/time/0.3/time/ +#[cfg_attr(docsrs, doc(cfg(feature = "time")))] +#[derive(Clone, Debug)] +pub struct UtcTime { + format: F, +} + +// === impl LocalTime === + +#[cfg(feature = "local-time")] +impl LocalTime { + /// Returns a formatter that formats the current [local time] in the + /// [RFC 3339] format (a subset of the [ISO 8601] timestamp format). + /// + /// # Examples + /// + /// ``` + /// use tracing_subscriber::fmt::{self, time}; + /// + /// let collector = tracing_subscriber::fmt() + /// .with_timer(time::LocalTime::rfc_3339()); + /// # drop(collector); + /// ``` + /// + /// [local time]: https://docs.rs/time/0.3/time/struct.OffsetDateTime.html#method.now_local + /// [RFC 3339]: https://datatracker.ietf.org/doc/html/rfc3339 + /// [ISO 8601]: https://en.wikipedia.org/wiki/ISO_8601 + pub fn rfc_3339() -> Self { + Self::new(well_known::Rfc3339) + } +} + +#[cfg(feature = "local-time")] +impl LocalTime { + /// Returns a formatter that formats the current [local time] using the + /// [`time` crate] with the provided provided format. The format may be any + /// type that implements the [`Formattable`] trait. + /// + /// Typically, the format will be a format description string, or one of the + /// `time` crate's [well-known formats]. + /// + /// If the format description is statically known, then the + /// [`format_description!`] macro should be used. This is identical to the + /// [`time::format_description::parse] method, but runs at compile-time, + /// throwing an error if the format description is invalid. If the desired format + /// is not known statically (e.g., a user is providing a format string), then the + /// [`time::format_description::parse]` method should be used. Note that this + /// method is fallible. + /// + /// See the [`time` book] for details on the format description syntax. + /// + /// # Examples + /// + /// Using the [`format_description!`] macro: + /// + /// ``` + /// use tracing_subscriber::fmt::{self, time::LocalTime}; + /// use time::macros::format_description; + /// + /// let timer = LocalTime::new(format_description!("[hour]:[minute]:[second]")); + /// let collector = tracing_subscriber::fmt() + /// .with_timer(timer); + /// # drop(collector); + /// ``` + /// + /// Using [`time::format_description::parse`]: + /// + /// ``` + /// use tracing_subscriber::fmt::{self, time::LocalTime}; + /// + /// let time_format = time::format_description::parse("[hour]:[minute]:[second]") + /// .expect("format string should be valid!"); + /// let timer = LocalTime::new(time_format); + /// let collector = tracing_subscriber::fmt() + /// .with_timer(timer); + /// # drop(collector); + /// ``` + /// + /// Using the [`format_description!`] macro requires enabling the `time` + /// crate's "macros" feature flag. + /// + /// Using a [well-known format][well-known formats] (this is equivalent to + /// [`LocalTime::rfc_3339`]): + /// + /// ``` + /// use tracing_subscriber::fmt::{self, time::LocalTime}; + /// + /// let timer = LocalTime::new(time::format_description::well_known::Rfc3339); + /// let collector = tracing_subscriber::fmt() + /// .with_timer(timer); + /// # drop(collector); + /// ``` + /// + /// [local time]: https://docs.rs/time/latest/time/struct.OffsetDateTime.html#method.now_local + /// [`time` crate]: https://docs.rs/time/0.3/time/ + /// [`Formattable`]: https://docs.rs/time/0.3/time/formatting/trait.Formattable.html + /// [well-known formats]: https://docs.rs/time/0.3/time/format_description/well_known/index.html + /// [`format_description!`]: https://docs.rs/time/0.3/time/macros/macro.format_description.html + /// [`time::format_description::parse`]: https://docs.rs/time/0.3/time/format_description/fn.parse.html + /// [`time` book]: https://time-rs.github.io/book/api/format-description.html + pub fn new(format: F) -> Self { + Self { format } + } +} + +#[cfg(feature = "local-time")] +impl FormatTime for LocalTime +where + F: Formattable, +{ + fn format_time(&self, w: &mut dyn fmt::Write) -> fmt::Result { + let now = OffsetDateTime::now_local().map_err(|_| fmt::Error)?; + format_datetime(now, w, &self.format) + } +} + +#[cfg(feature = "local-time")] +impl Default for LocalTime +where + F: Formattable + Default, +{ + fn default() -> Self { + Self::new(F::default()) + } +} + +// === impl UtcTime === + +impl UtcTime { + /// Returns a formatter that formats the current [UTC time] in the + /// [RFC 3339] format, which is a subset of the [ISO 8601] timestamp format. + /// + /// # Examples + /// + /// ``` + /// use tracing_subscriber::fmt::{self, time}; + /// + /// let collector = tracing_subscriber::fmt() + /// .with_timer(time::UtcTime::rfc_3339()); + /// # drop(collector); + /// ``` + /// + /// [local time]: https://docs.rs/time/0.3/time/struct.OffsetDateTime.html#method.now_utc + /// [RFC 3339]: https://datatracker.ietf.org/doc/html/rfc3339 + /// [ISO 8601]: https://en.wikipedia.org/wiki/ISO_8601 + pub fn rfc_3339() -> Self { + Self::new(well_known::Rfc3339) + } +} + +impl UtcTime { + /// Returns a formatter that formats the current [UTC time] using the + /// [`time` crate], with the provided provided format. The format may be any + /// type that implements the [`Formattable`] trait. + /// + /// Typically, the format will be a format description string, or one of the + /// `time` crate's [well-known formats]. + /// + /// If the format description is statically known, then the + /// [`format_description!`] macro should be used. This is identical to the + /// [`time::format_description::parse] method, but runs at compile-time, + /// failing an error if the format description is invalid. If the desired format + /// is not known statically (e.g., a user is providing a format string), then the + /// [`time::format_description::parse]` method should be used. Note that this + /// method is fallible. + /// + /// See the [`time` book] for details on the format description syntax. + /// + /// # Examples + /// + /// Using the [`format_description!`] macro: + /// + /// ``` + /// use tracing_subscriber::fmt::{self, time::UtcTime}; + /// use time::macros::format_description; + /// + /// let timer = UtcTime::new(format_description!("[hour]:[minute]:[second]")); + /// let collector = tracing_subscriber::fmt() + /// .with_timer(timer); + /// # drop(collector); + /// ``` + /// + /// Using the [`format_description!`] macro requires enabling the `time` + /// crate's "macros" feature flag. + /// + /// Using [`time::format_description::parse`]: + /// + /// ``` + /// use tracing_subscriber::fmt::{self, time::UtcTime}; + /// + /// let time_format = time::format_description::parse("[hour]:[minute]:[second]") + /// .expect("format string should be valid!"); + /// let timer = UtcTime::new(time_format); + /// let collector = tracing_subscriber::fmt() + /// .with_timer(timer); + /// # drop(collector); + /// ``` + /// + /// Using a [well-known format][well-known formats] (this is equivalent to + /// [`UtcTime::rfc_3339`]): + /// + /// ``` + /// use tracing_subscriber::fmt::{self, time::UtcTime}; + /// + /// let timer = UtcTime::new(time::format_description::well_known::Rfc3339); + /// let collector = tracing_subscriber::fmt() + /// .with_timer(timer); + /// # drop(collector); + /// ``` + /// + /// [UTC time]: https://docs.rs/time/latest/time/struct.OffsetDateTime.html#method.now_utc + /// [`time` crate]: https://docs.rs/time/0.3/time/ + /// [`Formattable`]: https://docs.rs/time/0.3/time/formatting/trait.Formattable.html + /// [well-known formats]: https://docs.rs/time/0.3/time/format_description/well_known/index.html + /// [`format_description!`]: https://docs.rs/time/0.3/time/macros/macro.format_description.html + /// [`time::format_description::parse`]: https://docs.rs/time/0.3/time/format_description/fn.parse.html + /// [`time` book]: https://time-rs.github.io/book/api/format-description.html + pub fn new(format: F) -> Self { + Self { format } + } +} + +impl FormatTime for UtcTime +where + F: Formattable, +{ + fn format_time(&self, w: &mut dyn fmt::Write) -> fmt::Result { + format_datetime(OffsetDateTime::now_utc(), w, &self.format) + } +} + +impl Default for UtcTime +where + F: Formattable + Default, +{ + fn default() -> Self { + Self::new(F::default()) + } +} + +fn format_datetime( + now: OffsetDateTime, + into: &mut dyn fmt::Write, + fmt: &impl Formattable, +) -> fmt::Result { + let mut into = WriteAdaptor::new(into); + now.format_into(&mut into, fmt) + .map_err(|_| fmt::Error) + .map(|_| ()) +} diff --git a/tracing-subscriber/src/fmt/writer.rs b/tracing-subscriber/src/fmt/writer.rs index 31e53254d3..e0fbbafefb 100644 --- a/tracing-subscriber/src/fmt/writer.rs +++ b/tracing-subscriber/src/fmt/writer.rs @@ -3,7 +3,7 @@ //! [`io::Write`]: std::io::Write use std::{ - fmt::Debug, + fmt::{self, Debug}, io::{self, Write}, sync::{Mutex, MutexGuard}, }; @@ -635,6 +635,17 @@ pub struct Tee { b: B, } +/// A bridge between `fmt::Write` and `io::Write`. +/// +/// This is used by the timestamp formatting implementation for the `time` +/// crate and by the JSON formatter. In both cases, this is needed because +/// `tracing-subscriber`'s `FormatEvent`/`FormatTime` traits expect a +/// `fmt::Write` implementation, while `serde_json::Serializer` and `time`'s +/// `format_into` methods expect an `io::Write`. +pub(in crate::fmt) struct WriteAdaptor<'a> { + fmt_write: &'a mut dyn fmt::Write, +} + impl<'a, F, W> MakeWriter<'a> for F where F: Fn() -> W, @@ -1084,10 +1095,39 @@ where } } +// === impl WriteAdaptor === + +impl<'a> WriteAdaptor<'a> { + pub(in crate::fmt) fn new(fmt_write: &'a mut dyn fmt::Write) -> Self { + Self { fmt_write } + } +} + +impl<'a> io::Write for WriteAdaptor<'a> { + fn write(&mut self, buf: &[u8]) -> io::Result { + let s = + std::str::from_utf8(buf).map_err(|e| io::Error::new(io::ErrorKind::InvalidData, e))?; + + self.fmt_write + .write_str(s) + .map_err(|e| io::Error::new(io::ErrorKind::Other, e))?; + + Ok(s.as_bytes().len()) + } + + fn flush(&mut self) -> io::Result<()> { + Ok(()) + } +} + +impl<'a> fmt::Debug for WriteAdaptor<'a> { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + f.pad("WriteAdaptor { .. }") + } +} // === blanket impls === impl<'a, M> MakeWriterExt<'a> for M where M: MakeWriter<'a> {} - #[cfg(test)] mod test { use super::*; diff --git a/tracing-subscriber/src/lib.rs b/tracing-subscriber/src/lib.rs index 1129f233ef..2dfc196220 100644 --- a/tracing-subscriber/src/lib.rs +++ b/tracing-subscriber/src/lib.rs @@ -31,13 +31,15 @@ //! default. //! - `registry`: enables the [`registry`] module. Enabled by default. //! - `json`: Enables `fmt` support for JSON output. In JSON output, the ANSI feature does nothing. +//! - [`local-time`]: Enables local time formatting when using the [`time` +//! crate]'s timestamp formatters with the `fmt` subscriber. //! //! ### Optional Dependencies //! //! - [`tracing-log`]: Enables better formatting for events emitted by `log` //! macros in the `fmt` subscriber. On by default. -//! - [`chrono`]: Enables human-readable time formatting in the `fmt` subscriber. -//! Enabled by default. +//! - [`time`]: Enables support for using the [`time` crate] for timestamp +//! formatting in the `fmt` subscriber. //! - [`smallvec`]: Causes the `EnvFilter` type to use the `smallvec` crate (rather //! than `Vec`) as a performance optimization. Enabled by default. //! - [`parking_lot`]: Use the `parking_lot` crate's `RwLock` implementation @@ -63,9 +65,9 @@ //! [`EnvFilter`]: filter::EnvFilter //! [`tracing-log`]: https://crates.io/crates/tracing-log //! [`smallvec`]: https://crates.io/crates/smallvec -//! [`chrono`]: https://crates.io/crates/chrono //! [`env_logger` crate]: https://crates.io/crates/env_logger //! [`parking_lot`]: https://crates.io/crates/parking_lot +//! [`time` crate]: https://crates.io/crates/time #![doc(html_root_url = "https://docs.rs/tracing-subscriber/0.2.12")] #![doc( html_logo_url = "https://raw.githubusercontent.com/tokio-rs/tracing/master/assets/logo-type.png",