Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

subscriber: add OffsetTime workaround for local offset #1772

Merged
merged 4 commits into from
Dec 28, 2021
Merged

subscriber: add OffsetTime workaround for local offset #1772

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
7a5de9b
subscriber: add OffsetTime workaround for local offset
marienz Dec 7, 2021
036d2b5
Merge branch 'v0.1.x' into tracing-subscriber-offset
hawkw Dec 21, 2021
543db37
Add an example using OffsetTime with Tokio
marienz Dec 26, 2021
d7c9dc1
Merge branch 'v0.1.x' into tracing-subscriber-offset
hawkw Dec 26, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 4 additions & 0 deletions tracing-subscriber/src/fmt/time/mod.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,10 @@ pub use time_crate::UtcTime;
#[cfg_attr(docsrs, doc(cfg(unsound_local_offset, feature = "local-time")))]
pub use time_crate::LocalTime;

#[cfg(feature = "time")]
#[cfg_attr(docsrs, doc(cfg(feature = "time")))]
pub use time_crate::OffsetTime;

/// 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.
Expand Down
169 changes: 168 additions & 1 deletion tracing-subscriber/src/fmt/time/time_crate.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
use crate::fmt::{format::Writer, time::FormatTime, writer::WriteAdaptor};
use std::fmt;
use time::{format_description::well_known, formatting::Formattable, OffsetDateTime};
use time::{format_description::well_known, formatting::Formattable, OffsetDateTime, UtcOffset};

/// Formats the current [local time] using a [formatter] from the [`time` crate].
///
Expand All @@ -13,6 +13,8 @@ use time::{format_description::well_known, formatting::Formattable, OffsetDateTi
/// local timestamps. When this cfg is not enabled, local timestamps cannot be recorded, and
/// events will be logged without timestamps.
///
/// Alternatively, [`OffsetTime`] can log with a local offset if it is initialized early.
///
/// See the <a href="https://docs.rs/time/0.3.4/time/#feature-flags"><code>time</code>
/// documentation</a> for more details.
/// </pre></div>
Expand Down Expand Up @@ -45,6 +47,23 @@ pub struct UtcTime<F> {
format: F,
}

/// Formats the current time using a fixed offset and a [formatter] from the [`time` crate].
///
/// This is typically used as an alternative to [`LocalTime`]. `LocalTime` determines the offset
/// every time it formats a message, which may be unsound or fail. With `OffsetTime`, the offset is
/// determined once. This makes it possible to do so while the program is still single-threaded and
/// handle any errors. However, this also means the offset cannot change while the program is
/// running (the offset will not change across DST changes).
///
/// [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(feature = "time")))]
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this states that the type requires the time feature, but it looks like all the methods implemented for this type also require the local-time feature...should the type itself also require that feature flag?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

OffsetTime::local_rfc_3339 requires local-time, but OffsetTime::init and OffsetTime::format_time (our impl FormatTime) do not. It should be possible (although admittedly unusual) to use OffsetTime with a non-local offset (not needing time's local-offset feature at all). And if our caller uses OffsetTime::init and calls current_local_offset themselves it seemed reasonable to have them enable the local-offset feature on the time crate themselves, rather than having them use our local-time feature just so we can turn on that time feature for them (we won't be doing anything with local time ourselves).

Please let me know if I'm overlooking something.

pub struct OffsetTime<F> {
offset: time::UtcOffset,
format: F,
}

// === impl LocalTime ===

#[cfg(feature = "local-time")]
Expand Down Expand Up @@ -291,6 +310,154 @@ where
}
}

// === impl OffsetTime ===

#[cfg(feature = "local-time")]
impl OffsetTime<well_known::Rfc3339> {
/// Returns a formatter that formats the current time using the [local time offset] in the [RFC
/// 3339] format (a subset of the [ISO 8601] timestamp format).
///
/// Returns an error if the local time offset cannot be determined. This typically occurs in
/// multithreaded programs. To avoid this problem, initialize `OffsetTime` before forking
/// threads. When using Tokio, this means initializing `OffsetTime` before the Tokio runtime.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

it might be worth adding an example showing initializing the formatter before starting a runtime? not a blocker though.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done (I didn't realize I could use Tokio and write my own main in examples like these...).

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I believe you can use Tokio because we have a dev dependency on tokio (it's used in a few other test).

Another approach I've used elsewhere in the documentation for tracing is to just do something like this:

//! # mod tokio {
//! #     fn spawn(_: impl Future<> {}
//! #    // fake versions of whatever other tokio APIs you need to show in the example...
//! # }
//! // the rest of the example...

///
/// # Examples
///
/// ```
/// use tracing_subscriber::fmt::{self, time};
///
/// let collector = tracing_subscriber::fmt()
/// .with_timer(time::OffsetTime::local_rfc_3339().expect("could not get local offset!"));
/// # drop(collector);
/// ```
///
/// Using `OffsetTime` with Tokio:
///
/// ```
/// use tracing_subscriber::fmt::time::OffsetTime;
///
/// #[tokio::main]
/// async fn run() {
/// tracing::info!("runtime initialized");
///
/// // At this point the Tokio runtime is initialized, and we can use both Tokio and Tracing
/// // normally.
/// }
///
/// fn main() {
/// // Because we need to get the local offset before Tokio spawns any threads, our `main`
/// // function cannot use `tokio::main`.
/// tracing_subscriber::fmt()
/// .with_timer(OffsetTime::local_rfc_3339().expect("could not get local time offset"))
/// .init();
///
/// // Even though `run` is written as an `async fn`, because we used `tokio::main` on it
/// // we can call it as a synchronous function.
/// run();
/// }
/// ```
///
/// [local time offset]: https://docs.rs/time/0.3/time/struct.UtcOffset.html#method.current_local_offset
/// [RFC 3339]: https://datatracker.ietf.org/doc/html/rfc3339
/// [ISO 8601]: https://en.wikipedia.org/wiki/ISO_8601
pub fn local_rfc_3339() -> Result<Self, time::error::IndeterminateOffset> {
Ok(Self::new(
UtcOffset::current_local_offset()?,
well_known::Rfc3339,
))
}
}

impl<F: time::formatting::Formattable> OffsetTime<F> {
/// Returns a formatter that formats the current time using the [`time` crate] with the provided
/// provided format and [timezone offset]. The format may be any type that implements the
/// [`Formattable`] trait.
///
///
/// Typically, the offset will be the [local offset], and 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::OffsetTime};
/// use time::macros::format_description;
/// use time::UtcOffset;
///
/// let offset = UtcOffset::current_local_offset().expect("should get local offset!");
/// let timer = OffsetTime::new(offset, 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::OffsetTime};
/// use time::UtcOffset;
///
/// let offset = UtcOffset::current_local_offset().expect("should get local offset!");
/// let time_format = time::format_description::parse("[hour]:[minute]:[second]")
/// .expect("format string should be valid!");
/// let timer = OffsetTime::new(offset, 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
/// [`OffsetTime::local_rfc_3339`]):
///
/// ```
/// use tracing_subscriber::fmt::{self, time::OffsetTime};
/// use time::UtcOffset;
///
/// let offset = UtcOffset::current_local_offset().expect("should get local offset!");
/// let timer = OffsetTime::new(offset, time::format_description::well_known::Rfc3339);
/// let collector = tracing_subscriber::fmt()
/// .with_timer(timer);
/// # drop(collector);
/// ```
///
/// [`time` crate]: https://docs.rs/time/0.3/time/
/// [timezone offset]: https://docs.rs/time/latest/time/struct.UtcOffset.html
/// [`Formattable`]: https://docs.rs/time/0.3/time/formatting/trait.Formattable.html
/// [local offset]: https://docs.rs/time/0.3.5/time/struct.UtcOffset.html#method.current_local_offset
/// [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(offset: time::UtcOffset, format: F) -> Self {
Self { offset, format }
}
}

impl<F> FormatTime for OffsetTime<F>
where
F: time::formatting::Formattable,
{
fn format_time(&self, w: &mut Writer<'_>) -> fmt::Result {
let now = OffsetDateTime::now_utc().to_offset(self.offset);
format_datetime(now, w, &self.format)
}
}
Comment on lines +451 to +459
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The actual formatting is not tested. My plan was to copy how LocalTime is tested, but I couldn't find its tests :) Happy to improve this if I missed something, or if you give me some pointers.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We don't really need tests for how the timestamp is actually formatted, because the way it's formatted is "however the time crate does it". :) Don't worry about adding tests for that.


fn format_datetime(
now: OffsetDateTime,
into: &mut Writer<'_>,
Expand Down