From 25ebc5578e6e8484496fb43f54633c3bc94384bd Mon Sep 17 00:00:00 2001 From: Hayden Stainsby Date: Sat, 24 Jun 2023 04:09:29 +0200 Subject: [PATCH] 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/expect.rs | 50 ++ tracing-mock/src/subscriber.rs | 913 ++++++++++++++++++++++++++++++--- 2 files changed, 892 insertions(+), 71 deletions(-) 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, + ), + } + } +} diff --git a/tracing-mock/src/subscriber.rs b/tracing-mock/src/subscriber.rs index 249985f3f0..ef7a93b148 100644 --- a/tracing-mock/src/subscriber.rs +++ b/tracing-mock/src/subscriber.rs @@ -1,4 +1,142 @@ -#![allow(missing_docs)] +//! An implementation of the [`Subscriber`] trait to receive and validate +//! `tracing` data. +//! +//! The [`MockSubscriber`] is the central component of this crate. The +//! `MockSubscriber` has expectations set on it which are later +//! validated as the code under test is run. +//! +//! # Examples +//! +//! ``` +//! use tracing_mock::{subscriber, expect, field}; +//! +//! let (subscriber, handle) = subscriber::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 `MockSubscriber` for the duration +//! // of the closure - this is what we are testing. +//! tracing::subscriber::with_default(subscriber, || { +//! // 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::{subscriber, expect, field}; +//! +//! let span = expect::span() +//! .named("my_span"); +//! let (subscriber, handle) = subscriber::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 subscriber and handle +//! .run_with_handle(); +//! +//! // Use `with_default` to apply the `MockSubscriber` for the duration +//! // of the closure - this is what we are testing. +//! tracing::subscriber::with_default(subscriber, || { +//! 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::{subscriber, expect, field}; +//! +//! let span = expect::span() +//! .named("my_span"); +//! let (subscriber, handle) = subscriber::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 `MockSubscriber` for the duration +//! // of the closure - this is what we are testing. +//! tracing::subscriber::with_default(subscriber, || { +//! 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/subscriber.rs:27", +//! target: "rust_out", +//! level: Level( +//! Info, +//! ), +//! module_path: "rust_out", +//! location: src/subscriber.rs:27, +//! fields: {message}, +//! callsite: Identifier(0x10eda3278), +//! kind: Kind(EVENT), +//! }, +//! parent: Current, +//! }', tracing/tracing-mock/src/expect.rs:59:33 +//! ``` +//! +//! [`Subscriber`]: trait@tracing::Subscriber +//! [`MockSubscriber`]: struct@crate::subscriber::MockSubscriber 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 subscriber which can validate received traces. +/// +/// For a detailed description and examples see the documentation +/// for the methods and the [`subscriber`] module. +/// +/// [`subscriber`]: mod@crate::subscriber pub struct MockSubscriber) -> bool> { expected: VecDeque, max_level: Option, @@ -44,8 +187,67 @@ pub struct MockSubscriber) -> 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 [`subscriber`] +/// module documentation. +/// +/// [`subscriber`]: mod@crate::subscriber pub struct MockHandle(Arc>>, String); +/// Create a new [`MockSubscriber`]. +/// +/// For additional information and examples, see the [`subscriber`] +/// module and [`MockSubscriber`] documentation. +/// +/// # Examples +/// +/// +/// ``` +/// use tracing_mock::{subscriber, expect, field}; +/// +/// let span = expect::span() +/// .named("my_span"); +/// let (subscriber, handle) = subscriber::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 subscriber and handle +/// .run_with_handle(); +/// +/// // Use `with_default` to apply the `MockSubscriber` for the duration +/// // of the closure - this is what we are testing. +/// tracing::subscriber::with_default(subscriber, || { +/// 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(); +/// ``` +/// +/// [`subscriber`]: mod@crate::subscriber +#[must_use] pub fn mock() -> MockSubscriber) -> bool> { MockSubscriber { expected: VecDeque::new(), @@ -75,6 +277,48 @@ 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. + /// + /// # Examples + /// + /// In the following example, we create 2 subscribers, both + /// expecting to receive an event. As we only record a single + /// event, the test will fail: + /// + /// ```should_panic + /// use tracing_mock::{subscriber, expect}; + /// + /// let (subscriber_1, handle_1) = subscriber::mock() + /// .named("subscriber-1") + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// let (subscriber_2, handle_2) = subscriber::mock() + /// .named("subscriber-2") + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// let _guard = tracing::subscriber::set_default(subscriber_2); + /// + /// tracing::subscriber::with_default(subscriber_1, || { + /// tracing::info!("a"); + /// }); + /// + /// handle_1.assert_finished(); + /// handle_2.assert_finished(); + /// ``` + /// + /// In the test output, we see that the subscriber which didn't + /// received the event was the one named `subscriber-2`, which is + /// correct as the subscriber named `subscriber-1` was the default + /// when the event was recorded: + /// + /// ```text + /// [subscriber-2] more notifications expected: [ + /// Event( + /// MockEvent, + /// ), + /// ]', tracing-mock/src/subscriber.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::{subscriber, expect}; + /// + /// let (subscriber, handle) = subscriber::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// tracing::info!("a"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// A span is entered before the event, causing the test to fail: + /// + /// ```should_panic + /// use tracing_mock::{subscriber, expect}; + /// + /// let (subscriber, handle) = subscriber::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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 + /// subscriber 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::{subscriber, 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 (subscriber, handle) = subscriber::mock() + /// .new_span(span) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// _ = 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::{subscriber, 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 (subscriber, handle) = subscriber::mock() + /// .new_span(span) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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::{subscriber, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing"); + /// let (subscriber, handle) = subscriber::mock() + /// .enter(span.clone()) + /// .exit(span) + /// .only() + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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::{subscriber, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing"); + /// let (subscriber, handle) = subscriber::mock() + /// .enter(span.clone()) + /// .exit(span) + /// .only() + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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::{subscriber, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing"); + /// let (subscriber, handle) = subscriber::mock() + /// .enter(span.clone()) + /// .exit(span) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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::{subscriber, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing"); + /// let (subscriber, handle) = subscriber::mock() + /// .enter(span.clone()) + /// .exit(span) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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::{subscriber, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing"); + /// let (subscriber, handle) = subscriber::mock() + /// .clone_span(span) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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::{subscriber, expect}; + /// + /// let span = expect::span() + /// .at_level(tracing::Level::INFO) + /// .named("the span we're testing"); + /// let (subscriber, handle) = subscriber::mock() + /// .clone_span(span) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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 + /// [`Subscriber::drop_span`] will be recorded next. + /// + /// Instead [`Subscriber::try_close`] should be used on the subscriber + /// and should be asserted with `close_span` (which hasn't been + /// implemented yet, but will be done as part of #539). + /// + /// [`Subscriber::drop_span`]: fn@tracing::Subscriber::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::{subscriber, expect}; + /// + /// let cause = expect::span().named("cause"); + /// let consequence = expect::span().named("consequence"); + /// + /// let (subscriber, handle) = subscriber::mock() + /// .follows_from(consequence, cause) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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::{subscriber, expect}; + /// + /// let cause = expect::span().named("cause"); + /// let consequence = expect::span().named("consequence"); + /// + /// let (subscriber, handle) = subscriber::mock() + /// .follows_from(consequence, cause) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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::{subscriber, expect}; + /// + /// let span = expect::span() + /// .named("my_span"); + /// let (subscriber, handle) = subscriber::mock() + /// .record(span, expect::field("parting").with_value(&"goodbye world!")) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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::{subscriber, expect}; + /// + /// let span = expect::span() + /// .named("my_span"); + /// let (subscriber, handle) = subscriber::mock() + /// .record(span, expect::field("parting").with_value(&"goodbye world!")) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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 `MockSubscriber`. + /// + /// 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::{subscriber, expect}; + /// + /// let (subscriber, handle) = subscriber::mock() + /// .with_filter(|meta| meta.level() <= &tracing::Level::WARN) + /// .event(expect::event()) + /// .only() + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// tracing::info!("a"); + /// tracing::warn!("b"); + /// }); + /// + /// handle.assert_finished(); + /// ``` pub fn with_filter(self, filter: G) -> MockSubscriber 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 subscribers, the + /// global filter will be the least restrictive of all subscribers. + /// To filter the events evaluated by a specific `MockSubscriber`, + /// use [`with_filter`] instead. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{subscriber, expect}; + /// + /// let (subscriber, handle) = subscriber::mock() + /// .with_max_level_hint(tracing::Level::INFO) + /// .event(expect::event().at_level(tracing::Level::INFO)) + /// .only() + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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,15 +848,112 @@ 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::{subscriber, expect}; + /// + /// let (subscriber, handle) = subscriber::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// tracing::info!("a"); + /// tracing::info!("b"); + /// tracing::info!("c"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// After including `only`, the test will fail: + /// + /// ```should_panic + /// use tracing_mock::{subscriber, expect}; + /// + /// let (subscriber, handle) = subscriber::mock() + /// .event(expect::event()) + /// .only() + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// 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` [`Subscriber`] which can + /// be set as the default subscriber. + /// + /// 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 subscriber. + /// + /// # Examples + /// + /// The following test is used within the `tracing` + /// codebase: + /// + /// ``` + /// use tracing_mock::subscriber; + /// + /// tracing::subscriber::with_default(subscriber::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); + /// }); + /// ``` + /// + /// [`Subscriber`]: tracing::Subscriber + /// [`run_with_handle`]: fn@Self::run_with_handle pub fn run(self) -> impl Subscriber { - let (collector, _) = self.run_with_handle(); - collector + let (subscriber, _) = self.run_with_handle(); + subscriber } + /// Consume the receiver and return an `impl` [`Subscriber`] which can + /// be set as the default subscriber and a [`MockHandle`] which can + /// be used to validate the provided expectations. + /// + /// # Examples + /// + /// ``` + /// use tracing_mock::{subscriber, expect}; + /// + /// // subscriber and handle are returned from `run_with_handle()` + /// let (subscriber, handle) = subscriber::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// tracing::info!("a"); + /// }); + /// + /// handle.assert_finished(); + /// ``` + /// + /// [`Subscriber`]: tracing::Subscriber pub fn run_with_handle(self) -> (impl Subscriber, MockHandle) { let expected = Arc::new(Mutex::new(self.expected)); let handle = MockHandle(expected.clone(), self.name.clone()); - let collector = Running { + let subscriber = Running { spans: Mutex::new(HashMap::new()), expected, current: Mutex::new(Vec::new()), @@ -171,7 +962,7 @@ where max_level: self.max_level, name: self.name, }; - (collector, handle) + (subscriber, handle) } } @@ -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 + /// [`MockSubscriber`]. + /// + /// 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::{subscriber, expect}; + /// + /// let (subscriber, handle) = subscriber::mock() + /// .event(expect::event()) + /// .run_with_handle(); + /// + /// tracing::subscriber::with_default(subscriber, || { + /// tracing::info!("a"); + /// }); + /// + /// // Check assertions set on the mock subscriber + /// 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, - ), - } - } -}