From 0991b41c0d12a3aa19230aa9e22e0db94fefbc41 Mon Sep 17 00:00:00 2001 From: Gus Wynn Date: Fri, 1 Jul 2022 12:39:36 -0700 Subject: [PATCH 1/8] subscriber: pass through `max_level_hint` in `reload` (#2204) ## Motivation When using a `reload` layer, the fast-path current level check doesn't work, as the `max_level_hint` is just `None`, which `rebuild_interest` interprets as `TRACE` ## Solution Pass through to the underlying layer/filter. On poisons, when already panicking, just return `None` --- tracing-subscriber/src/reload.rs | 12 ++++++++++- tracing-subscriber/tests/reload.rs | 32 +++++++++++++++++++++--------- 2 files changed, 34 insertions(+), 10 deletions(-) diff --git a/tracing-subscriber/src/reload.rs b/tracing-subscriber/src/reload.rs index 3d1743440e..0c6c1c45c4 100644 --- a/tracing-subscriber/src/reload.rs +++ b/tracing-subscriber/src/reload.rs @@ -75,7 +75,7 @@ use std::{ use tracing_core::{ callsite, span, subscriber::{Interest, Subscriber}, - Event, Metadata, + Event, LevelFilter, Metadata, }; /// Wraps a `Layer` or `Filter`, allowing it to be reloaded dynamically at runtime. @@ -173,6 +173,11 @@ where fn on_id_change(&self, old: &span::Id, new: &span::Id, ctx: layer::Context<'_, S>) { try_lock!(self.inner.read()).on_id_change(old, new, ctx) } + + #[inline] + fn max_level_hint(&self) -> Option { + try_lock!(self.inner.read(), else return None).max_level_hint() + } } // ===== impl Filter ===== @@ -218,6 +223,11 @@ where fn on_close(&self, id: span::Id, ctx: layer::Context<'_, S>) { try_lock!(self.inner.read()).on_close(id, ctx) } + + #[inline] + fn max_level_hint(&self) -> Option { + try_lock!(self.inner.read(), else return None).max_level_hint() + } } impl Layer { diff --git a/tracing-subscriber/tests/reload.rs b/tracing-subscriber/tests/reload.rs index b8b6c2b461..28662e2e6f 100644 --- a/tracing-subscriber/tests/reload.rs +++ b/tracing-subscriber/tests/reload.rs @@ -1,13 +1,16 @@ -#![cfg(feature = "std")] +#![cfg(feature = "registry")] use std::sync::atomic::{AtomicUsize, Ordering}; use tracing_core::{ span::{Attributes, Id, Record}, subscriber::Interest, - Event, Metadata, Subscriber, + Event, LevelFilter, Metadata, Subscriber, }; use tracing_subscriber::{layer, prelude::*, reload::*}; pub struct NopSubscriber; +fn event() { + tracing::info!("my event"); +} impl Subscriber for NopSubscriber { fn register_callsite(&self, _: &'static Metadata<'static>) -> Interest { @@ -53,9 +56,13 @@ fn reload_handle() { }; true } - } - fn event() { - tracing::trace!("my event"); + + fn max_level_hint(&self) -> Option { + match self { + Filter::One => Some(LevelFilter::INFO), + Filter::Two => Some(LevelFilter::DEBUG), + } + } } let (layer, handle) = Layer::new(Filter::One); @@ -71,7 +78,9 @@ fn reload_handle() { assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 1); assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 0); + assert_eq!(LevelFilter::current(), LevelFilter::INFO); handle.reload(Filter::Two).expect("should reload"); + assert_eq!(LevelFilter::current(), LevelFilter::DEBUG); event(); @@ -81,7 +90,6 @@ fn reload_handle() { } #[test] -#[cfg(feature = "registry")] fn reload_filter() { struct NopLayer; impl tracing_subscriber::Layer for NopLayer { @@ -111,9 +119,13 @@ fn reload_filter() { }; true } - } - fn event() { - tracing::trace!("my event"); + + fn max_level_hint(&self) -> Option { + match self { + Filter::One => Some(LevelFilter::INFO), + Filter::Two => Some(LevelFilter::DEBUG), + } + } } let (filter, handle) = Layer::new(Filter::One); @@ -131,7 +143,9 @@ fn reload_filter() { assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 1); assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 0); + assert_eq!(LevelFilter::current(), LevelFilter::INFO); handle.reload(Filter::Two).expect("should reload"); + assert_eq!(LevelFilter::current(), LevelFilter::DEBUG); event(); From 969bed19b04ce2c83cdf553e4002ddc91672a100 Mon Sep 17 00:00:00 2001 From: Taiki Endo Date: Tue, 12 Jul 2022 13:01:23 +0900 Subject: [PATCH 2/8] chore(ci): update actions/checkout action to v3 (#2213) Older versions use node 12 which is no longer supported (end-of-life on April 30, 2022). Also, @main/@master is not very good as they may run into unreleased breaking changes. --- .github/workflows/CI.yml | 22 +++++++++++----------- .github/workflows/audit.yml | 6 +++--- .github/workflows/release.yml | 2 +- 3 files changed, 15 insertions(+), 15 deletions(-) diff --git a/.github/workflows/CI.yml b/.github/workflows/CI.yml index 2529218a14..43fd26fbc1 100644 --- a/.github/workflows/CI.yml +++ b/.github/workflows/CI.yml @@ -39,7 +39,7 @@ jobs: name: cargo check runs-on: ubuntu-latest steps: - - uses: actions/checkout@main + - uses: actions/checkout@v3 - uses: actions-rs/toolchain@v1 with: toolchain: stable @@ -57,7 +57,7 @@ jobs: needs: check runs-on: ubuntu-latest steps: - - uses: actions/checkout@main + - uses: actions/checkout@v3 - uses: actions-rs/toolchain@v1 with: toolchain: stable @@ -75,7 +75,7 @@ jobs: runs-on: ubuntu-latest needs: check steps: - - uses: actions/checkout@main + - uses: actions/checkout@v3 - uses: actions-rs/toolchain@v1 with: toolchain: stable @@ -95,7 +95,7 @@ jobs: needs: check runs-on: ubuntu-latest steps: - - uses: actions/checkout@v2 + - uses: actions/checkout@v3 - uses: actions-rs/toolchain@v1 with: toolchain: nightly @@ -137,7 +137,7 @@ jobs: - tracing - tracing-subscriber steps: - - uses: actions/checkout@main + - uses: actions/checkout@v3 - uses: actions-rs/toolchain@v1 with: toolchain: stable @@ -180,7 +180,7 @@ jobs: needs: check runs-on: ubuntu-latest steps: - - uses: actions/checkout@master + - uses: actions/checkout@v3 - name: "install Rust ${{ env.MSRV }}" uses: actions-rs/toolchain@v1 with: @@ -223,7 +223,7 @@ jobs: needs: check runs-on: ubuntu-latest steps: - - uses: actions/checkout@master + - uses: actions/checkout@v3 - name: "install Rust ${{ env.APPENDER_MSRV }}" uses: actions-rs/toolchain@v1 with: @@ -268,7 +268,7 @@ jobs: fail-fast: false runs-on: ${{ matrix.os }} steps: - - uses: actions/checkout@main + - uses: actions/checkout@v3 - uses: actions-rs/toolchain@v1 with: toolchain: ${{ matrix.rust }} @@ -312,7 +312,7 @@ jobs: - tracing-tower fail-fast: false steps: - - uses: actions/checkout@main + - uses: actions/checkout@v3 - uses: actions-rs/toolchain@v1 with: target: wasm32-unknown-unknown @@ -333,7 +333,7 @@ jobs: subcrate: - tracing steps: - - uses: actions/checkout@main + - uses: actions/checkout@v3 - uses: actions-rs/toolchain@v1 with: target: wasm32-unknown-unknown @@ -353,7 +353,7 @@ jobs: needs: check runs-on: ubuntu-latest steps: - - uses: actions/checkout@main + - uses: actions/checkout@v3 - uses: actions-rs/toolchain@v1 with: toolchain: stable diff --git a/.github/workflows/audit.yml b/.github/workflows/audit.yml index 438cc500ef..f4d89ead1f 100644 --- a/.github/workflows/audit.yml +++ b/.github/workflows/audit.yml @@ -3,7 +3,7 @@ name: Security audit on: schedule: - cron: '0 0 * * *' - + env: # Disable incremental compilation. # @@ -29,7 +29,7 @@ jobs: security_audit: runs-on: ubuntu-latest steps: - - uses: actions/checkout@v1 + - uses: actions/checkout@v3 - uses: actions-rs/audit-check@v1 with: - token: ${{ secrets.GITHUB_TOKEN }} \ No newline at end of file + token: ${{ secrets.GITHUB_TOKEN }} diff --git a/.github/workflows/release.yml b/.github/workflows/release.yml index 98a6d33c77..77a52ca806 100644 --- a/.github/workflows/release.yml +++ b/.github/workflows/release.yml @@ -13,7 +13,7 @@ jobs: if: github.repository_owner == 'tokio-rs' runs-on: ubuntu-latest steps: - - uses: actions/checkout@v2 + - uses: actions/checkout@v3 - uses: taiki-e/create-gh-release-action@v1 with: prefix: tracing(-[a-z]+)? From 5f48248ebd28e022a69370f0fe4a061cd1ed9dcb Mon Sep 17 00:00:00 2001 From: Chris Burgess <9002722+cgbur@users.noreply.github.com> Date: Tue, 12 Jul 2022 11:57:39 -0400 Subject: [PATCH 3/8] docs: remove hard coded version link from readme (#2208) Motivation: When a user clicks they they may accidentally get an old version of the crate. Its also out of sync with the current main readme. Solution: removed the hard coded links --- tracing/README.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tracing/README.md b/tracing/README.md index 1c7261c6ff..4090c5d73b 100644 --- a/tracing/README.md +++ b/tracing/README.md @@ -16,9 +16,9 @@ Application-level tracing for Rust. [Documentation][docs-url] | [Chat][discord-url] [crates-badge]: https://img.shields.io/crates/v/tracing.svg -[crates-url]: https://crates.io/crates/tracing/0.1.35 +[crates-url]: https://crates.io/crates/tracing [docs-badge]: https://docs.rs/tracing/badge.svg -[docs-url]: https://docs.rs/tracing/0.1.35 +[docs-url]: https://docs.rs/tracing [docs-master-badge]: https://img.shields.io/badge/docs-master-blue [docs-master-url]: https://tracing-rs.netlify.com/tracing [mit-badge]: https://img.shields.io/badge/license-MIT-blue.svg From 9909b5ba5ac00ccd77085ec8771f0e6e616c0557 Mon Sep 17 00:00:00 2001 From: Guillaume Desmottes Date: Wed, 13 Jul 2022 21:13:14 +0200 Subject: [PATCH 4/8] appender: name spawned thread (#2219) ## Motivation I find it useful when debugging applications with lots of threads to easily identity them by their names. ## Solution Just name the thread as other crates such as `sentry-rust` are doing. Co-authored-by: Guillaume Desmottes --- tracing-appender/src/worker.rs | 33 ++++++++++++++++++--------------- 1 file changed, 18 insertions(+), 15 deletions(-) diff --git a/tracing-appender/src/worker.rs b/tracing-appender/src/worker.rs index 5508baca85..622cb2c61a 100644 --- a/tracing-appender/src/worker.rs +++ b/tracing-appender/src/worker.rs @@ -68,22 +68,25 @@ impl Worker { /// Creates a worker thread that processes a channel until it's disconnected pub(crate) fn worker_thread(mut self) -> std::thread::JoinHandle<()> { - thread::spawn(move || { - loop { - match self.work() { - Ok(WorkerState::Continue) | Ok(WorkerState::Empty) => {} - Ok(WorkerState::Shutdown) | Ok(WorkerState::Disconnected) => { - let _ = self.shutdown.recv(); - break; - } - Err(_) => { - // TODO: Expose a metric for IO Errors, or print to stderr + thread::Builder::new() + .name("tracing-appender".to_string()) + .spawn(move || { + loop { + match self.work() { + Ok(WorkerState::Continue) | Ok(WorkerState::Empty) => {} + Ok(WorkerState::Shutdown) | Ok(WorkerState::Disconnected) => { + let _ = self.shutdown.recv(); + break; + } + Err(_) => { + // TODO: Expose a metric for IO Errors, or print to stderr + } } } - } - if let Err(e) = self.writer.flush() { - eprintln!("Failed to flush. Error: {}", e); - } - }) + if let Err(e) = self.writer.flush() { + eprintln!("Failed to flush. Error: {}", e); + } + }) + .expect("failed to spawn `tracing-appender` non-blocking worker thread") } } From 0af3a31c4dd8807bae6eb6df97fa81b34324b9e4 Mon Sep 17 00:00:00 2001 From: Joshua Nelson Date: Wed, 13 Jul 2022 19:27:16 -0400 Subject: [PATCH 5/8] tracing: allow owned values and fat pointers in `Span::record` (#2212) Previously, using `record("x", "y")` would give an error: ``` error[E0277]: the size for values of type `str` cannot be known at compilation time --> src/main.rs:3:22 | 243 | span.record("x", "y"); | ^^^^^^ doesn't have a size known at compile-time | = help: the trait `Sized` is not implemented for `str` note: required by a bound in `Span::record` --> /home/jnelson/.local/lib/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/tracing-0.1.32/src/span.rs:1184:30 | 1184 | pub fn record(&self, field: &Q, value: &V) -> &Self | ^ required by this bound in `Span::record` ``` Now it works fine, as tested by the doc-example. This doesn't break any existing code, because there's a generic `impl Value for &T`: https://docs.rs/tracing/0.1.35/tracing/trait.Value.html#impl-Value-for-%26%27a%20T Co-authored-by: Eliza Weisman --- tracing/src/span.rs | 18 ++++++++++++------ 1 file changed, 12 insertions(+), 6 deletions(-) diff --git a/tracing/src/span.rs b/tracing/src/span.rs index 21358eb276..58822f4d9b 100644 --- a/tracing/src/span.rs +++ b/tracing/src/span.rs @@ -1136,7 +1136,7 @@ impl Span { /// /// // Now, record a value for parting as well. /// // (note that the field name is passed as a string slice) - /// span.record("parting", &"goodbye world!"); + /// span.record("parting", "goodbye world!"); /// ``` /// However, it may also be used to record a _new_ value for a field whose /// value was already recorded: @@ -1154,7 +1154,7 @@ impl Span { /// } /// Err(_) => { /// // Things are no longer okay! - /// span.record("is_okay", &false); + /// span.record("is_okay", false); /// } /// } /// ``` @@ -1181,17 +1181,17 @@ impl Span { /// // Now, you try to record a value for a new field, `new_field`, which was not /// // declared as `Empty` or populated when you created `span`. /// // You won't get any error, but the assignment will have no effect! - /// span.record("new_field", &"interesting_value_you_really_need"); + /// span.record("new_field", "interesting_value_you_really_need"); /// /// // Instead, all fields that may be recorded after span creation should be declared up front, /// // using field::Empty when a value is not known, as we did for `parting`. /// // This `record` call will indeed replace field::Empty with "you will be remembered". - /// span.record("parting", &"you will be remembered"); + /// span.record("parting", "you will be remembered"); /// ``` /// /// [`field::Empty`]: super::field::Empty /// [`Metadata`]: super::Metadata - pub fn record(&self, field: &Q, value: &V) -> &Self + pub fn record(&self, field: &Q, value: V) -> &Self where Q: field::AsField, V: field::Value, @@ -1201,7 +1201,7 @@ impl Span { self.record_all( &meta .fields() - .value_set(&[(&field, Some(value as &dyn field::Value))]), + .value_set(&[(&field, Some(&value as &dyn field::Value))]), ); } } @@ -1614,4 +1614,10 @@ mod test { impl AssertSync for Span {} impl AssertSync for Entered<'_> {} impl AssertSync for EnteredSpan {} + + #[test] + fn test_record_backwards_compat() { + Span::current().record("some-key", &"some text"); + Span::current().record("some-key", &false); + } } From af36ba51e8508a6574b9b938046072dcff13c58c Mon Sep 17 00:00:00 2001 From: Aleksey Kladov Date: Thu, 14 Jul 2022 20:50:42 +0100 Subject: [PATCH 6/8] core: remove misleading dispatcher docs (#2220) There's no automated propagation of subscribers between spans, you have to do this manually. https://discord.com/channels/500028886025895936/997201342596657232/997210656677830778 Co-authored-by: Eliza Weisman --- tracing/src/subscriber.rs | 17 +++++++---------- 1 file changed, 7 insertions(+), 10 deletions(-) diff --git a/tracing/src/subscriber.rs b/tracing/src/subscriber.rs index 343dc5914c..f55698d13f 100644 --- a/tracing/src/subscriber.rs +++ b/tracing/src/subscriber.rs @@ -5,12 +5,12 @@ pub use tracing_core::subscriber::*; #[cfg_attr(docsrs, doc(cfg(feature = "std")))] pub use tracing_core::dispatcher::DefaultGuard; -/// Sets this subscriber as the default for the duration of a closure. +/// Sets this [`Subscriber`] as the default for the current thread for the +/// duration of a closure. /// /// The default subscriber is used when creating a new [`Span`] or -/// [`Event`], _if no span is currently executing_. If a span is currently -/// executing, new spans or events are dispatched to the subscriber that -/// tagged that span, instead. +/// [`Event`]. +/// /// /// [`Span`]: super::span::Span /// [`Subscriber`]: super::subscriber::Subscriber @@ -43,13 +43,10 @@ where crate::dispatcher::set_global_default(crate::Dispatch::new(subscriber)) } -/// Sets the subscriber as the default for the duration of the lifetime of the -/// returned [`DefaultGuard`] +/// Sets the [`Subscriber`] as the default for the current thread for the +/// duration of the lifetime of the returned [`DefaultGuard`]. /// -/// The default subscriber is used when creating a new [`Span`] or -/// [`Event`], _if no span is currently executing_. If a span is currently -/// executing, new spans or events are dispatched to the subscriber that -/// tagged that span, instead. +/// The default subscriber is used when creating a new [`Span`] or [`Event`]. /// /// [`Span`]: super::span::Span /// [`Subscriber`]: super::subscriber::Subscriber From 67b94747144a9b056263be48a31767724cd3327b Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Mon, 18 Jul 2022 12:21:25 -0700 Subject: [PATCH 7/8] appender: add a builder for constructing `RollingFileAppender`s (#2227) ## Motivation Several currently open PRs, such as #2225 and #2221, add new configuration parameters to the rolling file appender in `tracing-appender`. The best way to add new optional configuration settings without breaking existing APIs or creating a very large number of new constructors is to add a builder interface. ## Solution Since a number of PRs would all need to add the builder API, introducing potential conflicts, this branch _just_ adds the builder interface without adding any new configuration options. Once this merges, the existing in-flight PRs can be rebased onto this branch to use the builder interface without conflicting with each other. Also, the `Builder::build` method is fallible and returns a `Result`, rather than panicking. This is a relatively common pattern in Rust --- for example, `std::thread::Builder::spawn` returns a `Result` if a new thread cannot be spawned, while `std::thread::spawn` simply panics. This allows users to handle appender initialization errors gracefully without breaking the API of the existing `new` constructor. Fixes #1953 Signed-off-by: Eliza Weisman --- tracing-appender/Cargo.toml | 1 + tracing-appender/src/rolling.rs | 160 ++++++++++++++++------- tracing-appender/src/rolling/builder.rs | 167 ++++++++++++++++++++++++ 3 files changed, 280 insertions(+), 48 deletions(-) create mode 100644 tracing-appender/src/rolling/builder.rs diff --git a/tracing-appender/Cargo.toml b/tracing-appender/Cargo.toml index 2d02b38e95..9f4e52139b 100644 --- a/tracing-appender/Cargo.toml +++ b/tracing-appender/Cargo.toml @@ -24,6 +24,7 @@ rust-version = "1.53.0" crossbeam-channel = "0.5.0" time = { version = "0.3", default-features = false, features = ["formatting"] } parking_lot = { optional = true, version = "0.12.0" } +thiserror = "1" [dependencies.tracing-subscriber] path = "../tracing-subscriber" diff --git a/tracing-appender/src/rolling.rs b/tracing-appender/src/rolling.rs index db1099403f..d4b2ee6fcf 100644 --- a/tracing-appender/src/rolling.rs +++ b/tracing-appender/src/rolling.rs @@ -31,11 +31,14 @@ use std::{ fmt::{self, Debug}, fs::{self, File, OpenOptions}, io::{self, Write}, - path::Path, + path::{Path, PathBuf}, sync::atomic::{AtomicUsize, Ordering}, }; use time::{format_description, Duration, OffsetDateTime, Time}; +mod builder; +pub use builder::{Builder, InitError}; + /// A file appender with the ability to rotate log files at a fixed schedule. /// /// `RollingFileAppender` implements the [`std:io::Write` trait][write] and will @@ -98,8 +101,8 @@ pub struct RollingWriter<'a>(RwLockReadGuard<'a, File>); #[derive(Debug)] struct Inner { - log_directory: String, - log_filename_prefix: String, + log_directory: PathBuf, + log_filename_prefix: Option, rotation: Rotation, next_date: AtomicUsize, } @@ -122,8 +125,10 @@ impl RollingFileAppender { /// - [`Rotation::daily()`][daily], /// - [`Rotation::never()`][never()] /// + /// Additional parameters can be configured using [`RollingFileAppender::builder`]. /// /// # Examples + /// /// ```rust /// # fn docs() { /// use tracing_appender::rolling::{RollingFileAppender, Rotation}; @@ -133,16 +138,63 @@ impl RollingFileAppender { pub fn new( rotation: Rotation, directory: impl AsRef, - file_name_prefix: impl AsRef, + filename_prefix: impl AsRef, ) -> RollingFileAppender { + let filename_prefix = filename_prefix + .as_ref() + .to_str() + .expect("filename prefix must be a valid UTF-8 string"); + Self::builder() + .rotation(rotation) + .filename_prefix(filename_prefix) + .build(directory) + .expect("initializing rolling file appender failed") + } + + /// Returns a new [`Builder`] for configuring a `RollingFileAppender`. + /// + /// The builder interface can be used to set additional configuration + /// parameters when constructing a new appender. + /// + /// Unlike [`RollingFileAppender::new`], the [`Builder::build`] method + /// returns a `Result` rather than panicking when the appender cannot be + /// initialized. Therefore, the builder interface can also be used when + /// appender initialization errors should be handled gracefully. + /// + /// # Examples + /// + /// ```rust + /// # fn docs() { + /// use tracing_appender::rolling::{RollingFileAppender, Rotation}; + /// + /// let file_appender = RollingFileAppender::builder() + /// .rotation(Rotation::HOURLY) // rotate log files once every hour + /// .filename_prefix("myapp") // log file names will be prefixed with `myapp.` + /// .build("/var/log") // try to build an appender that stores log files in `/var/log` + /// .expect("initializing rolling file appender failed"); + /// # drop(file_appender); + /// # } + /// ``` + #[must_use] + pub fn builder() -> Builder { + Builder::new() + } + + fn from_builder(builder: &Builder, directory: impl AsRef) -> Result { + let Builder { + ref rotation, + ref prefix, + } = builder; + let filename_prefix = prefix.clone(); + let directory = directory.as_ref().to_path_buf(); let now = OffsetDateTime::now_utc(); - let (state, writer) = Inner::new(now, rotation, directory, file_name_prefix); - Self { + let (state, writer) = Inner::new(now, rotation.clone(), directory, filename_prefix)?; + Ok(Self { state, writer, #[cfg(test)] now: Box::new(OffsetDateTime::now_utc), - } + }) } #[inline] @@ -428,35 +480,42 @@ impl Rotation { } } - pub(crate) fn join_date(&self, filename: &str, date: &OffsetDateTime) -> String { - match *self { + pub(crate) fn join_date(&self, filename: Option<&str>, date: &OffsetDateTime) -> String { + let date = match *self { Rotation::MINUTELY => { let format = format_description::parse("[year]-[month]-[day]-[hour]-[minute]") .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) + date.format(&format) + .expect("Unable to format OffsetDateTime; this is a bug in tracing-appender") } 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) + date.format(&format) + .expect("Unable to format OffsetDateTime; this is a bug in tracing-appender") } 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) + date.format(&format) + .expect("Unable to format OffsetDateTime; this is a bug in tracing-appender") + } + Rotation::NEVER => { + // If there's a name prefix, use that. + if let Some(filename) = filename { + return filename.to_owned(); + } + + // Otherwise, just use the date. + let format = format_description::parse("[year]-[month]-[day]") + .expect("Unable to create a formatter; this is a bug in tracing-appender"); + date.format(&format) + .expect("Unable to format OffsetDateTime; this is a bug in tracing-appender") } - Rotation::NEVER => filename.to_string(), + }; + match filename { + Some(filename) => format!("{}.{}", filename, date), + None => date, } } } @@ -480,20 +539,16 @@ impl Inner { now: OffsetDateTime, rotation: Rotation, directory: impl AsRef, - file_name_prefix: impl AsRef, - ) -> (Self, RwLock) { - let log_directory = directory.as_ref().to_str().unwrap(); - let log_filename_prefix = file_name_prefix.as_ref().to_str().unwrap(); - - let filename = rotation.join_date(log_filename_prefix, &now); + log_filename_prefix: Option, + ) -> Result<(Self, RwLock), builder::InitError> { + let log_directory = directory.as_ref().to_path_buf(); + let filename = rotation.join_date(log_filename_prefix.as_deref(), &now); let next_date = rotation.next_date(&now); - let writer = RwLock::new( - create_writer(log_directory, &filename).expect("failed to create appender"), - ); + let writer = RwLock::new(create_writer(log_directory.as_ref(), &filename)?); let inner = Inner { - log_directory: log_directory.to_string(), - log_filename_prefix: log_filename_prefix.to_string(), + log_directory, + log_filename_prefix, next_date: AtomicUsize::new( next_date .map(|date| date.unix_timestamp() as usize) @@ -501,11 +556,13 @@ impl Inner { ), rotation, }; - (inner, writer) + Ok((inner, writer)) } fn refresh_writer(&self, now: OffsetDateTime, file: &mut File) { - let filename = self.rotation.join_date(&self.log_filename_prefix, &now); + let filename = self + .rotation + .join_date(self.log_filename_prefix.as_deref(), &now); match create_writer(&self.log_directory, &filename) { Ok(new_file) => { @@ -552,20 +609,22 @@ impl Inner { } } -fn create_writer(directory: &str, filename: &str) -> io::Result { - let path = Path::new(directory).join(filename); +fn create_writer(directory: &Path, filename: &str) -> Result { + let path = directory.join(filename); let mut open_options = OpenOptions::new(); open_options.append(true).create(true); let new_file = open_options.open(path.as_path()); if new_file.is_err() { if let Some(parent) = path.parent() { - fs::create_dir_all(parent)?; - return open_options.open(path); + fs::create_dir_all(parent).map_err(InitError::ctx("failed to create log directory"))?; + return open_options + .open(path) + .map_err(InitError::ctx("failed to create initial log file")); } } - new_file + new_file.map_err(InitError::ctx("failed to create initial log file")) } #[cfg(test)] @@ -673,19 +732,19 @@ mod test { let now = OffsetDateTime::parse("2020-02-01 10:01:00 +00:00:00", &format).unwrap(); // per-minute - let path = Rotation::MINUTELY.join_date("app.log", &now); + let path = Rotation::MINUTELY.join_date(Some("app.log"), &now); assert_eq!("app.log.2020-02-01-10-01", path); // per-hour - let path = Rotation::HOURLY.join_date("app.log", &now); + let path = Rotation::HOURLY.join_date(Some("app.log"), &now); assert_eq!("app.log.2020-02-01-10", path); // per-day - let path = Rotation::DAILY.join_date("app.log", &now); + let path = Rotation::DAILY.join_date(Some("app.log"), &now); assert_eq!("app.log.2020-02-01", path); // never - let path = Rotation::NEVER.join_date("app.log", &now); + let path = Rotation::NEVER.join_date(Some("app.log"), &now); assert_eq!("app.log", path); } @@ -702,8 +761,13 @@ mod test { let now = OffsetDateTime::parse("2020-02-01 10:01:00 +00:00:00", &format).unwrap(); let directory = tempfile::tempdir().expect("failed to create tempdir"); - let (state, writer) = - Inner::new(now, Rotation::HOURLY, directory.path(), "test_make_writer"); + let (state, writer) = Inner::new( + now, + Rotation::HOURLY, + directory.path(), + Some("test_make_writer".to_string()), + ) + .unwrap(); let clock = Arc::new(Mutex::new(now)); let now = { diff --git a/tracing-appender/src/rolling/builder.rs b/tracing-appender/src/rolling/builder.rs new file mode 100644 index 0000000000..82161f0cc6 --- /dev/null +++ b/tracing-appender/src/rolling/builder.rs @@ -0,0 +1,167 @@ +use super::{RollingFileAppender, Rotation}; +use std::{io, path::Path}; +use thiserror::Error; + +/// A [builder] for configuring [`RollingFileAppender`]s. +/// +/// [builder]: https://rust-unofficial.github.io/patterns/patterns/creational/builder.html +#[derive(Debug)] +pub struct Builder { + pub(super) rotation: Rotation, + pub(super) prefix: Option, +} + +/// Errors returned by [`Builder::build`]. +#[derive(Error, Debug)] +#[error("{context}: {source}")] +pub struct InitError { + context: &'static str, + #[source] + source: io::Error, +} + +impl InitError { + pub(crate) fn ctx(context: &'static str) -> impl FnOnce(io::Error) -> Self { + move |source| Self { context, source } + } +} + +impl Builder { + /// Returns a new `Builder` for configuring a [`RollingFileAppender`], with + /// the default parameters. + /// + /// # Default Values + /// + /// The default values for the builder are: + /// + /// | Parameter | Default Value | Notes | + /// | :-------- | :------------ | :---- | + /// | [`rotation`] | [`Rotation::NEVER`] | By default, log files will never be rotated. | + /// | [`filename_prefix`] | `""` | By default, log file names will not have a prefix. | + /// + /// [`rotation`]: Self::rotation + /// [`filename_prefix`]: Self::filename_prefix + #[must_use] + pub const fn new() -> Self { + Self { + rotation: Rotation::NEVER, + prefix: None, + } + } + + /// Sets the [rotation strategy] for log files. + /// + /// By default, this is [`Rotation::NEVER`]. + /// + /// # Examples + /// + /// ``` + /// # fn docs() { + /// use tracing_appender::rolling::{Rotation, RollingFileAppender}; + /// + /// let appender = RollingFileAppender::builder() + /// .rotation(Rotation::HOURLY) // rotate log files once every hour + /// // ... + /// .build("/var/log") + /// .expect("failed to initialize rolling file appender"); + /// + /// # drop(appender) + /// # } + /// ``` + /// + /// [rotation strategy]: Rotation + #[must_use] + pub fn rotation(self, rotation: Rotation) -> Self { + Self { rotation, ..self } + } + + /// Sets the prefix for log filenames. The prefix is output before the + /// timestamp in the file name, and if it is non-empty, it is followed by a + /// dot (`.`). + /// + /// By default, log files do not have a prefix. + /// + /// # Examples + /// + /// Setting a prefix: + /// + /// ``` + /// use tracing_appender::rolling::RollingFileAppender; + /// + /// # fn docs() { + /// let appender = RollingFileAppender::builder() + /// .filename_prefix("myapp.log") // log files will have names like "myapp.log.2019-01-01" + /// // ... + /// .build("/var/log") + /// .expect("failed to initialize rolling file appender"); + /// # drop(appender) + /// # } + /// ``` + /// + /// No prefix: + /// + /// ``` + /// use tracing_appender::rolling::RollingFileAppender; + /// + /// # fn docs() { + /// let appender = RollingFileAppender::builder() + /// .filename_prefix("") // log files will have names like "2019-01-01" + /// // ... + /// .build("/var/log") + /// .expect("failed to initialize rolling file appender"); + /// # drop(appender) + /// # } + /// ``` + /// + /// [rotation strategy]: Rotation + #[must_use] + pub fn filename_prefix(self, prefix: impl Into) -> Self { + let prefix = prefix.into(); + // If the configured prefix is the empty string, then don't include a + // separator character. + let prefix = if prefix.is_empty() { + None + } else { + Some(prefix) + }; + Self { prefix, ..self } + } + + /// Builds a new [`RollingFileAppender`] with the configured parameters, + /// emitting log files to the provided directory. + /// + /// Unlike [`RollingFileAppender::new`], this returns a `Result` rather than + /// panicking when the appender cannot be initialized. + /// + /// # Examples + /// + /// ``` + /// use tracing_appender::rolling::{Rotation, RollingFileAppender}; + /// + /// # fn docs() { + /// let appender = RollingFileAppender::builder() + /// .rotation(Rotation::DAILY) // rotate log files once per day + /// .filename_prefix("myapp.log") // log files will have names like "myapp.log.2019-01-01" + /// .build("/var/log/myapp") // write log files to the '/var/log/myapp' directory + /// .expect("failed to initialize rolling file appender"); + /// # drop(appender); + /// # } + /// ``` + /// + /// This is equivalent to + /// ``` + /// # fn docs() { + /// let appender = tracing_appender::rolling::daily("myapp.log", "/var/log/myapp"); + /// # drop(appender); + /// # } + /// ``` + pub fn build(&self, directory: impl AsRef) -> Result { + RollingFileAppender::from_builder(self, directory) + } +} + +impl Default for Builder { + fn default() -> Self { + Self::new() + } +} From f4da668d0545f5271769d3a2af2469663da9bcee Mon Sep 17 00:00:00 2001 From: Jack Wrenn Date: Tue, 19 Jul 2022 18:36:59 -0400 Subject: [PATCH 8/8] core: implement `PartialEq`, `Eq` for `Metadata`, `FieldSet` (#2229) A `FieldSet` is equal to another `FieldSet` if they share the same callsite and fields (provided in the same order). This ensures that a `Field` applicable to one `FieldSet` is applicable to any equal `FieldSet`. A `Metadata` is equal to another `Metadata` if all of their contained metadata is exactly equal. This change manually re-implements `PartialEq` and `Eq` for `Metadata` and `FieldSet` to define their equality strictly in terms of callsite equality. In debug builds, the equality of these types' other fields is also checked. Documentation is added to both `Metadata` and `FieldSet` explaining this behavior. The expectation that, in a well-behaving application, `Metadata` and `FieldSet`s with equal callsites will be otherwise equal is documented on `Callsite::metadata`. This is not a breaking change, as previous releases did not define equality for `Metadata` or `FieldSet`. The `Callsite` trait remains safe, as this expectation is not (yet) a safety-critical property. --- tracing-core/src/callsite.rs | 9 ++++ tracing-core/src/field.rs | 44 ++++++++++++++++++ tracing-core/src/metadata.rs | 89 ++++++++++++++++++++++++++++-------- 3 files changed, 124 insertions(+), 18 deletions(-) diff --git a/tracing-core/src/callsite.rs b/tracing-core/src/callsite.rs index d0fe1a3d6c..bc7405ffa0 100644 --- a/tracing-core/src/callsite.rs +++ b/tracing-core/src/callsite.rs @@ -137,6 +137,15 @@ pub trait Callsite: Sync { /// Returns the [metadata] associated with the callsite. /// + ///
+ /// 
+    ///
+    /// **Note:** Implementations of this method should not produce [`Metadata`]
+    /// that share the same callsite [`Identifier`] but otherwise differ in any
+    /// way (e.g., have different `name`s).
+    ///
+    ///
+ /// /// [metadata]: super::metadata::Metadata fn metadata(&self) -> &Metadata<'_>; diff --git a/tracing-core/src/field.rs b/tracing-core/src/field.rs index c9869ce2ca..e103c75a9d 100644 --- a/tracing-core/src/field.rs +++ b/tracing-core/src/field.rs @@ -145,6 +145,16 @@ pub struct Field { pub struct Empty; /// Describes the fields present on a span. +/// +/// ## Equality +/// +/// In well-behaved applications, two `FieldSet`s [initialized] with equal +/// [callsite identifiers] will have identical fields. Consequently, in release +/// builds, [`FieldSet::eq`] *only* checks that its arguments have equal +/// callsites. However, the equality of field names is checked in debug builds. +/// +/// [initialized]: Self::new +/// [callsite identifiers]: callsite::Identifier pub struct FieldSet { /// The names of each field on the described span. names: &'static [&'static str], @@ -911,6 +921,40 @@ impl fmt::Display for FieldSet { } } +impl Eq for FieldSet {} + +impl PartialEq for FieldSet { + fn eq(&self, other: &Self) -> bool { + if core::ptr::eq(&self, &other) { + true + } else if cfg!(not(debug_assertions)) { + // In a well-behaving application, two `FieldSet`s can be assumed to + // be totally equal so long as they share the same callsite. + self.callsite == other.callsite + } else { + // However, when debug-assertions are enabled, do NOT assume that + // the application is well-behaving; check every the field names of + // each `FieldSet` for equality. + + // `FieldSet` is destructured here to ensure a compile-error if the + // fields of `FieldSet` change. + let Self { + names: lhs_names, + callsite: lhs_callsite, + } = self; + + let Self { + names: rhs_names, + callsite: rhs_callsite, + } = &other; + + // Check callsite equality first, as it is probably cheaper to do + // than str equality. + lhs_callsite == rhs_callsite && lhs_names == rhs_names + } + } +} + // ===== impl Iter ===== impl Iterator for Iter { diff --git a/tracing-core/src/metadata.rs b/tracing-core/src/metadata.rs index 47b9388a41..a154419a74 100644 --- a/tracing-core/src/metadata.rs +++ b/tracing-core/src/metadata.rs @@ -35,28 +35,25 @@ use crate::stdlib::{ /// _significantly_ lower than that of creating the actual span. Therefore, /// filtering is based on metadata, rather than on the constructed span. /// -/// 
-///     Note: Although instances of Metadata
-///     cannot be compared directly, they provide a method
-///     id, returning
-///     an opaque callsite
-///     identifierwhich uniquely identifies the callsite where the metadata
-///     originated. This can be used to determine if two Metadata
-///     correspond to the same callsite.
-///
+/// ## Equality +/// +/// In well-behaved applications, two `Metadata` with equal +/// [callsite identifiers] will be equal in all other ways (i.e., have the same +/// `name`, `target`, etc.). Consequently, in release builds, [`Metadata::eq`] +/// *only* checks that its arguments have equal callsites. However, the equality +/// of `Metadata`'s other fields is checked in debug builds. /// /// [span]: super::span /// [event]: super::event -/// [name]: Metadata::name() -/// [target]: Metadata::target() -/// [fields]: Metadata::fields() -/// [verbosity level]: Metadata::level() -/// [file name]: Metadata::file() -/// [line number]: Metadata::line() -/// [module path]: Metadata::module_path() +/// [name]: Self::name +/// [target]: Self::target +/// [fields]: Self::fields +/// [verbosity level]: Self::level +/// [file name]: Self::file +/// [line number]: Self::line +/// [module path]: Self::module_path /// [`Subscriber`]: super::subscriber::Subscriber -/// [`id`]: Metadata::id -/// [callsite identifier]: super::callsite::Identifier +/// [callsite identifiers]: Self::callsite pub struct Metadata<'a> { /// The name of the span described by this metadata. name: &'static str, @@ -443,6 +440,62 @@ impl fmt::Debug for Kind { } } +impl<'a> Eq for Metadata<'a> {} + +impl<'a> PartialEq for Metadata<'a> { + #[inline] + fn eq(&self, other: &Self) -> bool { + if core::ptr::eq(&self, &other) { + true + } else if cfg!(not(debug_assertions)) { + // In a well-behaving application, two `Metadata` can be assumed to + // be totally equal so long as they share the same callsite. + self.callsite() == other.callsite() + } else { + // However, when debug-assertions are enabled, do not assume that + // the application is well-behaving; check every field of `Metadata` + // for equality. + + // `Metadata` is destructured here to ensure a compile-error if the + // fields of `Metadata` change. + let Metadata { + name: lhs_name, + target: lhs_target, + level: lhs_level, + module_path: lhs_module_path, + file: lhs_file, + line: lhs_line, + fields: lhs_fields, + kind: lhs_kind, + } = self; + + let Metadata { + name: rhs_name, + target: rhs_target, + level: rhs_level, + module_path: rhs_module_path, + file: rhs_file, + line: rhs_line, + fields: rhs_fields, + kind: rhs_kind, + } = &other; + + // The initial comparison of callsites is purely an optimization; + // it can be removed without affecting the overall semantics of the + // expression. + self.callsite() == other.callsite() + && lhs_name == rhs_name + && lhs_target == rhs_target + && lhs_level == rhs_level + && lhs_module_path == rhs_module_path + && lhs_file == rhs_file + && lhs_line == rhs_line + && lhs_fields == rhs_fields + && lhs_kind == rhs_kind + } + } +} + // ===== impl Level ===== impl Level {