From a5e70584d599fd9db520da97bfc80da4b443312b Mon Sep 17 00:00:00 2001 From: Hayden Stainsby Date: Wed, 16 Nov 2022 14:24:11 +0100 Subject: [PATCH 1/9] mock: document public API in collector module 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 | 509 +++++++++++++++++++++++++++++----- tracing-mock/src/expect.rs | 50 ++++ 2 files changed, 491 insertions(+), 68 deletions(-) diff --git a/tracing-mock/src/collector.rs b/tracing-mock/src/collector.rs index 21cb6d6e2f..2792a4e069 100644 --- a/tracing-mock/src/collector.rs +++ b/tracing-mock/src/collector.rs @@ -1,4 +1,37 @@ -#![allow(missing_docs)] +//! A `Collector` to receive and validate `tracing` data. +//! +//! # Overview +//! +//! [`tracing`] is a framework for instrumenting Rust programs to collect +//! structured, event-based diagnostic information. `tracing-mock` provides +//! tools for making assertions about what `tracing` diagnostics are emitted +//! by code under test. The `MockCollector` is the central component in these +//! tools. The `MockCollector` has expectations set on it which are later +//! validated as the code under test is run. +//! +//! # Usage +//! +//! ``` +//! use tracing::collect::with_default; +//! 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. +//! 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(); +//! ``` use crate::{ event::ExpectedEvent, expect::Expect, @@ -7,7 +40,6 @@ use crate::{ }; use std::{ collections::{HashMap, VecDeque}, - fmt, sync::{ atomic::{AtomicUsize, Ordering}, Arc, Mutex, @@ -37,6 +69,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 +82,10 @@ pub struct MockCollector) -> bool> { name: String, } +/// A handle which is used to invoke validation of expectations. pub struct MockHandle(Arc>>, String); +/// Create a new [`MockCollector`]. pub fn mock() -> MockCollector) -> bool> { MockCollector { expected: VecDeque::new(), @@ -75,6 +115,22 @@ where /// interactions between multiple subscribers. In that case, it can be /// helpful to give each subscriber a separate name to distinguish where the /// debugging output comes from. + /// + /// ``` + /// use tracing::collect::with_default; + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .named("subscriber-1") + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// with_default(collector, || { + /// tracing::info!("a"); + /// }); + /// + /// handle.assert_finished(); + /// ``` pub fn named(self, name: impl ToString) -> Self { Self { name: name.to_string(), @@ -82,43 +138,245 @@ where } } - pub fn enter(mut self, span: ExpectedSpan) -> Self { - self.expected.push_back(Expect::Enter(span)); + /// Expects an event matching the [`ExpectedEvent`] to be traced. + /// + /// The `event` can be simple a default mock which will match + /// any event (`expect::event()`) or can include + /// additional requirements. See the [`ExpectedEvent`] documentation + /// for more details. + /// + /// ``` + /// use tracing::collect::with_default; + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// with_default(collector, || { + /// 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 }); + /// Expects a span matching `new_span` to be created. + /// + /// 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 have been entered. + /// + /// ``` + /// use tracing::collect::with_default; + /// 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(); + /// + /// with_default(collector, || { + /// _ = 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)); + /// Expects a span matching the [`ExpectedSpan`] to be entered. + /// + /// This expectation is generally accompanied by a call to + /// [`exit`] as well. If used together with [`only`], this + /// is necessary. + /// + /// ``` + /// use tracing::collect::with_default; + /// 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(); + /// + /// with_default(collector, || { + /// 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 } + /// Expects a span matching the [`ExpectedSpan`] to exit. + /// + /// 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. + /// + /// ``` + /// use tracing::collect::with_default; + /// 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.clone()) + /// .enter(span.clone()) + /// .exit(span) + /// .run_with_handle(); + /// + /// with_default(collector, || { + /// let span = tracing::info_span!("the span we're testing"); + /// { + /// let _entered = span.enter(); + /// } + /// { + /// let _entered = span.enter(); + /// } + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// [`enter`]: fn@Self::enter pub fn exit(mut self, span: ExpectedSpan) -> Self { self.expected.push_back(Expect::Exit(span)); self } + /// Expects a span matching the [`ExpectedSpan`] to be cloned. + /// + /// The cloned span does need to have been entered. + /// + /// ``` + /// use tracing::collect::with_default; + /// 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(); + /// + /// with_default(collector, || { + /// let span = tracing::info_span!("the span we're testing"); + /// _ = span.clone(); + /// }); + /// + /// handle.assert_finished(); + /// ``` pub fn clone_span(mut self, span: ExpectedSpan) -> Self { self.expected.push_back(Expect::CloneSpan(span)); self } - #[allow(deprecated)] + /// Expects a span matching the [`ExpectedSpan`] to be dropped via + /// the deprecated function [`Collect::drop_span`]. + /// + /// Instead [`Collect::try_close`] should be used on the collector + /// and should be asserted with [`close_span`]. + /// + /// NOTE: [`close_span`] hasn't been implemented yet, but will be + /// done as part of #539. + /// + /// [`Collect::drop_span`]: fn@tracing::Collect::drop_span + /// [`close_span`]: fn@Self::close_span + #[deprecated(since = "0.1.0", note = "use `MockCollector::close_span` instead")] 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); + /// Expects that a span matching `consequence` follows from a span matching `cause`. + /// + /// For further details on what this causal relationship means, see + /// [`Span::follows_from`]. + /// + /// ``` + /// use tracing::collect::with_default; + /// use tracing_mock::{collector, expect}; + /// + /// let span_1 = expect::span().named("cause"); + /// let span_2 = expect::span().named("consequence"); + /// + /// let (collector, handle) = collector::mock() + /// .new_span(span_1.clone()) + /// .new_span(span_2.clone()) + /// .follows_from(span_2, span_1) + /// .run_with_handle(); + /// + /// with_default(collector, || { + /// let cause = tracing::info_span!("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 } + /// Expect that `fields` are recorded on a span matching the + /// [`ExpectedSpan`]. + /// + /// ``` + /// use tracing::collect::with_default; + /// use tracing_mock::{collector, expect}; + /// + /// let span = expect::span() + /// .named("my_span"); + /// let (collector, handle) = collector::mock() + /// .new_span(span.clone()) + /// .record(span, expect::field("parting").with_value(&"goodbye world!")) + /// .run_with_handle(); + /// + /// 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(); + /// ``` pub fn record(mut self, span: ExpectedSpan, fields: I) -> Self where I: Into, @@ -127,14 +385,29 @@ 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 verification occurs - so its position in the call chain + /// is not important. + /// + /// ``` + /// use tracing::collect::with_default; + /// 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(); + /// + /// 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 +420,38 @@ 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. + /// + /// ``` + /// use tracing::collect::with_default; + /// 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(); + /// + /// with_default(collector, || { + /// tracing::debug!("a message we don't care about"); + /// tracing::info!("a message we want to verify"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// Note that 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. + /// + /// [`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 +459,102 @@ where } } + /// Expects that no further traces are received. + /// + /// Consider this simple test. It passes even though we only + /// expect a single event, but receive three. + /// + /// ``` + /// use tracing::collect::with_default; + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// with_default(collector, || { + /// tracing::info!("a"); + /// tracing::info!("b"); + /// tracing::info!("c"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// Now we include `only` and this test will fail. + /// + /// ```should_panic + /// use tracing::collect::with_default; + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .event(expect::event()) + /// .only() + /// .run_with_handle(); + /// + /// 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. + /// + /// For example, the following test is used within the `tracing` + /// codebase. + /// + /// ``` + /// use tracing::collect::with_default; + /// use tracing_mock::collector; + /// + /// 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. + /// + /// ``` + /// use tracing::collect::with_default; + /// 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(); + /// + /// 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()); @@ -459,6 +855,31 @@ 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. + /// + /// ``` + /// use tracing::collect::with_default; + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// 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!( @@ -470,51 +891,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 39045eddf660f965955bf6cee2b412ee0b095c2c Mon Sep 17 00:00:00 2001 From: Hayden Stainsby Date: Sat, 19 Nov 2022 00:20:09 +0100 Subject: [PATCH 2/9] don't make MockCollector::drop_span deprecated It creates too many issues (need to add `allow_deprecated` annotations all over the place) and they will actually make fixing those tests to use the new (but as yet unimplemented) `MockCollector::close_span` more difficult. --- tracing-mock/src/collector.rs | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/tracing-mock/src/collector.rs b/tracing-mock/src/collector.rs index 2792a4e069..dfd0a9e04e 100644 --- a/tracing-mock/src/collector.rs +++ b/tracing-mock/src/collector.rs @@ -300,6 +300,8 @@ where self } + /// **This method is deprecated.** + /// /// Expects a span matching the [`ExpectedSpan`] to be dropped via /// the deprecated function [`Collect::drop_span`]. /// @@ -311,7 +313,7 @@ where /// /// [`Collect::drop_span`]: fn@tracing::Collect::drop_span /// [`close_span`]: fn@Self::close_span - #[deprecated(since = "0.1.0", note = "use `MockCollector::close_span` instead")] + #[allow(deprecated)] pub fn drop_span(mut self, span: ExpectedSpan) -> Self { self.expected.push_back(Expect::DropSpan(span)); self From fe92324b92aa748345f09d16f2f66b10378b598d Mon Sep 17 00:00:00 2001 From: Hayden Stainsby Date: Sat, 19 Nov 2022 00:25:37 +0100 Subject: [PATCH 3/9] I was wondering whether missing docs were checked... They are! I removed the referce to `MockCollector::close_span` as it doesn't yet exist. --- tracing-mock/src/collector.rs | 7 ++----- 1 file changed, 2 insertions(+), 5 deletions(-) diff --git a/tracing-mock/src/collector.rs b/tracing-mock/src/collector.rs index dfd0a9e04e..6856ec52c8 100644 --- a/tracing-mock/src/collector.rs +++ b/tracing-mock/src/collector.rs @@ -306,13 +306,10 @@ where /// the deprecated function [`Collect::drop_span`]. /// /// Instead [`Collect::try_close`] should be used on the collector - /// and should be asserted with [`close_span`]. - /// - /// NOTE: [`close_span`] hasn't been implemented yet, but will be - /// done as part of #539. + /// 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 - /// [`close_span`]: fn@Self::close_span #[allow(deprecated)] pub fn drop_span(mut self, span: ExpectedSpan) -> Self { self.expected.push_back(Expect::DropSpan(span)); From b2816a2bc283d48de721bceb455bf198af9739bb Mon Sep 17 00:00:00 2001 From: Hayden Stainsby Date: Thu, 5 Jan 2023 01:55:07 +0100 Subject: [PATCH 4/9] added negative examples to most methods Also cleaned up the text and tried to apply the code review comments from #2426 to what I'd written already. --- tracing-mock/src/collector.rs | 341 ++++++++++++++++++++++++++++------ 1 file changed, 288 insertions(+), 53 deletions(-) diff --git a/tracing-mock/src/collector.rs b/tracing-mock/src/collector.rs index 6856ec52c8..9eb36274d4 100644 --- a/tracing-mock/src/collector.rs +++ b/tracing-mock/src/collector.rs @@ -107,15 +107,17 @@ 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 + /// /// ``` /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; @@ -138,12 +140,18 @@ where } } - /// Expects an event matching the [`ExpectedEvent`] to be traced. + /// Adds the 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. /// - /// The `event` can be simple a default mock which will match - /// any event (`expect::event()`) or can include - /// additional requirements. See the [`ExpectedEvent`] documentation - /// for more details. + /// # Examples /// /// ``` /// use tracing::collect::with_default; @@ -159,20 +167,47 @@ where /// /// handle.assert_finished(); /// ``` + /// + /// A span is entered before the event, causing the test to fail: + /// + /// ```should_panic + /// use tracing::collect::with_default; + /// use tracing_mock::{collector, expect}; + /// + /// let (collector, handle) = collector::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// 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 } - /// Expects a span matching `new_span` to be created. + /// Adds the 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 + /// [`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 have been 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::collect::with_default; @@ -192,6 +227,29 @@ where /// /// handle.assert_finished(); /// ``` + /// + /// An event is recorded before the span is created, causing the + /// test to fail: + /// + /// ```should_panic + /// use tracing::collect::with_default; + /// 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(); + /// + /// 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, @@ -200,12 +258,19 @@ where self } - /// Expects a span matching the [`ExpectedSpan`] to be entered. + /// Adds the 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::collect::with_default; /// use tracing_mock::{collector, expect}; @@ -227,6 +292,31 @@ where /// handle.assert_finished(); /// ``` /// + /// An event is recorded before the span is entered, causing the + /// test to fail: + /// + /// ```should_panic + /// use tracing::collect::with_default; + /// 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(); + /// + /// 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 { @@ -234,12 +324,19 @@ where self } - /// Expects a span matching the [`ExpectedSpan`] to exit. + /// Adds the 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::collect::with_default; /// use tracing_mock::{collector, expect}; @@ -249,19 +346,36 @@ where /// .named("the span we're testing"); /// let (collector, handle) = collector::mock() /// .enter(span.clone()) - /// .exit(span.clone()) + /// .exit(span) + /// .run_with_handle(); + /// + /// 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::collect::with_default; + /// 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(); /// /// with_default(collector, || { /// let span = tracing::info_span!("the span we're testing"); - /// { - /// let _entered = span.enter(); - /// } - /// { - /// let _entered = span.enter(); - /// } + /// let _entered = span.enter(); + /// tracing::info!("an event"); /// }); /// /// handle.assert_finished(); @@ -273,11 +387,40 @@ where self } - /// Expects a span matching the [`ExpectedSpan`] to be cloned. + /// Adds the 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::collect::with_default; + /// use tracing_mock::{collector, expect}; /// - /// The cloned span does need to have been entered. + /// 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(); + /// + /// 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::collect::with_default; /// use tracing_mock::{collector, expect}; /// @@ -290,6 +433,7 @@ where /// /// with_default(collector, || { /// let span = tracing::info_span!("the span we're testing"); + /// tracing::info!("an event"); /// _ = span.clone(); /// }); /// @@ -302,8 +446,9 @@ where /// **This method is deprecated.** /// - /// Expects a span matching the [`ExpectedSpan`] to be dropped via - /// the deprecated function [`Collect::drop_span`]. + /// Adds the 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 @@ -316,22 +461,31 @@ where self } - /// Expects that a span matching `consequence` follows from a span matching `cause`. + /// Adds the 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::collect::with_default; /// use tracing_mock::{collector, expect}; /// - /// let span_1 = expect::span().named("cause"); - /// let span_2 = expect::span().named("consequence"); + /// let cause = expect::span().named("cause"); + /// let consequence = expect::span().named("consequence"); /// /// let (collector, handle) = collector::mock() - /// .new_span(span_1.clone()) - /// .new_span(span_2.clone()) - /// .follows_from(span_2, span_1) + /// .follows_from(consequence, cause) /// .run_with_handle(); /// /// with_default(collector, || { @@ -344,6 +498,31 @@ where /// 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::collect::with_default; + /// 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(); + /// + /// 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 @@ -351,8 +530,18 @@ where self } - /// Expect that `fields` are recorded on a span matching the - /// [`ExpectedSpan`]. + /// Adds the 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::collect::with_default; @@ -361,7 +550,6 @@ where /// let span = expect::span() /// .named("my_span"); /// let (collector, handle) = collector::mock() - /// .new_span(span.clone()) /// .record(span, expect::field("parting").with_value(&"goodbye world!")) /// .run_with_handle(); /// @@ -376,6 +564,33 @@ where /// /// handle.assert_finished(); /// ``` + /// + /// The value of the recorded field doesn't match the expectation, + /// causing the test to fail: + /// + /// ```should_panic + /// use tracing::collect::with_default; + /// 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(); + /// + /// 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, @@ -387,8 +602,11 @@ where /// Filter the traces evaluated by the `MockCollector`. /// /// The filter will be applied to all traces received before - /// any verification occurs - so its position in the call chain - /// is not important. + /// any validation occurs - so its position in the call chain + /// is not important. The filter does not perform any validation + /// itself. + /// + /// # Examples /// /// ``` /// use tracing::collect::with_default; @@ -419,11 +637,21 @@ where } } - /// Sets the max level that will be provided to the `tracing` system. + /// 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. + /// 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::collect::with_default; @@ -437,19 +665,12 @@ where /// /// with_default(collector, || { /// tracing::debug!("a message we don't care about"); - /// tracing::info!("a message we want to verify"); + /// tracing::info!("a message we want to validate"); /// }); /// /// handle.assert_finished(); /// ``` /// - /// Note that 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. - /// /// [`with_filter`]: fn@Self::with_filter pub fn with_max_level_hint(self, hint: impl Into) -> Self { Self { @@ -460,8 +681,14 @@ 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. + /// expect a single event, but receive three: /// /// ``` /// use tracing::collect::with_default; @@ -480,7 +707,7 @@ where /// handle.assert_finished(); /// ``` /// - /// Now we include `only` and this test will fail. + /// After including `only`, the test will fail: /// /// ```should_panic /// use tracing::collect::with_default; @@ -511,8 +738,10 @@ where /// return a [`MockHandle`]. This is useful if the desired /// assertions can be checked externally to the collector. /// - /// For example, the following test is used within the `tracing` - /// codebase. + /// # Examples + /// + /// The following test is used within the `tracing` + /// codebase: /// /// ``` /// use tracing::collect::with_default; @@ -537,6 +766,8 @@ where /// be set as the default collector and a [`MockHandle`] which can /// be used to validate the provided expectations. /// + /// # Examples + /// /// ``` /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; @@ -654,9 +885,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); } } @@ -864,6 +1097,8 @@ impl MockHandle { /// This method will panic if any of the provided expectations are /// not met. /// + /// # Examples + /// /// ``` /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; From 299f093ab9f5fa2772027746efdb712ce517825e Mon Sep 17 00:00:00 2001 From: Hayden Stainsby Date: Thu, 5 Jan 2023 21:46:57 +0100 Subject: [PATCH 5/9] typo fix --- tracing-mock/src/collector.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tracing-mock/src/collector.rs b/tracing-mock/src/collector.rs index 9eb36274d4..3ffdd14c40 100644 --- a/tracing-mock/src/collector.rs +++ b/tracing-mock/src/collector.rs @@ -473,7 +473,7 @@ where /// recorded first, then the expectation will fail. /// /// **Note**: The 2 spans, `consequence` and `cause` are matched - /// by `name `only. + /// by `name` only. /// /// # Examples /// From 757d87777998689fba33b2ef566d27330ea5a5f8 Mon Sep 17 00:00:00 2001 From: Hayden Stainsby Date: Mon, 9 Jan 2023 12:48:15 +0100 Subject: [PATCH 6/9] Apply suggestions from code review Co-authored-by: Eliza Weisman --- tracing-mock/src/collector.rs | 16 ++++++++++------ 1 file changed, 10 insertions(+), 6 deletions(-) diff --git a/tracing-mock/src/collector.rs b/tracing-mock/src/collector.rs index be11029b49..8dd331e4d0 100644 --- a/tracing-mock/src/collector.rs +++ b/tracing-mock/src/collector.rs @@ -9,17 +9,17 @@ //! tools. The `MockCollector` has expectations set on it which are later //! validated as the code under test is run. //! -//! # Usage +//! # Examples //! //! ``` //! use tracing::collect::with_default; //! 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(); +//! // 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. @@ -118,12 +118,14 @@ where /// /// # Examples /// + /// # Examples + /// /// ``` /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let (collector, handle) = collector::mock() - /// .named("subscriber-1") + /// .named("collector-1") /// .event(expect::event()) /// .run_with_handle(); /// @@ -165,6 +167,8 @@ where /// tracing::info!("a"); /// }); /// + /// # Examples + /// /// handle.assert_finished(); /// ``` /// From 55901c8c824d347666b5e620190fc3cee08a7862 Mon Sep 17 00:00:00 2001 From: Hayden Stainsby Date: Tue, 10 Jan 2023 18:16:53 +0100 Subject: [PATCH 7/9] Expanded collector module examples and other changes All based on the lovely code review feedback I've been receiving. --- tracing-mock/src/collector.rs | 280 +++++++++++++++++++++++++++------- 1 file changed, 223 insertions(+), 57 deletions(-) diff --git a/tracing-mock/src/collector.rs b/tracing-mock/src/collector.rs index be11029b49..c2c126191d 100644 --- a/tracing-mock/src/collector.rs +++ b/tracing-mock/src/collector.rs @@ -1,18 +1,15 @@ -//! A `Collector` to receive and validate `tracing` data. +//! An implementation of the [`Collect`] trait to receive and validate +//! `tracing` data. //! //! # Overview //! -//! [`tracing`] is a framework for instrumenting Rust programs to collect -//! structured, event-based diagnostic information. `tracing-mock` provides -//! tools for making assertions about what `tracing` diagnostics are emitted -//! by code under test. The `MockCollector` is the central component in these -//! tools. The `MockCollector` has expectations set on it which are later +//! The [`MockCollector`] is the central component in these tools. The +//! `MockCollector` has expectations set on it which are later //! validated as the code under test is run. //! -//! # Usage +//! # Examples //! //! ``` -//! use tracing::collect::with_default; //! use tracing_mock::{collector, expect, field}; //! //! let (collector, handle) = collector::mock() @@ -23,7 +20,7 @@ //! //! // Use `with_default` to apply the `MockCollector` for the duration //! // of the closure - this is what we are testing. -//! with_default(collector, || { +//! tracing::collect::with_default(collector, || { //! // These *are* the droids we are looking for //! tracing::info!("droids"); //! }); @@ -32,6 +29,116 @@ //! // 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, @@ -83,9 +190,65 @@ pub struct MockCollector) -> bool> { } /// 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 pub fn mock() -> MockCollector) -> bool> { MockCollector { expected: VecDeque::new(), @@ -118,20 +281,44 @@ where /// /// # Examples /// - /// ``` - /// use tracing::collect::with_default; + /// 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, handle) = collector::mock() - /// .named("subscriber-1") + /// let (collector_1, handle_1) = collector::mock() + /// .named("collector-1") /// .event(expect::event()) /// .run_with_handle(); /// - /// with_default(collector, || { + /// 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.assert_finished(); + /// 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 { @@ -154,14 +341,13 @@ where /// # Examples /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let (collector, handle) = collector::mock() /// .event(expect::event()) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// tracing::info!("a"); /// }); /// @@ -171,14 +357,13 @@ where /// A span is entered before the event, causing the test to fail: /// /// ```should_panic - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let (collector, handle) = collector::mock() /// .event(expect::event()) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// let span = tracing::info_span!("span"); /// let _guard = span.enter(); /// tracing::info!("a"); @@ -210,7 +395,6 @@ where /// # Examples /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let span = expect::span() @@ -221,7 +405,7 @@ where /// .new_span(span) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// _ = tracing::info_span!("the span we're testing", testing = "yes"); /// }); /// @@ -232,7 +416,6 @@ where /// test to fail: /// /// ```should_panic - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let span = expect::span() @@ -243,7 +426,7 @@ where /// .new_span(span) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// tracing::info!("an event"); /// _ = tracing::info_span!("the span we're testing", testing = "yes"); /// }); @@ -272,7 +455,6 @@ where /// # Examples /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let span = expect::span() @@ -284,7 +466,7 @@ where /// .only() /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// let span = tracing::info_span!("the span we're testing"); /// let _entered = span.enter(); /// }); @@ -296,7 +478,6 @@ where /// test to fail: /// /// ```should_panic - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let span = expect::span() @@ -308,7 +489,7 @@ where /// .only() /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// tracing::info!("an event"); /// let span = tracing::info_span!("the span we're testing"); /// let _entered = span.enter(); @@ -338,7 +519,6 @@ where /// # Examples /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let span = expect::span() @@ -349,7 +529,7 @@ where /// .exit(span) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// let span = tracing::info_span!("the span we're testing"); /// let _entered = span.enter(); /// }); @@ -361,7 +541,6 @@ where /// test to fail: /// /// ```should_panic - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let span = expect::span() @@ -372,7 +551,7 @@ where /// .exit(span) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// let span = tracing::info_span!("the span we're testing"); /// let _entered = span.enter(); /// tracing::info!("an event"); @@ -399,7 +578,6 @@ where /// # Examples /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let span = expect::span() @@ -409,7 +587,7 @@ where /// .clone_span(span) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// let span = tracing::info_span!("the span we're testing"); /// _ = span.clone(); /// }); @@ -421,7 +599,6 @@ where /// test to fail: /// /// ```should_panic - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let span = expect::span() @@ -431,7 +608,7 @@ where /// .clone_span(span) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// let span = tracing::info_span!("the span we're testing"); /// tracing::info!("an event"); /// _ = span.clone(); @@ -478,7 +655,6 @@ where /// # Examples /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let cause = expect::span().named("cause"); @@ -488,7 +664,7 @@ where /// .follows_from(consequence, cause) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// let cause = tracing::info_span!("cause"); /// let consequence = tracing::info_span!("consequence"); /// @@ -503,7 +679,6 @@ where /// this test to fail: /// /// ```should_panic - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let cause = expect::span().named("cause"); @@ -513,7 +688,7 @@ where /// .follows_from(consequence, cause) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// let cause = tracing::info_span!("another cause"); /// let consequence = tracing::info_span!("consequence"); /// @@ -544,7 +719,6 @@ where /// # Examples /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let span = expect::span() @@ -553,7 +727,7 @@ where /// .record(span, expect::field("parting").with_value(&"goodbye world!")) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// let span = tracing::trace_span!( /// "my_span", /// greeting = "hello world", @@ -569,7 +743,6 @@ where /// causing the test to fail: /// /// ```should_panic - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let span = expect::span() @@ -578,7 +751,7 @@ where /// .record(span, expect::field("parting").with_value(&"goodbye world!")) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// let span = tracing::trace_span!( /// "my_span", /// greeting = "hello world", @@ -609,7 +782,6 @@ where /// # Examples /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let (collector, handle) = collector::mock() @@ -618,7 +790,7 @@ where /// .only() /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// tracing::info!("a"); /// tracing::warn!("b"); /// }); @@ -654,7 +826,6 @@ where /// # Examples /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let (collector, handle) = collector::mock() @@ -663,7 +834,7 @@ where /// .only() /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// tracing::debug!("a message we don't care about"); /// tracing::info!("a message we want to validate"); /// }); @@ -691,14 +862,13 @@ where /// expect a single event, but receive three: /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let (collector, handle) = collector::mock() /// .event(expect::event()) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// tracing::info!("a"); /// tracing::info!("b"); /// tracing::info!("c"); @@ -710,7 +880,6 @@ where /// After including `only`, the test will fail: /// /// ```should_panic - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let (collector, handle) = collector::mock() @@ -718,7 +887,7 @@ where /// .only() /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// tracing::info!("a"); /// tracing::info!("b"); /// tracing::info!("c"); @@ -744,10 +913,9 @@ where /// codebase: /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::collector; /// - /// with_default(collector::mock().run(), || { + /// 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. @@ -769,7 +937,6 @@ where /// # Examples /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// // collector and handle are returned from `run_with_handle()` @@ -777,7 +944,7 @@ where /// .event(expect::event()) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// tracing::info!("a"); /// }); /// @@ -1108,14 +1275,13 @@ impl MockHandle { /// # Examples /// /// ``` - /// use tracing::collect::with_default; /// use tracing_mock::{collector, expect}; /// /// let (collector, handle) = collector::mock() /// .event(expect::event()) /// .run_with_handle(); /// - /// with_default(collector, || { + /// tracing::collect::with_default(collector, || { /// tracing::info!("a"); /// }); /// From ca6b72a2581582d1be1339796b9097fe7fda1b88 Mon Sep 17 00:00:00 2001 From: Hayden Stainsby Date: Tue, 10 Jan 2023 19:10:52 +0100 Subject: [PATCH 8/9] Update tracing-mock/src/collector.rs --- tracing-mock/src/collector.rs | 2 -- 1 file changed, 2 deletions(-) diff --git a/tracing-mock/src/collector.rs b/tracing-mock/src/collector.rs index 3a2d09cbf5..b6cfe29600 100644 --- a/tracing-mock/src/collector.rs +++ b/tracing-mock/src/collector.rs @@ -351,8 +351,6 @@ where /// tracing::info!("a"); /// }); /// - /// # Examples - /// /// handle.assert_finished(); /// ``` /// From df486f957649d475fad24ec8ebce6fcc350effda Mon Sep 17 00:00:00 2001 From: Hayden Stainsby Date: Wed, 18 Jan 2023 16:33:53 +0100 Subject: [PATCH 9/9] Ported some comments from #2446 The PR documenting the subscriber module. --- tracing-mock/src/collector.rs | 24 +++++++++++------------- 1 file changed, 11 insertions(+), 13 deletions(-) diff --git a/tracing-mock/src/collector.rs b/tracing-mock/src/collector.rs index b6cfe29600..0a9e760161 100644 --- a/tracing-mock/src/collector.rs +++ b/tracing-mock/src/collector.rs @@ -1,9 +1,7 @@ //! An implementation of the [`Collect`] trait to receive and validate //! `tracing` data. //! -//! # Overview -//! -//! The [`MockCollector`] is the central component in these tools. The +//! 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. //! @@ -249,6 +247,7 @@ pub struct MockHandle(Arc>>, String); /// ``` /// /// [`collector`]: mod@crate::collector +#[must_use] pub fn mock() -> MockCollector) -> bool> { MockCollector { expected: VecDeque::new(), @@ -327,7 +326,7 @@ where } } - /// Adds the expectation that an event matching the [`ExpectedEvent`] + /// 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 @@ -376,7 +375,7 @@ where self } - /// Adds the expectation that the creation of a span will be + /// Adds an expectation that the creation of a span will be /// recorded next. /// /// This function accepts `Into` instead of @@ -441,7 +440,7 @@ where self } - /// Adds the expectation that entering a span matching the + /// Adds an expectation that entering a span matching the /// [`ExpectedSpan`] will be recorded next. /// /// This expectation is generally accompanied by a call to @@ -505,7 +504,7 @@ where self } - /// Adds the expectation that exiting a span matching the + /// Adds ab expectation that exiting a span matching the /// [`ExpectedSpan`] will be recorded next. /// /// As a span may be entered and exited multiple times, @@ -566,7 +565,7 @@ where self } - /// Adds the expectation that cloning a span matching the + /// Adds an expectation that cloning a span matching the /// [`ExpectedSpan`] will be recorded next. /// /// The cloned span does need to be entered. @@ -623,8 +622,8 @@ where /// **This method is deprecated.** /// - /// Adds the expectation that a span matching the [`ExpectedSpan`] - /// getting dropped` via the deprecated function + /// 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 @@ -638,7 +637,7 @@ where self } - /// Adds the expectation that a `follows_from` relationship will be + /// Adds an expectation that a `follows_from` relationship will be /// recorded next. Specifically that a span matching `consequence` /// follows from a span matching `cause`. /// @@ -705,7 +704,7 @@ where self } - /// Adds the expectation that `fields` are recorded on a span + /// 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 @@ -816,7 +815,6 @@ where /// 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.