mock: differentiate between mocks and expectations (tokio-rs#2373)

The `tracing-mock` crate provides a mock collector (and a subscriber for
use by the tests in the `tracing-subscriber` crate) which is able to
make assertions about what diagnostics are emitted.

These assertions are defined by structs that match on events, span, and
their fields and metadata. The structs that matched these objects have
been called, up until now, mocks, however this terminology may be
misleading, as the created objects don't mock anything.

There were two different names for similar functionality with `only()`
and `done()` on fields and collectors/subscribers respectively. Using a
single name for these may make it easier to onboard onto `tracing-mock`.

To reduce confusion, these structs have been split into two categories:
mocks and expectations.

Additionally, the `done()` function on the `Collector` and `Subscriber`
mocks has been replaced with `only()`. This matches the similar function
for `ExpectedField`, and may be more intuitive.

The mocks replace some component in the tracing ecosystem when a library
is under test. The expectations define the assertions we wish to make
about traces received by the mocks.

Mocks (per module):
* collector - `MockCollector`, no change
* subscriber - `MockSubscriber`, renamed from `ExpectSubscriber`

Expectations (per module):
* event - `ExpectedEvent`, renamed from `MockEvent`
* span - `ExpectedSpan`, renamed from `MockSpan`
* field - `ExpectedField` and `ExpectedFields`, renamed from `MockField`
  and `Expected`. Also `ExpectedValue` renamed from `MockValue`.
* metadata - `ExpectedMetadata`, renamed from `Expected`

Refs: tokio-rs#539

tracing-attributes/tests/err.rs

@@ -56,6 +56,27 @@ fn test_early_return() {
     handle.assert_finished();
 }
 
+#[instrument(err)]
+fn err_early_return() -> Result<u8, TryFromIntError> {
+    u8::try_from(1234)?;
+    Ok(5)
+}
+
+#[test]
+fn test_early_return() {
+    let span = span::expect().named("err_early_return");
+    let (subscriber, handle) = subscriber::mock()
+        .new_span(span.clone())
+        .enter(span.clone())
+        .event(event::expect().at_level(Level::ERROR))
+        .exit(span.clone())
+        .drop_span(span)
+        .only()
+        .run_with_handle();
+    with_default(subscriber, || err_early_return().ok());
+    handle.assert_finished();
+}
+
 #[instrument(err)]
 async fn err_async(polls: usize) -> Result<u8, TryFromIntError> {
     let future = PollN::new_ok(polls);

tracing-attributes/tests/levels.rs

@@ -158,22 +158,22 @@ fn enum_levels() {
     #[instrument(level = Level::ERROR)]
     fn error() {}
     let (subscriber, handle) = subscriber::mock()
-        .new_span(span::mock().named("trace").at_level(Level::TRACE))
-        .enter(span::mock().named("trace").at_level(Level::TRACE))
-        .exit(span::mock().named("trace").at_level(Level::TRACE))
-        .new_span(span::mock().named("debug").at_level(Level::DEBUG))
-        .enter(span::mock().named("debug").at_level(Level::DEBUG))
-        .exit(span::mock().named("debug").at_level(Level::DEBUG))
-        .new_span(span::mock().named("info").at_level(Level::INFO))
-        .enter(span::mock().named("info").at_level(Level::INFO))
-        .exit(span::mock().named("info").at_level(Level::INFO))
-        .new_span(span::mock().named("warn").at_level(Level::WARN))
-        .enter(span::mock().named("warn").at_level(Level::WARN))
-        .exit(span::mock().named("warn").at_level(Level::WARN))
-        .new_span(span::mock().named("error").at_level(Level::ERROR))
-        .enter(span::mock().named("error").at_level(Level::ERROR))
-        .exit(span::mock().named("error").at_level(Level::ERROR))
-        .done()
+        .new_span(span::expect().named("trace").at_level(Level::TRACE))
+        .enter(span::expect().named("trace").at_level(Level::TRACE))
+        .exit(span::expect().named("trace").at_level(Level::TRACE))
+        .new_span(span::expect().named("debug").at_level(Level::DEBUG))
+        .enter(span::expect().named("debug").at_level(Level::DEBUG))
+        .exit(span::expect().named("debug").at_level(Level::DEBUG))
+        .new_span(span::expect().named("info").at_level(Level::INFO))
+        .enter(span::expect().named("info").at_level(Level::INFO))
+        .exit(span::expect().named("info").at_level(Level::INFO))
+        .new_span(span::expect().named("warn").at_level(Level::WARN))
+        .enter(span::expect().named("warn").at_level(Level::WARN))
+        .exit(span::expect().named("warn").at_level(Level::WARN))
+        .new_span(span::expect().named("error").at_level(Level::ERROR))
+        .enter(span::expect().named("error").at_level(Level::ERROR))
+        .exit(span::expect().named("error").at_level(Level::ERROR))
+        .only()
         .run_with_handle();
 
     with_default(subscriber, || {

tracing-attributes/tests/ret.rs

@@ -69,22 +69,22 @@ fn test_custom_target() {
 #[test]
 fn test_custom_target() {
     let filter: EnvFilter = "my_target=info".parse().expect("filter should parse");
-    let span = span::mock()
+    let span = span::expect()
         .named("ret_with_target")
         .with_target("my_target");
 
     let (subscriber, handle) = subscriber::mock()
         .new_span(span.clone())
         .enter(span.clone())
         .event(
-            event::mock()
-                .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
+            event::expect()
+                .with_fields(field::expect("return").with_value(&tracing::field::debug(42)))
                 .at_level(Level::INFO)
                 .with_target("my_target"),
         )
         .exit(span.clone())
         .drop_span(span)
-        .done()
+        .only()
         .run_with_handle();
 
     let subscriber = subscriber.with(filter);
@@ -342,18 +342,18 @@ fn ret_warn_info() -> i32 {
 
 #[test]
 fn test_warn_info() {
-    let span = span::mock().named("ret_warn_info").at_level(Level::WARN);
+    let span = span::expect().named("ret_warn_info").at_level(Level::WARN);
     let (subscriber, handle) = subscriber::mock()
         .new_span(span.clone())
         .enter(span.clone())
         .event(
-            event::mock()
-                .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
+            event::expect()
+                .with_fields(field::expect("return").with_value(&tracing::field::debug(42)))
                 .at_level(Level::INFO),
         )
         .exit(span.clone())
         .drop_span(span)
-        .done()
+        .only()
         .run_with_handle();
 
     with_default(subscriber, ret_warn_info);
@@ -367,18 +367,18 @@ fn ret_dbg_warn() -> i32 {
 
 #[test]
 fn test_dbg_warn() {
-    let span = span::mock().named("ret_dbg_warn").at_level(Level::INFO);
+    let span = span::expect().named("ret_dbg_warn").at_level(Level::INFO);
     let (subscriber, handle) = subscriber::mock()
         .new_span(span.clone())
         .enter(span.clone())
         .event(
-            event::mock()
-                .with_fields(field::mock("return").with_value(&tracing::field::debug(42)))
+            event::expect()
+                .with_fields(field::expect("return").with_value(&tracing::field::debug(42)))
                 .at_level(Level::WARN),
         )
         .exit(span.clone())
         .drop_span(span)
-        .done()
+        .only()
         .run_with_handle();
 
     with_default(subscriber, ret_dbg_warn);

tracing-mock/src/expectation.rs

@@ -1,21 +1,21 @@
 use crate::{
-    event::MockEvent,
-    field,
-    span::{MockSpan, NewSpan},
+    event::ExpectedEvent,
+    field::ExpectedFields,
+    span::{ExpectedSpan, NewSpan},
 };
 
 #[derive(Debug, Eq, PartialEq)]
 pub(crate) enum Expect {
-    Event(MockEvent),
+    Event(ExpectedEvent),
     FollowsFrom {
-        consequence: MockSpan,
-        cause: MockSpan,
+        consequence: ExpectedSpan,
+        cause: ExpectedSpan,
     },
-    Enter(MockSpan),
-    Exit(MockSpan),
-    CloneSpan(MockSpan),
-    DropSpan(MockSpan),
-    Visit(MockSpan, field::Expect),
+    Enter(ExpectedSpan),
+    Exit(ExpectedSpan),
+    CloneSpan(ExpectedSpan),
+    DropSpan(ExpectedSpan),
+    Visit(ExpectedSpan, ExpectedFields),
     NewSpan(NewSpan),
     Nothing,
 }

tracing-mock/src/layer.rs

@@ -1,7 +1,9 @@
+#![allow(missing_docs, dead_code)]
 use crate::{
-    event::MockEvent,
+    event::ExpectedEvent,
     expectation::Expect,
-    span::{MockSpan, NewSpan},
+    field::ExpectedFields,
+    span::{ExpectedSpan, NewSpan},
     subscriber::MockHandle,
 };
 use tracing_core::{
@@ -19,7 +21,6 @@ use std::{
     sync::{Arc, Mutex},
 };
 
-#[must_use]
 pub fn mock() -> MockLayerBuilder {
     MockLayerBuilder {
         expected: Default::default(),
@@ -30,7 +31,6 @@ pub fn mock() -> MockLayerBuilder {
     }
 }
 
-#[must_use]
 pub fn named(name: impl std::fmt::Display) -> MockLayerBuilder {
     mock().named(name)
 }
@@ -47,6 +47,19 @@ pub struct MockLayer {
 }
 
 impl MockLayerBuilder {
+    /// Overrides the name printed by the mock layer's debugging output.
+    ///
+    /// The debugging output is displayed if the test panics, or if the test is
+    /// run with `--nocapture`.
+    ///
+    /// By default, the mock layer'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 layer, this is sufficient. However,
+    /// some tests may include multiple layers, in order to test
+    /// interactions between multiple layers. In that case, it can be
+    /// helpful to give each layer a separate name to distinguish where the
+    /// debugging output comes from.
     pub fn named(mut self, name: impl fmt::Display) -> Self {
         use std::fmt::Write;
         if !self.name.is_empty() {
@@ -57,31 +70,39 @@ impl MockLayerBuilder {
         self
     }
 
-    pub fn event(mut self, event: MockEvent) -> Self {
+    pub fn enter(mut self, span: ExpectedSpan) -> Self {
+        self.expected.push_back(Expect::Enter(span));
+        self
+    }
+
+    pub fn event(mut self, event: ExpectedEvent) -> Self {
         self.expected.push_back(Expect::Event(event));
         self
     }
 
-    pub fn new_span<I>(mut self, new_span: I) -> Self
-    where
-        I: Into<NewSpan>,
-    {
-        self.expected.push_back(Expect::NewSpan(new_span.into()));
+    pub fn exit(mut self, span: ExpectedSpan) -> Self {
+        self.expected.push_back(Expect::Exit(span));
         self
     }
 
-    pub fn enter(mut self, span: MockSpan) -> Self {
-        self.expected.push_back(Expect::Enter(span));
+    pub fn only(mut self) -> Self {
+        self.expected.push_back(Expect::Nothing);
         self
     }
 
-    pub fn exit(mut self, span: MockSpan) -> Self {
-        self.expected.push_back(Expect::Exit(span));
+    pub fn record<I>(mut self, span: ExpectedSpan, fields: I) -> Self
+    where
+        I: Into<ExpectedFields>,
+    {
+        self.expected.push_back(Expect::Visit(span, fields.into()));
         self
     }
 
-    pub fn done(mut self) -> Self {
-        self.expected.push_back(Expect::Nothing);
+    pub fn new_span<I>(mut self, new_span: I) -> Self
+    where
+        I: Into<NewSpan>,
+    {
+        self.expected.push_back(Expect::NewSpan(new_span.into()));
         self
     }
 
@@ -96,19 +117,19 @@ impl MockLayerBuilder {
     pub fn run_with_handle(self) -> (MockLayer, MockHandle) {
         let expected = Arc::new(Mutex::new(self.expected));
         let handle = MockHandle::new(expected.clone(), self.name.clone());
-        let subscriber = MockLayer {
+        let layer = MockLayer {
             expected,
             name: self.name,
             current: Mutex::new(Vec::new()),
         };
-        (subscriber, handle)
+        (layer, handle)
     }
 }
 
 impl MockLayer {
     fn check_span_ref<'spans, S>(
         &self,
-        expected: &MockSpan,
+        expected: &ExpectedSpan,
         actual: &SpanRef<'spans, S>,
         what_happened: impl fmt::Display,
     ) where
@@ -238,11 +259,7 @@ where
     }
 
     fn on_follows_from(&self, _span: &Id, _follows: &Id, _: Context<'_, C>) {
-        unimplemented!(
-            "so far, we don't have any tests that need an `on_follows_from` \
-            implementation.\nif you just wrote one that does, feel free to \
-            implement it!"
-        );
+        // TODO: it should be possible to expect spans to follow from other spans
     }
 
     fn on_new_span(&self, span: &Attributes<'_>, id: &Id, cx: Context<'_, C>) {
@@ -360,13 +377,13 @@ where
     }
 
     fn on_id_change(&self, _old: &Id, _new: &Id, _ctx: Context<'_, C>) {
-        panic!("well-behaved subscribers should never do this to us, lol");
+        panic!("well-behaved Layers should never do this to us, lol");
     }
 }
 
 impl fmt::Debug for MockLayer {
     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
-        let mut s = f.debug_struct("MockLayer");
+        let mut s = f.debug_struct("Expectlayer");
         s.field("name", &self.name);
 
         if let Ok(expected) = self.expected.try_lock() {

tracing-subscriber/tests/cached_layer_filters_dont_break_other_layers.rs

@@ -107,20 +107,20 @@ fn filter() -> LevelFilter {
 
 fn unfiltered(name: &str) -> (MockLayer, subscriber::MockHandle) {
     layer::named(name)
-        .event(event::mock().at_level(Level::TRACE))
-        .event(event::mock().at_level(Level::DEBUG))
-        .event(event::mock().at_level(Level::INFO))
-        .event(event::mock().at_level(Level::WARN))
-        .event(event::mock().at_level(Level::ERROR))
-        .done()
+        .event(event::expect().at_level(Level::TRACE))
+        .event(event::expect().at_level(Level::DEBUG))
+        .event(event::expect().at_level(Level::INFO))
+        .event(event::expect().at_level(Level::WARN))
+        .event(event::expect().at_level(Level::ERROR))
+        .only()
         .run_with_handle()
 }
 
 fn filtered(name: &str) -> (MockLayer, subscriber::MockHandle) {
     layer::named(name)
-        .event(event::mock().at_level(Level::INFO))
-        .event(event::mock().at_level(Level::WARN))
-        .event(event::mock().at_level(Level::ERROR))
-        .done()
+        .event(event::expect().at_level(Level::INFO))
+        .event(event::expect().at_level(Level::WARN))
+        .event(event::expect().at_level(Level::ERROR))
+        .only()
         .run_with_handle()
 }