tracing-subscriber: LocalTime doesn't work by default on unix systems, no warning of --cfg unsound_local_offset

[lilyball]

Bug Report

Version

tracing-slog v0.1.0 (/Users/lily/Dev/Work/rust-crates/crates/tracing-slog)
└── tracing-core v0.1.21
├── tracing v0.1.29
│   ├── tracing-attributes v0.1.18 (proc-macro)
│   └── tracing-core v0.1.21 (*)
└── tracing-subscriber v0.3.1
    ├── tracing-core v0.1.21 (*)
    └── tracing-log v0.1.2
        └── tracing-core v0.1.21 (*)

Platform

Darwin DeerBook 20.6.0 Darwin Kernel Version 20.6.0: Mon Aug 30 06:12:21 PDT 2021; root:xnu-7195.141.6~3/RELEASE_X86_64 x86_64

Crates

tracing-subscriber

Description

Attempting to use .with_timer with a LocalTime argument cause all tracing events to vanish. The problem seems to be that on unix systems the time crate refuses to fetch the local offset without --cfg unsound_local_offset, and this gets turned into an error which bubbles up through the formatting until it gets to tracing_subscriber::fmt::FmtLayer::on_event() which just throws away the error and logs nothing.

This is rather surprising behavior, all the more-so that it isn't documented. Even the time crate itself doesn't give a good explanation of this feature, and doesn't warn that OffsetDateTime::now_local() doesn't work on unix systems without it. I only figured it out by looking through the source.

It also seems to be rather poor behavior to throw away the whole tracing event because the local time offset couldn't be fetched. Surely there's some fallback behavior that could be used here. I'd suggest just falling back to UTC except if the time formatter doesn't show offset then this could be confusing. It could of course just fall back to the default timestamp formatter, as if I never called .with_timer().

In any case, I feel like at a minimum this should be documented properly, so it doesn't surprise everybody. And then I would suggest that FormatTime be extended with methods that allow for implementing easy fallback, so I can say e.g. "if LocalTime doesn't work, try this other formatter instead". And any error bubbled up from FormatTime should just result in using a default fallback instead of abandoning the whole event.

[hawkw]

. Even the time crate itself doesn't give a good explanation of this feature, and doesn't warn that OffsetDateTime::now_local() doesn't work on unix systems without it. I only figured it out by looking through the source.

Whew, okay, I had no idea about this. Hmm. We should probably surface the feature flag in the docs, as well as adding a note. This was definitely not obvious from the time crate's docs.

It also seems to be rather poor behavior to throw away the whole tracing event because the local time offset couldn't be fetched. Surely there's some fallback behavior that could be used here. I'd suggest just falling back to UTC except if the time formatter doesn't show offset then this could be confusing. It could of course just fall back to the default timestamp formatter, as if I never called .with_timer().

Yeah, this should probably be fixed. Previously, getting the timestamp itself was always infallible, and the error would only be returned if formatting it failed...which, because it's being written to a String (the local buffer), would never happen. So, if writing to the buffer fails for some reason, it makes sense to just bail...but if getting the timestamp fails, it makes less sense. We should fix that as well.