From 2fc09f47caddd880b5935a68ce3d40cdb545d1c5 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Fri, 16 Jun 2023 08:24:06 -0700 Subject: [PATCH 1/7] chore: silence `clippy::redundant_clone` warning (#2619) The purpose of this test is to assert two clones of the same span are equal to each other, so the clone is kind of the whole point of the test. This commit adds an allow attribute to make clippy shut up about it. --- tracing/tests/span.rs | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/tracing/tests/span.rs b/tracing/tests/span.rs index ad71b17a8c..14c4417cb6 100644 --- a/tracing/tests/span.rs +++ b/tracing/tests/span.rs @@ -21,7 +21,12 @@ fn handles_to_the_same_span_are_equal() { // expect to see any spans. with_default(collector::mock().run(), || { let foo1 = tracing::span!(Level::TRACE, "foo"); + + // The purpose of this test is to assert that two clones of the same + // span are equal, so the clone here is kind of the whole point :) + #[allow(clippy::redundant_clone)] let foo2 = foo1.clone(); + // Two handles that point to the same span are equal. assert_eq!(foo1, foo2); }); From c14525e1610db88986f849d46bd3e9795878b012 Mon Sep 17 00:00:00 2001 From: Guillaume Desmottes Date: Fri, 16 Jun 2023 17:43:59 +0200 Subject: [PATCH 2/7] core: fix typo in `field` docs (#2611) ## Motivation Module `tracing::field` documentation is missing a word. ## Solution Fixing the typo by adding `event`. --- tracing-core/src/field.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tracing-core/src/field.rs b/tracing-core/src/field.rs index 768107b042..21ac163eee 100644 --- a/tracing-core/src/field.rs +++ b/tracing-core/src/field.rs @@ -7,7 +7,7 @@ //! # `Value`s and `Collect`s //! //! Collectors consume `Value`s as fields attached to [span]s or [`Event`]s. -//! The set of field keys on a given span or is defined on its [`Metadata`]. +//! The set of field keys on a given span or event is defined on its [`Metadata`]. //! When a span is created, it provides [`Attributes`] to the collector's //! [`new_span`] method, containing any fields whose values were provided when //! the span was created; and may call the collector's [`record`] method From ebd437cf1a1f4bb3f916cde7d798776b89e319cb Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?David=20Ml=C3=A1dek?= Date: Tue, 20 Jun 2023 16:36:12 +0200 Subject: [PATCH 3/7] attributes: allow `unknown_lints` in generated code (#2626) ## Motivation #2609 added an allow to generated code to allow a lint that was added in Clippy 1.70.0. This was released with a patch bump so anyone who uses an older version and latest tracing gets a compilation warning about an unkonwn lint. ## Solution Allowing unkonwn lints should fix this now and prevent similar issues in the future. If the lints are unknown it will most likely be because the lints are introduced only in newer compiler. There is just a higher risk that a future contributor tries to add another allow and if they make a typo, the issue will not be caught. --- tracing-attributes/src/expand.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tracing-attributes/src/expand.rs b/tracing-attributes/src/expand.rs index 50d6648d6b..bedff8e833 100644 --- a/tracing-attributes/src/expand.rs +++ b/tracing-attributes/src/expand.rs @@ -65,8 +65,8 @@ pub(crate) fn gen_function<'a, B: ToTokens + 'a>( // exactly that way for it to do its magic. let fake_return_edge = quote_spanned! {return_span=> #[allow( - unreachable_code, clippy::diverging_sub_expression, clippy::let_unit_value, - clippy::unreachable, clippy::let_with_type_underscore + unknown_lints, unreachable_code, clippy::diverging_sub_expression, + clippy::let_unit_value, clippy::unreachable, clippy::let_with_type_underscore )] if false { let __tracing_attr_fake_return: #return_type = From 2906278ba7afde87067a5af7c4eab51ebc410619 Mon Sep 17 00:00:00 2001 From: James Munns Date: Tue, 7 Jun 2022 22:12:06 +0200 Subject: [PATCH 4/7] core: add `ValueSet::len` and `Record::len` (#2152) ## Motivation This PR adds two new accessor functions that are useful for creating a structured serde implementation for tracing. This is a sort of "distilled" version of https://github.com/tokio-rs/tracing/pull/2113, based on the `v0.1.x` branch. As it is unlikely that "structured serde" will be 1:1 compatible with the existing JSON-based `tracing-serde` (or at least - I'm not sure how to do it in a reasonable amount of effort), these functions will allow me to make a separate crate to hold me over until breaking formatting changes are possible in `tracing-serde`. CC @hawkw, as we've discussed this pretty extensively --- tracing-core/src/field.rs | 15 ++++++++++++++- tracing-core/src/span.rs | 8 ++++++++ 2 files changed, 22 insertions(+), 1 deletion(-) diff --git a/tracing-core/src/field.rs b/tracing-core/src/field.rs index 21ac163eee..8bfcab6f20 100644 --- a/tracing-core/src/field.rs +++ b/tracing-core/src/field.rs @@ -880,6 +880,19 @@ impl<'a> ValueSet<'a> { } } + /// Returns the number of fields in this `ValueSet` that would be visited + /// by a given [visitor] to the [`ValueSet::record()`] method. + /// + /// [visitor]: Visit + /// [`ValueSet::record()`]: ValueSet::record() + pub fn len(&self) -> usize { + let my_callsite = self.callsite(); + self.values + .iter() + .filter(|(field, _)| field.callsite() == my_callsite) + .count() + } + /// Returns `true` if this `ValueSet` contains a value for the given `Field`. pub(crate) fn contains(&self, field: &Field) -> bool { field.callsite() == self.callsite() @@ -890,7 +903,7 @@ impl<'a> ValueSet<'a> { } /// Returns true if this `ValueSet` contains _no_ values. - pub(crate) fn is_empty(&self) -> bool { + pub fn is_empty(&self) -> bool { let my_callsite = self.callsite(); self.values .iter() diff --git a/tracing-core/src/span.rs b/tracing-core/src/span.rs index 1113eabe39..49c1cb95d5 100644 --- a/tracing-core/src/span.rs +++ b/tracing-core/src/span.rs @@ -226,6 +226,14 @@ impl<'a> Record<'a> { self.values.record(visitor) } + /// Returns the number of fields that would be visited from this `Record` + /// when [`Record::record()`] is called + /// + /// [`Record::record()`]: Record::record() + pub fn len(&self) -> usize { + self.values.len() + } + /// Returns `true` if this `Record` contains a value for the given `Field`. pub fn contains(&self, field: &field::Field) -> bool { self.values.contains(field) From 9ad27405f82ca7414a9b742493c00e6782e548df Mon Sep 17 00:00:00 2001 From: Hayden Stainsby Date: Sat, 24 Jun 2023 04:09:29 +0200 Subject: [PATCH 5/7] mock: document public API in collector module (#2389) There has been interest around publishing `tracing-mock` to crates.io for some time. In order to make this possible, documentation and some code clean up is needed. This change adds documentation to the collector module itself and to all the public APIs in the module. This includes doctests on all the methods that serve as examples. Additionally the implementation for the `Expect` struct has been moved into the module with the definition, this was missed in #2369. Refs: #539 --- tracing-mock/src/collector.rs | 915 +++++++++++++++++++++++++++++++--- tracing-mock/src/expect.rs | 50 ++ 2 files changed, 893 insertions(+), 72 deletions(-) diff --git a/tracing-mock/src/collector.rs b/tracing-mock/src/collector.rs index 530766fd6c..3298bfb22f 100644 --- a/tracing-mock/src/collector.rs +++ b/tracing-mock/src/collector.rs @@ -1,4 +1,142 @@ -#![allow(missing_docs)] +//! An implementation of the [`Collect`] trait to receive and validate +//! `tracing` data. +//! +//! The [`MockCollector`] is the central component of this crate. The +//! `MockCollector` has expectations set on it which are later +//! validated as the code under test is run. +//! +//! # Examples +//! +//! ``` +//! use tracing_mock::{collector, expect, field}; +//! +//! let (collector, handle) = collector::mock() +//! // Expect a single event with a specified message +//! .event(expect::event().with_fields(field::msg("droids"))) +//! .only() +//! .run_with_handle(); +//! +//! // Use `with_default` to apply the `MockCollector` for the duration +//! // of the closure - this is what we are testing. +//! tracing::collect::with_default(collector, || { +//! // These *are* the droids we are looking for +//! tracing::info!("droids"); +//! }); +//! +//! // Use the handle to check the assertions. This line will panic if an +//! // assertion is not met. +//! handle.assert_finished(); +//! ``` +//! +//! A more complex example may consider multiple spans and events with +//! their respective fields: +//! +//! ``` +//! use tracing_mock::{collector, expect, field}; +//! +//! let span = expect::span() +//! .named("my_span"); +//! let (collector, handle) = collector::mock() +//! // Enter a matching span +//! .enter(span.clone()) +//! // Record an event with message "collect parting message" +//! .event(expect::event().with_fields(field::msg("collect parting message"))) +//! // Record a value for the field `parting` on a matching span +//! .record(span.clone(), expect::field("parting").with_value(&"goodbye world!")) +//! // Exit a matching span +//! .exit(span) +//! // Expect no further messages to be recorded +//! .only() +//! // Return the collector and handle +//! .run_with_handle(); +//! +//! // Use `with_default` to apply the `MockCollector` for the duration +//! // of the closure - this is what we are testing. +//! tracing::collect::with_default(collector, || { +//! let span = tracing::trace_span!( +//! "my_span", +//! greeting = "hello world", +//! parting = tracing::field::Empty +//! ); +//! +//! let _guard = span.enter(); +//! tracing::info!("collect parting message"); +//! let parting = "goodbye world!"; +//! +//! span.record("parting", &parting); +//! }); +//! +//! // Use the handle to check the assertions. This line will panic if an +//! // assertion is not met. +//! handle.assert_finished(); +//! ``` +//! +//! If we modify the previous example so that we **don't** enter the +//! span before recording an event, the test will fail: +//! +//! ```should_panic +//! use tracing_mock::{collector, expect, field}; +//! +//! let span = expect::span() +//! .named("my_span"); +//! let (collector, handle) = collector::mock() +//! .enter(span.clone()) +//! .event(expect::event().with_fields(field::msg("collect parting message"))) +//! .record(span.clone(), expect::field("parting").with_value(&"goodbye world!")) +//! .exit(span) +//! .only() +//! .run_with_handle(); +//! +//! // Use `with_default` to apply the `MockCollector` for the duration +//! // of the closure - this is what we are testing. +//! tracing::collect::with_default(collector, || { +//! let span = tracing::trace_span!( +//! "my_span", +//! greeting = "hello world", +//! parting = tracing::field::Empty +//! ); +//! +//! // Don't enter the span. +//! // let _guard = span.enter(); +//! tracing::info!("collect parting message"); +//! let parting = "goodbye world!"; +//! +//! span.record("parting", &parting); +//! }); +//! +//! // Use the handle to check the assertions. This line will panic if an +//! // assertion is not met. +//! handle.assert_finished(); +//! ``` +//! +//! This will result in an error message such as the following: +//! +//! ```text +//! thread 'main' panicked at ' +//! [main] expected to enter a span named `my_span` +//! [main] but instead observed event Event { +//! fields: ValueSet { +//! message: collect parting message, +//! callsite: Identifier(0x10eda3278), +//! }, +//! metadata: Metadata { +//! name: "event src/collector.rs:27", +//! target: "rust_out", +//! level: Level( +//! Info, +//! ), +//! module_path: "rust_out", +//! location: src/collector.rs:27, +//! fields: {message}, +//! callsite: Identifier(0x10eda3278), +//! kind: Kind(EVENT), +//! }, +//! parent: Current, +//! }', tracing/tracing-mock/src/expect.rs:59:33 +//! ``` +//! +//! [`Collect`]: trait@tracing::Collect +//! [`MockCollector`]: struct@crate::collector::MockCollector use crate::{ event::ExpectedEvent, expect::Expect, @@ -7,7 +145,6 @@ use crate::{ }; use std::{ collections::{HashMap, VecDeque}, - fmt, sync::{ atomic::{AtomicUsize, Ordering}, Arc, Mutex, @@ -37,6 +174,12 @@ struct Running) -> bool> { name: String, } +/// A collector which can validate received traces. +/// +/// For a detailed description and examples see the documentation +/// for the methods and the [`collector`] module. +/// +/// [`collector`]: mod@crate::collector pub struct MockCollector) -> bool> { expected: VecDeque, max_level: Option, @@ -44,8 +187,67 @@ pub struct MockCollector) -> bool> { name: String, } +/// A handle which is used to invoke validation of expectations. +/// +/// The handle is currently only used to assert that all the expected +/// events and spans were seen. +/// +/// For additional information and examples, see the [`collector`] +/// module documentation. +/// +/// [`collector`]: mod@crate::collector pub struct MockHandle(Arc>>, String); +/// Create a new [`MockCollector`]. +/// +/// For additional information and examples, see the [`collector`] +/// module and [`MockCollector`] documentation. +/// +/// # Examples +/// +/// +/// ``` +/// use tracing_mock::{collector, expect, field}; +/// +/// let span = expect::span() +/// .named("my_span"); +/// let (collector, handle) = collector::mock() +/// // Enter a matching span +/// .enter(span.clone()) +/// // Record an event with message "collect parting message" +/// .event(expect::event().with_fields(field::msg("collect parting message"))) +/// // Record a value for the field `parting` on a matching span +/// .record(span.clone(), expect::field("parting").with_value(&"goodbye world!")) +/// // Exit a matching span +/// .exit(span) +/// // Expect no further messages to be recorded +/// .only() +/// // Return the collector and handle +/// .run_with_handle(); +/// +/// // Use `with_default` to apply the `MockCollector` for the duration +/// // of the closure - this is what we are testing. +/// tracing::collect::with_default(collector, || { +/// let span = tracing::trace_span!( +/// "my_span", +/// greeting = "hello world", +/// parting = tracing::field::Empty +/// ); +/// +/// let _guard = span.enter(); +/// tracing::info!("collect parting message"); +/// let parting = "goodbye world!"; +/// +/// span.record("parting", &parting); +/// }); +/// +/// // Use the handle to check the assertions. This line will panic if an +/// // assertion is not met. +/// handle.assert_finished(); +/// ``` +/// +/// [`collector`]: mod@crate::collector +#[must_use] pub fn mock() -> MockCollector) -> bool> { MockCollector { expected: VecDeque::new(), @@ -67,14 +269,56 @@ where /// The debugging output is displayed if the test panics, or if the test is /// run with `--nocapture`. /// - /// By default, the mock subscriber's name is the name of the test + /// By default, the mock collector's name is the name of the test /// (*technically*, the name of the thread where it was created, which is /// the name of the test unless tests are run with `--test-threads=1`). - /// When a test has only one mock subscriber, this is sufficient. However, - /// some tests may include multiple subscribers, in order to test - /// interactions between multiple subscribers. In that case, it can be - /// helpful to give each subscriber a separate name to distinguish where the + /// When a test has only one mock collector, this is sufficient. However, + /// some tests may include multiple collectors, in order to test + /// interactions between multiple collectors. In that case, it can be + /// helpful to give each collector a separate name to distinguish where the /// debugging output comes from. + /// + /// # Examples + /// + /// In the following example, we create 2 collectors, both + /// expecting to receive an event. As we only record a single + /// event, the test will fail: + /// + /// ```should_panic + /// use tracing_mock::{collector, expect}; + /// + /// let (collector_1, handle_1) = collector::mock() + /// .named("collector-1") + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// let (collector_2, handle_2) = collector::mock() + /// .named("collector-2") + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// let _guard = tracing::collect::set_default(collector_2); + /// + /// tracing::collect::with_default(collector_1, || { + /// tracing::info!("a"); + /// }); + /// + /// handle_1.assert_finished(); + /// handle_2.assert_finished(); + /// ``` + /// + /// In the test output, we see that the collector which didn't + /// received the event was the one named `collector-2`, which is + /// correct as the collector named `collector-1` was the default + /// when the event was recorded: + /// + /// ```text + /// [collector-2] more notifications expected: [ + /// Event( + /// MockEvent, + /// ), + /// ]', tracing-mock/src/collector.rs:1276:13 + /// ``` pub fn named(self, name: impl ToString) -> Self { Self { name: name.to_string(), @@ -82,43 +326,443 @@ where } } - pub fn enter(mut self, span: ExpectedSpan) -> Self { - self.expected.push_back(Expect::Enter(span)); + /// Adds an expectation that an event matching the [`ExpectedEvent`] + /// will be recorded next. + /// + /// The `event` can be a default mock which will match any event + /// (`expect::event()`) or can include additional expectations. + /// See the [`ExpectedEvent`] documentation for more details. + /// + /// If an event is recorded that doesn't match the `ExpectedEvent`, + /// or if something else (such as entering a span) is recorded + /// first, then the expectation will fail. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// tracing::info!("a"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// A span is entered before the event, causing the test to fail: + /// + /// ```should_panic + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// let span = tracing::info_span!("span"); + /// let _guard = span.enter(); + /// tracing::info!("a"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + pub fn event(mut self, event: ExpectedEvent) -> Self { + self.expected.push_back(Expect::Event(event)); self } - pub fn follows_from(mut self, consequence: ExpectedSpan, cause: ExpectedSpan) -> Self { - self.expected - .push_back(Expect::FollowsFrom { consequence, cause }); + /// Adds an expectation that the creation of a span will be + /// recorded next. + /// + /// This function accepts `Into` instead of + /// [`ExpectedSpan`] directly, so it can be used to test + /// span fields and the span parent. This is because a + /// collector only receives the span fields and parent when + /// a span is created, not when it is entered. + /// + /// The new span doesn't need to be entered for this expectation + /// to succeed. + /// + /// If a span is recorded that doesn't match the `ExpectedSpan`, + /// or if something else (such as an event) is recorded first, + /// then the expectation will fail. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{collector, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing") + /// .with_field(expect::field("testing").with_value(&"yes")); + /// let (collector, handle) = collector::mock() + /// .new_span(span) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// _ = tracing::info_span!("the span we're testing", testing = "yes"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// An event is recorded before the span is created, causing the + /// test to fail: + /// + /// ```should_panic + /// use tracing_mock::{collector, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing") + /// .with_field(expect::field("testing").with_value(&"yes")); + /// let (collector, handle) = collector::mock() + /// .new_span(span) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// tracing::info!("an event"); + /// _ = tracing::info_span!("the span we're testing", testing = "yes"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + pub fn new_span(mut self, new_span: I) -> Self + where + I: Into, + { + self.expected.push_back(Expect::NewSpan(new_span.into())); self } - pub fn event(mut self, event: ExpectedEvent) -> Self { - self.expected.push_back(Expect::Event(event)); + /// Adds an expectation that entering a span matching the + /// [`ExpectedSpan`] will be recorded next. + /// + /// This expectation is generally accompanied by a call to + /// [`exit`] as well. If used together with [`only`], this + /// is necessary. + /// + /// If the span that is entered doesn't match the [`ExpectedSpan`], + /// or if something else (such as an event) is recorded first, + /// then the expectation will fail. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{collector, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing"); + /// let (collector, handle) = collector::mock() + /// .enter(span.clone()) + /// .exit(span) + /// .only() + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// let span = tracing::info_span!("the span we're testing"); + /// let _entered = span.enter(); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// An event is recorded before the span is entered, causing the + /// test to fail: + /// + /// ```should_panic + /// use tracing_mock::{collector, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing"); + /// let (collector, handle) = collector::mock() + /// .enter(span.clone()) + /// .exit(span) + /// .only() + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// tracing::info!("an event"); + /// let span = tracing::info_span!("the span we're testing"); + /// let _entered = span.enter(); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// [`exit`]: fn@Self::exit + /// [`only`]: fn@Self::only + pub fn enter(mut self, span: ExpectedSpan) -> Self { + self.expected.push_back(Expect::Enter(span)); self } + /// Adds ab expectation that exiting a span matching the + /// [`ExpectedSpan`] will be recorded next. + /// + /// As a span may be entered and exited multiple times, + /// this is different from the span being closed. In + /// general [`enter`] and `exit` should be paired. + /// + /// If the span that is exited doesn't match the [`ExpectedSpan`], + /// or if something else (such as an event) is recorded first, + /// then the expectation will fail. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{collector, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing"); + /// let (collector, handle) = collector::mock() + /// .enter(span.clone()) + /// .exit(span) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// let span = tracing::info_span!("the span we're testing"); + /// let _entered = span.enter(); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// An event is recorded before the span is exited, causing the + /// test to fail: + /// + /// ```should_panic + /// use tracing_mock::{collector, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing"); + /// let (collector, handle) = collector::mock() + /// .enter(span.clone()) + /// .exit(span) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// let span = tracing::info_span!("the span we're testing"); + /// let _entered = span.enter(); + /// tracing::info!("an event"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// [`enter`]: fn@Self::enter pub fn exit(mut self, span: ExpectedSpan) -> Self { self.expected.push_back(Expect::Exit(span)); self } + /// Adds an expectation that cloning a span matching the + /// [`ExpectedSpan`] will be recorded next. + /// + /// The cloned span does need to be entered. + /// + /// If the span that is cloned doesn't match the [`ExpectedSpan`], + /// or if something else (such as an event) is recorded first, + /// then the expectation will fail. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{collector, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing"); + /// let (collector, handle) = collector::mock() + /// .clone_span(span) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// let span = tracing::info_span!("the span we're testing"); + /// _ = span.clone(); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// An event is recorded before the span is cloned, causing the + /// test to fail: + /// + /// ```should_panic + /// use tracing_mock::{collector, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing"); + /// let (collector, handle) = collector::mock() + /// .clone_span(span) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// let span = tracing::info_span!("the span we're testing"); + /// tracing::info!("an event"); + /// _ = span.clone(); + /// }); + /// + /// handle.assert_finished(); + /// ``` pub fn clone_span(mut self, span: ExpectedSpan) -> Self { self.expected.push_back(Expect::CloneSpan(span)); self } + /// **This method is deprecated.** + /// + /// Adds an expectation that a span matching the [`ExpectedSpan`] + /// getting dropped via the deprecated function + /// [`Collect::drop_span`] will be recorded next. + /// + /// Instead [`Collect::try_close`] should be used on the collector + /// and should be asserted with `close_span` (which hasn't been + /// implemented yet, but will be done as part of #539). + /// + /// [`Collect::drop_span`]: fn@tracing::Collect::drop_span #[allow(deprecated)] pub fn drop_span(mut self, span: ExpectedSpan) -> Self { self.expected.push_back(Expect::DropSpan(span)); self } - pub fn only(mut self) -> Self { - self.expected.push_back(Expect::Nothing); + /// Adds an expectation that a `follows_from` relationship will be + /// recorded next. Specifically that a span matching `consequence` + /// follows from a span matching `cause`. + /// + /// For further details on what this causal relationship means, see + /// [`Span::follows_from`]. + /// + /// If either of the 2 spans don't match their respective + /// [`ExpectedSpan`] or if something else (such as an event) is + /// recorded first, then the expectation will fail. + /// + /// **Note**: The 2 spans, `consequence` and `cause` are matched + /// by `name` only. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{collector, expect}; + /// + /// let cause = expect::span().named("cause"); + /// let consequence = expect::span().named("consequence"); + /// + /// let (collector, handle) = collector::mock() + /// .follows_from(consequence, cause) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// let cause = tracing::info_span!("cause"); + /// let consequence = tracing::info_span!("consequence"); + /// + /// consequence.follows_from(&cause); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// The `cause` span doesn't match, it is actually recorded at + /// `Level::WARN` instead of the expected `Level::INFO`, causing + /// this test to fail: + /// + /// ```should_panic + /// use tracing_mock::{collector, expect}; + /// + /// let cause = expect::span().named("cause"); + /// let consequence = expect::span().named("consequence"); + /// + /// let (collector, handle) = collector::mock() + /// .follows_from(consequence, cause) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// let cause = tracing::info_span!("another cause"); + /// let consequence = tracing::info_span!("consequence"); + /// + /// consequence.follows_from(&cause); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// [`Span::follows_from`]: fn@tracing::Span::follows_from + pub fn follows_from(mut self, consequence: ExpectedSpan, cause: ExpectedSpan) -> Self { + self.expected + .push_back(Expect::FollowsFrom { consequence, cause }); self } + /// Adds an expectation that `fields` are recorded on a span + /// matching the [`ExpectedSpan`] will be recorded next. + /// + /// For further information on how to specify the expected + /// fields, see the documentation on the [`field`] module. + /// + /// If either the span doesn't match the [`ExpectedSpan`], the + /// fields don't match the expected fields, or if something else + /// (such as an event) is recorded first, then the expectation + /// will fail. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{collector, expect}; + /// + /// let span = expect::span() + /// .named("my_span"); + /// let (collector, handle) = collector::mock() + /// .record(span, expect::field("parting").with_value(&"goodbye world!")) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// let span = tracing::trace_span!( + /// "my_span", + /// greeting = "hello world", + /// parting = tracing::field::Empty + /// ); + /// span.record("parting", "goodbye world!"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// The value of the recorded field doesn't match the expectation, + /// causing the test to fail: + /// + /// ```should_panic + /// use tracing_mock::{collector, expect}; + /// + /// let span = expect::span() + /// .named("my_span"); + /// let (collector, handle) = collector::mock() + /// .record(span, expect::field("parting").with_value(&"goodbye world!")) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// let span = tracing::trace_span!( + /// "my_span", + /// greeting = "hello world", + /// parting = tracing::field::Empty + /// ); + /// span.record("parting", "goodbye universe!"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// [`field`]: mod@crate::field pub fn record(mut self, span: ExpectedSpan, fields: I) -> Self where I: Into, @@ -127,14 +771,31 @@ where self } - pub fn new_span(mut self, new_span: I) -> Self - where - I: Into, - { - self.expected.push_back(Expect::NewSpan(new_span.into())); - self - } - + /// Filter the traces evaluated by the `MockCollector`. + /// + /// The filter will be applied to all traces received before + /// any validation occurs - so its position in the call chain + /// is not important. The filter does not perform any validation + /// itself. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .with_filter(|meta| meta.level() <= &tracing::Level::WARN) + /// .event(expect::event()) + /// .only() + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// tracing::info!("a"); + /// tracing::warn!("b"); + /// }); + /// + /// handle.assert_finished(); + /// ``` pub fn with_filter(self, filter: G) -> MockCollector where G: Fn(&Metadata<'_>) -> bool + 'static, @@ -147,6 +808,39 @@ where } } + /// Sets the max level that will be provided to the `tracing` + /// system. + /// + /// This method can be used to test the internals of `tracing`, + /// but it is also useful to filter out traces on more verbose + /// levels if you only want to verify above a certain level. + /// + /// **Note**: this value determines a global filter, if + /// `with_max_level_hint` is called on multiple collectors, the + /// global filter will be the least restrictive of all collectors. + /// To filter the events evaluated by a specific `MockCollector`, + /// use [`with_filter`] instead. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .with_max_level_hint(tracing::Level::INFO) + /// .event(expect::event().at_level(tracing::Level::INFO)) + /// .only() + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// tracing::debug!("a message we don't care about"); + /// tracing::info!("a message we want to validate"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// [`with_filter`]: fn@Self::with_filter pub fn with_max_level_hint(self, hint: impl Into) -> Self { Self { max_level: Some(hint.into()), @@ -154,11 +848,108 @@ where } } + /// Expects that no further traces are received. + /// + /// The call to `only` should appear immediately before the final + /// call to `run` or `run_with_handle`, as any expectations which + /// are added after `only` will not be considered. + /// + /// # Examples + /// + /// Consider this simple test. It passes even though we only + /// expect a single event, but receive three: + /// + /// ``` + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// tracing::info!("a"); + /// tracing::info!("b"); + /// tracing::info!("c"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// After including `only`, the test will fail: + /// + /// ```should_panic + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .event(expect::event()) + /// .only() + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// tracing::info!("a"); + /// tracing::info!("b"); + /// tracing::info!("c"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + pub fn only(mut self) -> Self { + self.expected.push_back(Expect::Nothing); + self + } + + /// Consume the receiver and return an `impl` [`Collect`] which can + /// be set as the default collector. + /// + /// This function is similar to [`run_with_handle`], but it doesn't + /// return a [`MockHandle`]. This is useful if the desired + /// assertions can be checked externally to the collector. + /// + /// # Examples + /// + /// The following test is used within the `tracing` + /// codebase: + /// + /// ``` + /// use tracing_mock::collector; + /// + /// tracing::collect::with_default(collector::mock().run(), || { + /// let foo1 = tracing::span!(tracing::Level::TRACE, "foo"); + /// let foo2 = foo1.clone(); + /// // Two handles that point to the same span are equal. + /// assert_eq!(foo1, foo2); + /// }); + /// ``` + /// + /// [`Collect`]: tracing::Collect + /// [`run_with_handle`]: fn@Self::run_with_handle pub fn run(self) -> impl Collect { let (collector, _) = self.run_with_handle(); collector } + /// Consume the receiver and return an `impl` [`Collect`] which can + /// be set as the default collector and a [`MockHandle`] which can + /// be used to validate the provided expectations. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{collector, expect}; + /// + /// // collector and handle are returned from `run_with_handle()` + /// let (collector, handle) = collector::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// tracing::info!("a"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// [`Collect`]: tracing::Collect pub fn run_with_handle(self) -> (impl Collect, MockHandle) { let expected = Arc::new(Mutex::new(self.expected)); let handle = MockHandle(expected.clone(), self.name.clone()); @@ -267,9 +1058,11 @@ where cause: ref expected_cause, }) => { if let Some(name) = expected_consequence.name() { + // TODO(hds): Write proper assertion text. assert_eq!(name, consequence_span.name); } if let Some(name) = expected_cause.name() { + // TODO(hds): Write proper assertion text. assert_eq!(name, cause_span.name); } } @@ -467,6 +1260,32 @@ impl MockHandle { Self(expected, name) } + /// Checks the expectations which were set on the + /// [`MockCollector`]. + /// + /// Calling `assert_finished` is usually the final part of a test. + /// + /// # Panics + /// + /// This method will panic if any of the provided expectations are + /// not met. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// tracing::collect::with_default(collector, || { + /// tracing::info!("a"); + /// }); + /// + /// // Check assertions set on the mock collector + /// handle.assert_finished(); + /// ``` pub fn assert_finished(&self) { if let Ok(ref expected) = self.0.lock() { assert!( @@ -478,51 +1297,3 @@ impl MockHandle { } } } - -impl Expect { - pub fn bad(&self, name: impl AsRef, what: fmt::Arguments<'_>) { - let name = name.as_ref(); - match self { - Expect::Event(e) => panic!( - "\n[{}] expected event {}\n[{}] but instead {}", - name, e, name, what, - ), - Expect::FollowsFrom { consequence, cause } => panic!( - "\n[{}] expected consequence {} to follow cause {} but instead {}", - name, consequence, cause, what, - ), - Expect::Enter(e) => panic!( - "\n[{}] expected to enter {}\n[{}] but instead {}", - name, e, name, what, - ), - Expect::Exit(e) => panic!( - "\n[{}] expected to exit {}\n[{}] but instead {}", - name, e, name, what, - ), - Expect::CloneSpan(e) => { - panic!( - "\n[{}] expected to clone {}\n[{}] but instead {}", - name, e, name, what, - ) - } - Expect::DropSpan(e) => { - panic!( - "\n[{}] expected to drop {}\n[{}] but instead {}", - name, e, name, what, - ) - } - Expect::Visit(e, fields) => panic!( - "\n[{}] expected {} to record {}\n[{}] but instead {}", - name, e, fields, name, what, - ), - Expect::NewSpan(e) => panic!( - "\n[{}] expected {}\n[{}] but instead {}", - name, e, name, what - ), - Expect::Nothing => panic!( - "\n[{}] expected nothing else to happen\n[{}] but {} instead", - name, name, what, - ), - } - } -} diff --git a/tracing-mock/src/expect.rs b/tracing-mock/src/expect.rs index a21f260e8d..044f134580 100644 --- a/tracing-mock/src/expect.rs +++ b/tracing-mock/src/expect.rs @@ -1,3 +1,5 @@ +use std::fmt; + use crate::{ event::ExpectedEvent, field::{ExpectedField, ExpectedFields, ExpectedValue}, @@ -41,3 +43,51 @@ pub fn span() -> ExpectedSpan { ..Default::default() } } + +impl Expect { + pub(crate) fn bad(&self, name: impl AsRef, what: fmt::Arguments<'_>) { + let name = name.as_ref(); + match self { + Expect::Event(e) => panic!( + "\n[{}] expected event {}\n[{}] but instead {}", + name, e, name, what, + ), + Expect::FollowsFrom { consequence, cause } => panic!( + "\n[{}] expected consequence {} to follow cause {} but instead {}", + name, consequence, cause, what, + ), + Expect::Enter(e) => panic!( + "\n[{}] expected to enter {}\n[{}] but instead {}", + name, e, name, what, + ), + Expect::Exit(e) => panic!( + "\n[{}] expected to exit {}\n[{}] but instead {}", + name, e, name, what, + ), + Expect::CloneSpan(e) => { + panic!( + "\n[{}] expected to clone {}\n[{}] but instead {}", + name, e, name, what, + ) + } + Expect::DropSpan(e) => { + panic!( + "\n[{}] expected to drop {}\n[{}] but instead {}", + name, e, name, what, + ) + } + Expect::Visit(e, fields) => panic!( + "\n[{}] expected {} to record {}\n[{}] but instead {}", + name, e, fields, name, what, + ), + Expect::NewSpan(e) => panic!( + "\n[{}] expected {}\n[{}] but instead {}", + name, e, name, what + ), + Expect::Nothing => panic!( + "\n[{}] expected nothing else to happen\n[{}] but {} instead", + name, name, what, + ), + } + } +} From c6e8a8f679f40d2528008918e2d636e0b48b8107 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Sat, 24 Jun 2023 10:13:17 -0700 Subject: [PATCH 6/7] tracing: fix recursive `register_callsite` deadlock (#2634) ## Motivation A deadlock exists when a collector's `register_callsite` method calls into code that also contains tracing instrumentation and triggers a second `register_callsite` call for the same callsite. This is because the current implementation of the `MacroCallsite` type holds a `core::sync::Once` which it uses to ensure that it is only added to the callsite registry a single time. This deadlock was fixed in v0.1.x in PR #2083, but the issue still exists on v0.2.x. ## Solution This branch forward-ports the solution from #2083. Rather than using a `core::sync::Once`, we now track the callsite's registration state directly in `MacroCallsite`. If a callsite has started registering, but has not yet completed, subsequent `register` calls will just immediately receive an `Interest::sometimes` until the registration has completed, rather than waiting to attempt their own registration. I've also forward-ported the tests for this that were added in #2083. --- tracing/src/lib.rs | 59 +++++++++++++++---- .../tests/rebuild_interest_doesnt_deadlock.rs | 51 ++++++++++++++++ .../register_callsite_doesnt_deadlock.rs | 49 +++++++++++++++ 3 files changed, 146 insertions(+), 13 deletions(-) create mode 100644 tracing/tests/rebuild_interest_doesnt_deadlock.rs create mode 100644 tracing/tests/register_callsite_doesnt_deadlock.rs diff --git a/tracing/src/lib.rs b/tracing/src/lib.rs index 916cf03cdf..1494048523 100644 --- a/tracing/src/lib.rs +++ b/tracing/src/lib.rs @@ -988,8 +988,7 @@ pub mod __macro_support { pub use crate::callsite::{Callsite, Registration}; use crate::{collect::Interest, Metadata}; use core::fmt; - use core::sync::atomic::{AtomicUsize, Ordering}; - use tracing_core::Once; + use core::sync::atomic::{AtomicU8, Ordering}; /// Callsite implementation used by macro-generated code. /// @@ -1003,9 +1002,9 @@ pub mod __macro_support { where T: 'static, { - interest: AtomicUsize, + interest: AtomicU8, + register: AtomicU8, meta: &'static Metadata<'static>, - register: Once, registration: &'static Registration, } @@ -1023,12 +1022,21 @@ pub mod __macro_support { registration: &'static Registration, ) -> Self { Self { - interest: AtomicUsize::new(0xDEADFACED), + interest: AtomicU8::new(Self::INTEREST_EMPTY), + register: AtomicU8::new(Self::UNREGISTERED), meta, - register: Once::new(), registration, } } + + const UNREGISTERED: u8 = 0; + const REGISTERING: u8 = 1; + const REGISTERED: u8 = 2; + + const INTEREST_NEVER: u8 = 0; + const INTEREST_SOMETIMES: u8 = 1; + const INTEREST_ALWAYS: u8 = 2; + const INTEREST_EMPTY: u8 = 0xFF; } impl MacroCallsite<&'static dyn Callsite> { @@ -1046,11 +1054,36 @@ pub mod __macro_support { // This only happens once (or if the cached interest value was corrupted). #[cold] pub fn register(&'static self) -> Interest { - self.register - .call_once(|| crate::callsite::register(self.registration)); + // Attempt to advance the registration state to `REGISTERING`... + match self.register.compare_exchange( + Self::UNREGISTERED, + Self::REGISTERING, + Ordering::AcqRel, + Ordering::Acquire, + ) { + Ok(_) => { + // Okay, we advanced the state, try to register the callsite. + crate::callsite::register(self.registration); + self.register.store(Self::REGISTERED, Ordering::Release); + } + // Great, the callsite is already registered! Just load its + // previous cached interest. + Err(Self::REGISTERED) => {} + // Someone else is registering... + Err(_state) => { + debug_assert_eq!( + _state, + Self::REGISTERING, + "weird callsite registration state" + ); + // Just hit `enabled` this time. + return Interest::sometimes(); + } + } + match self.interest.load(Ordering::Relaxed) { - 0 => Interest::never(), - 2 => Interest::always(), + Self::INTEREST_NEVER => Interest::never(), + Self::INTEREST_ALWAYS => Interest::always(), _ => Interest::sometimes(), } } @@ -1067,9 +1100,9 @@ pub mod __macro_support { #[inline] pub fn interest(&'static self) -> Interest { match self.interest.load(Ordering::Relaxed) { - 0 => Interest::never(), - 1 => Interest::sometimes(), - 2 => Interest::always(), + Self::INTEREST_NEVER => Interest::never(), + Self::INTEREST_SOMETIMES => Interest::sometimes(), + Self::INTEREST_ALWAYS => Interest::always(), _ => self.register(), } } diff --git a/tracing/tests/rebuild_interest_doesnt_deadlock.rs b/tracing/tests/rebuild_interest_doesnt_deadlock.rs new file mode 100644 index 0000000000..cd877cbafd --- /dev/null +++ b/tracing/tests/rebuild_interest_doesnt_deadlock.rs @@ -0,0 +1,51 @@ +use std::{sync::mpsc, thread, time::Duration}; +use tracing::{ + callsite, + collect::{self, Collect, Interest}, + metadata::Metadata, + span, Event, +}; + +#[test] +fn rebuild_callsites_doesnt_deadlock() { + pub struct EvilCollector; + + impl Collect for EvilCollector { + fn register_callsite(&self, meta: &'static Metadata<'static>) -> Interest { + tracing::info!(?meta, "registered a callsite"); + Interest::always() + } + + fn enabled(&self, _: &Metadata<'_>) -> bool { + true + } + fn new_span(&self, _: &span::Attributes<'_>) -> span::Id { + span::Id::from_u64(1) + } + fn record(&self, _: &span::Id, _: &span::Record<'_>) {} + fn record_follows_from(&self, _: &span::Id, _: &span::Id) {} + fn event(&self, _: &Event<'_>) {} + fn enter(&self, _: &span::Id) {} + fn exit(&self, _: &span::Id) {} + fn current_span(&self) -> tracing_core::span::Current { + unimplemented!() + } + } + + collect::set_global_default(EvilCollector).unwrap(); + + // spawn a thread, and assert it doesn't hang... + let (tx, didnt_hang) = mpsc::channel(); + let th = thread::spawn(move || { + tracing::info!("hello world!"); + callsite::rebuild_interest_cache(); + tx.send(()).unwrap(); + }); + + didnt_hang + // Note: 60 seconds is *way* more than enough, but let's be generous in + // case of e.g. slow CI machines. + .recv_timeout(Duration::from_secs(60)) + .expect("the thread must not have hung!"); + th.join().expect("thread should join successfully"); +} diff --git a/tracing/tests/register_callsite_doesnt_deadlock.rs b/tracing/tests/register_callsite_doesnt_deadlock.rs new file mode 100644 index 0000000000..32f3e686bc --- /dev/null +++ b/tracing/tests/register_callsite_doesnt_deadlock.rs @@ -0,0 +1,49 @@ +use std::{sync::mpsc, thread, time::Duration}; +use tracing::{ + collect::{self, Collect, Interest}, + metadata::Metadata, + span, Event, +}; + +#[test] +fn register_callsite_doesnt_deadlock() { + pub struct EvilCollector; + + impl Collect for EvilCollector { + fn register_callsite(&self, meta: &'static Metadata<'static>) -> Interest { + tracing::info!(?meta, "registered a callsite"); + Interest::always() + } + + fn enabled(&self, _: &Metadata<'_>) -> bool { + true + } + fn new_span(&self, _: &span::Attributes<'_>) -> span::Id { + span::Id::from_u64(1) + } + fn record(&self, _: &span::Id, _: &span::Record<'_>) {} + fn record_follows_from(&self, _: &span::Id, _: &span::Id) {} + fn event(&self, _: &Event<'_>) {} + fn enter(&self, _: &span::Id) {} + fn exit(&self, _: &span::Id) {} + fn current_span(&self) -> tracing_core::span::Current { + unimplemented!() + } + } + + collect::set_global_default(EvilCollector).unwrap(); + + // spawn a thread, and assert it doesn't hang... + let (tx, didnt_hang) = mpsc::channel(); + let th = thread::spawn(move || { + tracing::info!("hello world!"); + tx.send(()).unwrap(); + }); + + didnt_hang + // Note: 60 seconds is *way* more than enough, but let's be generous in + // case of e.g. slow CI machines. + .recv_timeout(Duration::from_secs(60)) + .expect("the thread must not have hung!"); + th.join().expect("thread should join successfully"); +} From 27f688efb72316a26f3ec1f952c82626692c08ff Mon Sep 17 00:00:00 2001 From: Harry Barber <106155934+hlbarber@users.noreply.github.com> Date: Tue, 11 Jul 2023 20:39:10 +0100 Subject: [PATCH 7/7] tracing: use fully qualified names in macros for items exported from std prelude (#2621) ## Motivation Currently, in many places, macros do not use fully qualified names for items exported from the prelude. This means that naming collisions (`struct Some`) or the removal of the std library prelude will cause compilation errors. ## Solution - Identify and use fully qualified names in macros were we previously assumed the Rust std prelude. We use `::core` rather than `::std`. - Add [`no_implicit_prelude`](https://doc.rust-lang.org/reference/names/preludes.html#the-no_implicit_prelude-attribute) to `tracing/tests/macros.rs`. I'm unsure if this is giving us good coverage - can we improve on this approach? I'm not confident I've caught everything. --- tracing-core/src/field.rs | 2 +- tracing-core/src/lib.rs | 6 +- tracing-log/src/lib.rs | 6 +- tracing-subscriber/src/fmt/fmt_subscriber.rs | 2 +- tracing-subscriber/src/macros.rs | 2 +- tracing-subscriber/src/subscribe/mod.rs | 2 +- tracing/src/macros.rs | 40 +-- tracing/tests/macros.rs | 320 ++++++++++--------- 8 files changed, 192 insertions(+), 188 deletions(-) diff --git a/tracing-core/src/field.rs b/tracing-core/src/field.rs index 8bfcab6f20..80ca065ba3 100644 --- a/tracing-core/src/field.rs +++ b/tracing-core/src/field.rs @@ -963,7 +963,7 @@ macro_rules! impl_valid_len { ( $( $len:tt ),+ ) => { $( impl<'a> private::ValidLen<'a> for - [(&'a Field, Option<&'a (dyn Value + 'a)>); $len] {} + [(&'a Field, ::core::option::Option<&'a (dyn Value + 'a)>); $len] {} )+ } } diff --git a/tracing-core/src/lib.rs b/tracing-core/src/lib.rs index e31978368d..d01b4a0c7a 100644 --- a/tracing-core/src/lib.rs +++ b/tracing-core/src/lib.rs @@ -263,9 +263,9 @@ macro_rules! metadata { $name, $target, $level, - Some(file!()), - Some(line!()), - Some(module_path!()), + ::core::option::Option::Some(file!()), + ::core::option::Option::Some(line!()), + ::core::option::Option::Some(module_path!()), $crate::field::FieldSet::new($fields, $crate::identify_callsite!($callsite)), $kind, ) diff --git a/tracing-log/src/lib.rs b/tracing-log/src/lib.rs index 916d0b6b7f..a822051baf 100644 --- a/tracing-log/src/lib.rs +++ b/tracing-log/src/lib.rs @@ -280,9 +280,9 @@ macro_rules! log_cs { "log event", "log", $level, - None, - None, - None, + ::core::option::Option::None, + ::core::option::Option::None, + ::core::option::Option::None, field::FieldSet::new(FIELD_NAMES, identify_callsite!(&$cs)), Kind::EVENT, ); diff --git a/tracing-subscriber/src/fmt/fmt_subscriber.rs b/tracing-subscriber/src/fmt/fmt_subscriber.rs index 1b89039261..366660fb82 100644 --- a/tracing-subscriber/src/fmt/fmt_subscriber.rs +++ b/tracing-subscriber/src/fmt/fmt_subscriber.rs @@ -778,7 +778,7 @@ macro_rules! with_event_from_span { #[allow(unused)] let mut iter = fs.iter(); let v = [$( - (&iter.next().unwrap(), Some(&$value as &dyn field::Value)), + (&iter.next().unwrap(), ::core::option::Option::Some(&$value as &dyn field::Value)), )*]; let vs = fs.value_set(&v); let $event = Event::new_child_of($id, meta, &vs); diff --git a/tracing-subscriber/src/macros.rs b/tracing-subscriber/src/macros.rs index 81351132f5..5b461d0a0a 100644 --- a/tracing-subscriber/src/macros.rs +++ b/tracing-subscriber/src/macros.rs @@ -4,7 +4,7 @@ macro_rules! try_lock { try_lock!($lock, else return) }; ($lock:expr, else $els:expr) => { - if let Ok(l) = $lock { + if let ::core::result::Result::Ok(l) = $lock { l } else if std::thread::panicking() { $els diff --git a/tracing-subscriber/src/subscribe/mod.rs b/tracing-subscriber/src/subscribe/mod.rs index a18d95fc5a..8601ca3287 100644 --- a/tracing-subscriber/src/subscribe/mod.rs +++ b/tracing-subscriber/src/subscribe/mod.rs @@ -1729,7 +1729,7 @@ macro_rules! subscriber_impl_body { #[doc(hidden)] #[inline] - unsafe fn downcast_raw(&self, id: TypeId) -> Option> { + unsafe fn downcast_raw(&self, id: TypeId) -> ::core::option::Option> { self.deref().downcast_raw(id) } }; diff --git a/tracing/src/macros.rs b/tracing/src/macros.rs index 138a80a40d..f47f9bbb2b 100644 --- a/tracing/src/macros.rs +++ b/tracing/src/macros.rs @@ -2196,79 +2196,79 @@ macro_rules! valueset { // }; (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = ?$val:expr, $($rest:tt)*) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&debug(&$val) as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&debug(&$val) as &dyn Value)) }, $next, $($rest)* ) }; (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = %$val:expr, $($rest:tt)*) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&display(&$val) as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&display(&$val) as &dyn Value)) }, $next, $($rest)* ) }; (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = $val:expr, $($rest:tt)*) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&$val as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&$val as &dyn Value)) }, $next, $($rest)* ) }; (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+, $($rest:tt)*) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&$($k).+ as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&$($k).+ as &dyn Value)) }, $next, $($rest)* ) }; (@ { $(,)* $($out:expr),* }, $next:expr, ?$($k:ident).+, $($rest:tt)*) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&debug(&$($k).+) as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&debug(&$($k).+) as &dyn Value)) }, $next, $($rest)* ) }; (@ { $(,)* $($out:expr),* }, $next:expr, %$($k:ident).+, $($rest:tt)*) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&display(&$($k).+) as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&display(&$($k).+) as &dyn Value)) }, $next, $($rest)* ) }; (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = ?$val:expr) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&debug(&$val) as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&debug(&$val) as &dyn Value)) }, $next, ) }; (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = %$val:expr) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&display(&$val) as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&display(&$val) as &dyn Value)) }, $next, ) }; (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = $val:expr) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&$val as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&$val as &dyn Value)) }, $next, ) }; (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&$($k).+ as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&$($k).+ as &dyn Value)) }, $next, ) }; (@ { $(,)* $($out:expr),* }, $next:expr, ?$($k:ident).+) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&debug(&$($k).+) as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&debug(&$($k).+) as &dyn Value)) }, $next, ) }; (@ { $(,)* $($out:expr),* }, $next:expr, %$($k:ident).+) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&display(&$($k).+) as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&display(&$($k).+) as &dyn Value)) }, $next, ) }; @@ -2276,47 +2276,47 @@ macro_rules! valueset { // Handle literal names (@ { $(,)* $($out:expr),* }, $next:expr, $k:literal = ?$val:expr, $($rest:tt)*) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&debug(&$val) as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&debug(&$val) as &dyn Value)) }, $next, $($rest)* ) }; (@ { $(,)* $($out:expr),* }, $next:expr, $k:literal = %$val:expr, $($rest:tt)*) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&display(&$val) as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&display(&$val) as &dyn Value)) }, $next, $($rest)* ) }; (@ { $(,)* $($out:expr),* }, $next:expr, $k:literal = $val:expr, $($rest:tt)*) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&$val as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&$val as &dyn Value)) }, $next, $($rest)* ) }; (@ { $(,)* $($out:expr),* }, $next:expr, $k:literal = ?$val:expr) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&debug(&$val) as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&debug(&$val) as &dyn Value)) }, $next, ) }; (@ { $(,)* $($out:expr),* }, $next:expr, $k:literal = %$val:expr) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&display(&$val) as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&display(&$val) as &dyn Value)) }, $next, ) }; (@ { $(,)* $($out:expr),* }, $next:expr, $k:literal = $val:expr) => { $crate::valueset!( - @ { $($out),*, (&$next, Some(&$val as &dyn Value)) }, + @ { $($out),*, (&$next, ::core::option::Option::Some(&$val as &dyn Value)) }, $next, ) }; // Remainder is unparsable, but exists --- must be format args! (@ { $(,)* $($out:expr),* }, $next:expr, $($rest:tt)+) => { - $crate::valueset!(@ { (&$next, Some(&format_args!($($rest)+) as &dyn Value)), $($out),* }, $next, ) + $crate::valueset!(@ { (&$next, ::core::option::Option::Some(&format_args!($($rest)+) as &dyn Value)), $($out),* }, $next, ) }; // === entry === @@ -2327,7 +2327,7 @@ macro_rules! valueset { let mut iter = $fields.iter(); $fields.value_set($crate::valueset!( @ { }, - iter.next().expect("FieldSet corrupted (this is a bug)"), + ::core::iter::Iterator::next(&mut iter).expect("FieldSet corrupted (this is a bug)"), $($kvs)+ )) } diff --git a/tracing/tests/macros.rs b/tracing/tests/macros.rs index a9679a3e94..423984da27 100644 --- a/tracing/tests/macros.rs +++ b/tracing/tests/macros.rs @@ -1,4 +1,8 @@ #![deny(warnings)] +// We call all macros in this module with `no_implicit_prelude` to ensure they do not depend on the standard prelude. +#![no_implicit_prelude] +extern crate tracing; + use tracing::{ callsite, debug, debug_span, enabled, error, error_span, event, event_enabled, info, info_span, span, span_enabled, trace, trace_span, warn, warn_span, Level, @@ -111,80 +115,80 @@ fn error_span() { #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] #[test] fn span_root() { - span!(target: "foo_events", parent: None, Level::TRACE, "foo", bar.baz = 2, quux = 3); - span!(target: "foo_events", parent: None, Level::TRACE, "foo", bar.baz = 2, quux = 3); - span!(target: "foo_events", parent: None, Level::TRACE, "foo", bar.baz = 2, quux = 4,); - span!(target: "foo_events", parent: None, Level::TRACE, "foo"); - span!(target: "foo_events", parent: None, Level::TRACE, "bar",); - span!(parent: None, Level::DEBUG, "foo", bar.baz = 2, quux = 3); - span!(parent: None, Level::DEBUG, "foo", bar.baz = 2, quux = 4,); - span!(parent: None, Level::DEBUG, "foo"); - span!(parent: None, Level::DEBUG, "bar",); + span!(target: "foo_events", parent: ::core::option::Option::None, Level::TRACE, "foo", bar.baz = 2, quux = 3); + span!(target: "foo_events", parent: ::core::option::Option::None, Level::TRACE, "foo", bar.baz = 2, quux = 3); + span!(target: "foo_events", parent: ::core::option::Option::None, Level::TRACE, "foo", bar.baz = 2, quux = 4,); + span!(target: "foo_events", parent: ::core::option::Option::None, Level::TRACE, "foo"); + span!(target: "foo_events", parent: ::core::option::Option::None, Level::TRACE, "bar",); + span!(parent: ::core::option::Option::None, Level::DEBUG, "foo", bar.baz = 2, quux = 3); + span!(parent: ::core::option::Option::None, Level::DEBUG, "foo", bar.baz = 2, quux = 4,); + span!(parent: ::core::option::Option::None, Level::DEBUG, "foo"); + span!(parent: ::core::option::Option::None, Level::DEBUG, "bar",); } #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] #[test] fn trace_span_root() { - trace_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 3); - trace_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 4,); - trace_span!(target: "foo_events", parent: None, "foo"); - trace_span!(target: "foo_events", parent: None, "bar",); - trace_span!(parent: None, "foo", bar.baz = 2, quux = 3); - trace_span!(parent: None, "foo", bar.baz = 2, quux = 4,); - trace_span!(parent: None, "foo"); - trace_span!(parent: None, "bar",); + trace_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3); + trace_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,); + trace_span!(target: "foo_events", parent: ::core::option::Option::None, "foo"); + trace_span!(target: "foo_events", parent: ::core::option::Option::None, "bar",); + trace_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3); + trace_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,); + trace_span!(parent: ::core::option::Option::None, "foo"); + trace_span!(parent: ::core::option::Option::None, "bar",); } #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] #[test] fn debug_span_root() { - debug_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 3); - debug_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 4,); - debug_span!(target: "foo_events", parent: None, "foo"); - debug_span!(target: "foo_events", parent: None, "bar",); - debug_span!(parent: None, "foo", bar.baz = 2, quux = 3); - debug_span!(parent: None, "foo", bar.baz = 2, quux = 4,); - debug_span!(parent: None, "foo"); - debug_span!(parent: None, "bar",); + debug_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3); + debug_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,); + debug_span!(target: "foo_events", parent: ::core::option::Option::None, "foo"); + debug_span!(target: "foo_events", parent: ::core::option::Option::None, "bar",); + debug_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3); + debug_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,); + debug_span!(parent: ::core::option::Option::None, "foo"); + debug_span!(parent: ::core::option::Option::None, "bar",); } #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] #[test] fn info_span_root() { - info_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 3); - info_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 4,); - info_span!(target: "foo_events", parent: None, "foo"); - info_span!(target: "foo_events", parent: None, "bar",); - info_span!(parent: None, "foo", bar.baz = 2, quux = 3); - info_span!(parent: None, "foo", bar.baz = 2, quux = 4,); - info_span!(parent: None, "foo"); - info_span!(parent: None, "bar",); + info_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3); + info_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,); + info_span!(target: "foo_events", parent: ::core::option::Option::None, "foo"); + info_span!(target: "foo_events", parent: ::core::option::Option::None, "bar",); + info_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3); + info_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,); + info_span!(parent: ::core::option::Option::None, "foo"); + info_span!(parent: ::core::option::Option::None, "bar",); } #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] #[test] fn warn_span_root() { - warn_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 3); - warn_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 4,); - warn_span!(target: "foo_events", parent: None, "foo"); - warn_span!(target: "foo_events", parent: None, "bar",); - warn_span!(parent: None, "foo", bar.baz = 2, quux = 3); - warn_span!(parent: None, "foo", bar.baz = 2, quux = 4,); - warn_span!(parent: None, "foo"); - warn_span!(parent: None, "bar",); + warn_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3); + warn_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,); + warn_span!(target: "foo_events", parent: ::core::option::Option::None, "foo"); + warn_span!(target: "foo_events", parent: ::core::option::Option::None, "bar",); + warn_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3); + warn_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,); + warn_span!(parent: ::core::option::Option::None, "foo"); + warn_span!(parent: ::core::option::Option::None, "bar",); } #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] #[test] fn error_span_root() { - error_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 3); - error_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 4,); - error_span!(target: "foo_events", parent: None, "foo"); - error_span!(target: "foo_events", parent: None, "bar",); - error_span!(parent: None, "foo", bar.baz = 2, quux = 3); - error_span!(parent: None, "foo", bar.baz = 2, quux = 4,); - error_span!(parent: None, "foo"); - error_span!(parent: None, "bar",); + error_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3); + error_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,); + error_span!(target: "foo_events", parent: ::core::option::Option::None, "foo"); + error_span!(target: "foo_events", parent: ::core::option::Option::None, "bar",); + error_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3); + error_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,); + error_span!(parent: ::core::option::Option::None, "foo"); + error_span!(parent: ::core::option::Option::None, "bar",); } #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] @@ -605,144 +609,144 @@ fn error() { #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] #[test] fn event_root() { - event!(parent: None, Level::DEBUG, foo = ?3, bar.baz = %2, quux = false); + event!(parent: ::core::option::Option::None, Level::DEBUG, foo = ?3, bar.baz = %2, quux = false); event!( - parent: None, + parent: ::core::option::Option::None, Level::DEBUG, foo = 3, bar.baz = 2, quux = false ); - event!(parent: None, Level::DEBUG, foo = 3, bar.baz = 3,); - event!(parent: None, Level::DEBUG, "foo"); - event!(parent: None, Level::DEBUG, "foo: {}", 3); - event!(parent: None, Level::DEBUG, { foo = 3, bar.baz = 80 }, "quux"); - event!(parent: None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}", true); - event!(parent: None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - event!(parent: None, Level::DEBUG, { foo = ?2, bar.baz = %78 }, "quux"); - event!(target: "foo_events", parent: None, Level::DEBUG, foo = 3, bar.baz = 2, quux = false); - event!(target: "foo_events", parent: None, Level::DEBUG, foo = 3, bar.baz = 3,); - event!(target: "foo_events", parent: None, Level::DEBUG, "foo"); - event!(target: "foo_events", parent: None, Level::DEBUG, "foo: {}", 3); - event!(target: "foo_events", parent: None, Level::DEBUG, { foo = 3, bar.baz = 80 }, "quux"); - event!(target: "foo_events", parent: None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}", true); - event!(target: "foo_events", parent: None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - event!(target: "foo_events", parent: None, Level::DEBUG, { foo = 2, bar.baz = 78, }, "quux"); + event!(parent: ::core::option::Option::None, Level::DEBUG, foo = 3, bar.baz = 3,); + event!(parent: ::core::option::Option::None, Level::DEBUG, "foo"); + event!(parent: ::core::option::Option::None, Level::DEBUG, "foo: {}", 3); + event!(parent: ::core::option::Option::None, Level::DEBUG, { foo = 3, bar.baz = 80 }, "quux"); + event!(parent: ::core::option::Option::None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + event!(parent: ::core::option::Option::None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + event!(parent: ::core::option::Option::None, Level::DEBUG, { foo = ?2, bar.baz = %78 }, "quux"); + event!(target: "foo_events", parent: ::core::option::Option::None, Level::DEBUG, foo = 3, bar.baz = 2, quux = false); + event!(target: "foo_events", parent: ::core::option::Option::None, Level::DEBUG, foo = 3, bar.baz = 3,); + event!(target: "foo_events", parent: ::core::option::Option::None, Level::DEBUG, "foo"); + event!(target: "foo_events", parent: ::core::option::Option::None, Level::DEBUG, "foo: {}", 3); + event!(target: "foo_events", parent: ::core::option::Option::None, Level::DEBUG, { foo = 3, bar.baz = 80 }, "quux"); + event!(target: "foo_events", parent: ::core::option::Option::None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + event!(target: "foo_events", parent: ::core::option::Option::None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + event!(target: "foo_events", parent: ::core::option::Option::None, Level::DEBUG, { foo = 2, bar.baz = 78, }, "quux"); } #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] #[test] fn trace_root() { - trace!(parent: None, foo = ?3, bar.baz = %2, quux = false); - trace!(parent: None, foo = 3, bar.baz = 2, quux = false); - trace!(parent: None, foo = 3, bar.baz = 3,); - trace!(parent: None, "foo"); - trace!(parent: None, "foo: {}", 3); - trace!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); - trace!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); - trace!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - trace!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); - trace!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); - trace!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); - trace!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); - trace!(target: "foo_events", parent: None, "foo"); - trace!(target: "foo_events", parent: None, "foo: {}", 3); - trace!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); - trace!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); - trace!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - trace!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); + trace!(parent: ::core::option::Option::None, foo = ?3, bar.baz = %2, quux = false); + trace!(parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false); + trace!(parent: ::core::option::Option::None, foo = 3, bar.baz = 3,); + trace!(parent: ::core::option::Option::None, "foo"); + trace!(parent: ::core::option::Option::None, "foo: {}", 3); + trace!(parent: ::core::option::Option::None, { foo = 3, bar.baz = 80 }, "quux"); + trace!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + trace!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + trace!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 78 }, "quux"); + trace!(parent: ::core::option::Option::None, { foo = ?2, bar.baz = %78 }, "quux"); + trace!(target: "foo_events", parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false); + trace!(target: "foo_events", parent: ::core::option::Option::None, foo = 3, bar.baz = 3,); + trace!(target: "foo_events", parent: ::core::option::Option::None, "foo"); + trace!(target: "foo_events", parent: ::core::option::Option::None, "foo: {}", 3); + trace!(target: "foo_events", parent: ::core::option::Option::None, { foo = 3, bar.baz = 80 }, "quux"); + trace!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + trace!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + trace!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 78, }, "quux"); } #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] #[test] fn debug_root() { - debug!(parent: None, foo = ?3, bar.baz = %2, quux = false); - debug!(parent: None, foo = 3, bar.baz = 2, quux = false); - debug!(parent: None, foo = 3, bar.baz = 3,); - debug!(parent: None, "foo"); - debug!(parent: None, "foo: {}", 3); - debug!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); - debug!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); - debug!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - debug!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); - debug!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); - debug!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); - debug!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); - debug!(target: "foo_events", parent: None, "foo"); - debug!(target: "foo_events", parent: None, "foo: {}", 3); - debug!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); - debug!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); - debug!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - debug!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); + debug!(parent: ::core::option::Option::None, foo = ?3, bar.baz = %2, quux = false); + debug!(parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false); + debug!(parent: ::core::option::Option::None, foo = 3, bar.baz = 3,); + debug!(parent: ::core::option::Option::None, "foo"); + debug!(parent: ::core::option::Option::None, "foo: {}", 3); + debug!(parent: ::core::option::Option::None, { foo = 3, bar.baz = 80 }, "quux"); + debug!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + debug!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + debug!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 78 }, "quux"); + debug!(parent: ::core::option::Option::None, { foo = ?2, bar.baz = %78 }, "quux"); + debug!(target: "foo_events", parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false); + debug!(target: "foo_events", parent: ::core::option::Option::None, foo = 3, bar.baz = 3,); + debug!(target: "foo_events", parent: ::core::option::Option::None, "foo"); + debug!(target: "foo_events", parent: ::core::option::Option::None, "foo: {}", 3); + debug!(target: "foo_events", parent: ::core::option::Option::None, { foo = 3, bar.baz = 80 }, "quux"); + debug!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + debug!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + debug!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 78, }, "quux"); } #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] #[test] fn info_root() { - info!(parent: None, foo = ?3, bar.baz = %2, quux = false); - info!(parent: None, foo = 3, bar.baz = 2, quux = false); - info!(parent: None, foo = 3, bar.baz = 3,); - info!(parent: None, "foo"); - info!(parent: None, "foo: {}", 3); - info!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); - info!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); - info!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - info!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); - info!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); - info!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); - info!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); - info!(target: "foo_events", parent: None, "foo"); - info!(target: "foo_events", parent: None, "foo: {}", 3); - info!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); - info!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); - info!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - info!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); + info!(parent: ::core::option::Option::None, foo = ?3, bar.baz = %2, quux = false); + info!(parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false); + info!(parent: ::core::option::Option::None, foo = 3, bar.baz = 3,); + info!(parent: ::core::option::Option::None, "foo"); + info!(parent: ::core::option::Option::None, "foo: {}", 3); + info!(parent: ::core::option::Option::None, { foo = 3, bar.baz = 80 }, "quux"); + info!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + info!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + info!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 78 }, "quux"); + info!(parent: ::core::option::Option::None, { foo = ?2, bar.baz = %78 }, "quux"); + info!(target: "foo_events", parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false); + info!(target: "foo_events", parent: ::core::option::Option::None, foo = 3, bar.baz = 3,); + info!(target: "foo_events", parent: ::core::option::Option::None, "foo"); + info!(target: "foo_events", parent: ::core::option::Option::None, "foo: {}", 3); + info!(target: "foo_events", parent: ::core::option::Option::None, { foo = 3, bar.baz = 80 }, "quux"); + info!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + info!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + info!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 78, }, "quux"); } #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] #[test] fn warn_root() { - warn!(parent: None, foo = ?3, bar.baz = %2, quux = false); - warn!(parent: None, foo = 3, bar.baz = 2, quux = false); - warn!(parent: None, foo = 3, bar.baz = 3,); - warn!(parent: None, "foo"); - warn!(parent: None, "foo: {}", 3); - warn!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); - warn!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); - warn!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - warn!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); - warn!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); - warn!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); - warn!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); - warn!(target: "foo_events", parent: None, "foo"); - warn!(target: "foo_events", parent: None, "foo: {}", 3); - warn!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); - warn!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); - warn!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - warn!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); + warn!(parent: ::core::option::Option::None, foo = ?3, bar.baz = %2, quux = false); + warn!(parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false); + warn!(parent: ::core::option::Option::None, foo = 3, bar.baz = 3,); + warn!(parent: ::core::option::Option::None, "foo"); + warn!(parent: ::core::option::Option::None, "foo: {}", 3); + warn!(parent: ::core::option::Option::None, { foo = 3, bar.baz = 80 }, "quux"); + warn!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + warn!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + warn!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 78 }, "quux"); + warn!(parent: ::core::option::Option::None, { foo = ?2, bar.baz = %78 }, "quux"); + warn!(target: "foo_events", parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false); + warn!(target: "foo_events", parent: ::core::option::Option::None, foo = 3, bar.baz = 3,); + warn!(target: "foo_events", parent: ::core::option::Option::None, "foo"); + warn!(target: "foo_events", parent: ::core::option::Option::None, "foo: {}", 3); + warn!(target: "foo_events", parent: ::core::option::Option::None, { foo = 3, bar.baz = 80 }, "quux"); + warn!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + warn!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + warn!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 78, }, "quux"); } #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] #[test] fn error_root() { - error!(parent: None, foo = ?3, bar.baz = %2, quux = false); - error!(parent: None, foo = 3, bar.baz = 2, quux = false); - error!(parent: None, foo = 3, bar.baz = 3,); - error!(parent: None, "foo"); - error!(parent: None, "foo: {}", 3); - error!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); - error!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); - error!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - error!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); - error!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); - error!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); - error!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); - error!(target: "foo_events", parent: None, "foo"); - error!(target: "foo_events", parent: None, "foo: {}", 3); - error!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); - error!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); - error!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - error!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); + error!(parent: ::core::option::Option::None, foo = ?3, bar.baz = %2, quux = false); + error!(parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false); + error!(parent: ::core::option::Option::None, foo = 3, bar.baz = 3,); + error!(parent: ::core::option::Option::None, "foo"); + error!(parent: ::core::option::Option::None, "foo: {}", 3); + error!(parent: ::core::option::Option::None, { foo = 3, bar.baz = 80 }, "quux"); + error!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + error!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + error!(parent: ::core::option::Option::None, { foo = 2, bar.baz = 78 }, "quux"); + error!(parent: ::core::option::Option::None, { foo = ?2, bar.baz = %78 }, "quux"); + error!(target: "foo_events", parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false); + error!(target: "foo_events", parent: ::core::option::Option::None, foo = 3, bar.baz = 3,); + error!(target: "foo_events", parent: ::core::option::Option::None, "foo"); + error!(target: "foo_events", parent: ::core::option::Option::None, "foo: {}", 3); + error!(target: "foo_events", parent: ::core::option::Option::None, { foo = 3, bar.baz = 80 }, "quux"); + error!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + error!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + error!(target: "foo_events", parent: ::core::option::Option::None, { foo = 2, bar.baz = 78, }, "quux"); } #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] @@ -913,7 +917,7 @@ fn field_shorthand_only() { #[test] fn borrow_val_events() { // Reproduces https://github.com/tokio-rs/tracing/issues/954 - let mut foo = (String::new(), String::new()); + let mut foo = (::std::string::String::new(), ::std::string::String::new()); let zero = &mut foo.0; trace!(one = ?foo.1); debug!(one = ?foo.1); @@ -927,7 +931,7 @@ fn borrow_val_events() { #[test] fn borrow_val_spans() { // Reproduces https://github.com/tokio-rs/tracing/issues/954 - let mut foo = (String::new(), String::new()); + let mut foo = (::std::string::String::new(), ::std::string::String::new()); let zero = &mut foo.0; let _span = trace_span!("span", one = ?foo.1); let _span = debug_span!("span", one = ?foo.1);