tracing_mock/
layer.rs

1//! An implementation of the [`Layer`] trait which validates that
2//! the `tracing` data it receives matches the expected output for a test.
3//!
4//!
5//! The [`MockLayer`] is the central component in these tools. The
6//! `MockLayer` has expectations set on it which are later
7//! validated as the code under test is run.
8//!
9//! ```
10//! use tracing_mock::{expect, layer};
11//! use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
12//!
13//! let (layer, handle) = layer::mock()
14//!     // Expect a single event with a specified message
15//!     .event(expect::event().with_fields(expect::msg("droids")))
16//!     .run_with_handle();
17//!
18//! // Use `set_default` to apply the `MockSubscriber` until the end
19//! // of the current scope (when the guard `_subscriber` is dropped).
20//! let _subscriber =  tracing_subscriber::registry()
21//!     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
22//!     .set_default();
23//!
24//! // These *are* the droids we are looking for
25//! tracing::info!("droids");
26//!
27//! // Use the handle to check the assertions. This line will panic if an
28//! // assertion is not met.
29//! handle.assert_finished();
30//! ```
31//!
32//! A more complex example may consider multiple spans and events with
33//! their respective fields:
34//!
35//! ```
36//! use tracing_mock::{expect, layer};
37//! use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
38//!
39//! let span = expect::span()
40//!     .named("my_span");
41//! let (layer, handle) = layer::mock()
42//!     // Enter a matching span
43//!     .enter(&span)
44//!     // Record an event with message "collect parting message"
45//!     .event(expect::event().with_fields(expect::msg("say hello")))
46//!     // Exit a matching span
47//!     .exit(&span)
48//!     // Expect no further messages to be recorded
49//!     .only()
50//!     // Return the layer and handle
51//!     .run_with_handle();
52//!
53//! // Use `set_default` to apply the `MockLayers` until the end
54//! // of the current scope (when the guard `_subscriber` is dropped).
55//! let _subscriber = tracing_subscriber::registry()
56//!     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
57//!     .set_default();
58//!
59//! {
60//!     let span = tracing::trace_span!(
61//!         "my_span",
62//!         greeting = "hello world",
63//!     );
64//!
65//!     let _guard = span.enter();
66//!     tracing::info!("say hello");
67//! }
68//!
69//! // Use the handle to check the assertions. This line will panic if an
70//! // assertion is not met.
71//! handle.assert_finished();
72//! ```
73//!
74//! If we modify the previous example so that we **don't** enter the
75//! span before recording an event, the test will fail:
76//!
77//! ```should_panic
78//! use tracing_mock::{expect, layer};
79//! use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};  
80//!
81//! let span = expect::span()
82//!     .named("my_span");
83//! let (layer, handle) = layer::mock()
84//!     // Enter a matching span
85//!     .enter(&span)
86//!     // Record an event with message "collect parting message"
87//!     .event(expect::event().with_fields(expect::msg("say hello")))
88//!     // Exit a matching span
89//!     .exit(&span)
90//!     // Expect no further messages to be recorded
91//!     .only()
92//!     // Return the subscriber and handle
93//!     .run_with_handle();
94//!
95//! // Use `set_default` to apply the `MockSubscriber` until the end
96//! // of the current scope (when the guard `_subscriber` is dropped).
97//! let _subscriber =  tracing_subscriber::registry()
98//!     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
99//!     .set_default();
100//!
101//! {
102//!     let span = tracing::trace_span!(
103//!         "my_span",
104//!         greeting = "hello world",
105//!     );
106//!
107//!     // Don't enter the span.
108//!     // let _guard = span.enter();
109//!     tracing::info!("say hello");
110//! }
111//!
112//! // Use the handle to check the assertions. This line will panic if an
113//! // assertion is not met.
114//! handle.assert_finished();
115//! ```
116//!
117//! [`Layer`]: trait@tracing_subscriber::layer::Layer
118use std::{
119    collections::VecDeque,
120    fmt,
121    sync::{Arc, Mutex},
122};
123
124use tracing_core::{
125    span::{Attributes, Id, Record},
126    Event, Subscriber,
127};
128use tracing_subscriber::{
129    layer::{Context, Layer},
130    registry::{LookupSpan, SpanRef},
131};
132
133use crate::{
134    ancestry::{get_ancestry, ActualAncestry, HasAncestry},
135    event::ExpectedEvent,
136    expect::Expect,
137    span::{ActualSpan, ExpectedSpan, NewSpan},
138    subscriber::MockHandle,
139};
140
141/// Create a [`MockLayerBuilder`] used to construct a
142/// [`MockLayer`].
143///
144/// For additional information and examples, see the [`layer`]
145/// module and [`MockLayerBuilder`] documentation.
146///
147/// # Examples
148///
149/// ```
150/// use tracing_mock::{expect, layer};
151/// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
152///
153/// let span = expect::span()
154///     .named("my_span");
155/// let (layer, handle) = layer::mock()
156///     // Enter a matching span
157///     .enter(&span)
158///     // Record an event with message "collect parting message"
159///     .event(expect::event().with_fields(expect::msg("say hello")))
160///     // Exit a matching span
161///     .exit(&span)
162///     // Expect no further messages to be recorded
163///     .only()
164///     // Return the subscriber and handle
165///     .run_with_handle();
166///
167/// // Use `set_default` to apply the `MockSubscriber` until the end
168/// // of the current scope (when the guard `_subscriber` is dropped).
169/// let _subscriber =  tracing_subscriber::registry()
170///     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
171///     .set_default();
172///
173/// {
174///     let span = tracing::trace_span!(
175///         "my_span",
176///         greeting = "hello world",
177///     );
178///
179///     let _guard = span.enter();
180///     tracing::info!("say hello");
181/// }
182///
183/// // Use the handle to check the assertions. This line will panic if an
184/// // assertion is not met.
185/// handle.assert_finished();
186/// ```
187///
188/// [`layer`]: mod@crate::layer
189#[must_use]
190pub fn mock() -> MockLayerBuilder {
191    MockLayerBuilder {
192        expected: Default::default(),
193        name: std::thread::current()
194            .name()
195            .map(String::from)
196            .unwrap_or_default(),
197    }
198}
199
200/// Create a [`MockLayerBuilder`] with a name already set.
201///
202/// This constructor is equivalent to calling
203/// [`MockLayerBuilder::named`] in the following way"
204/// `layer::mock().named(name)`.
205///
206/// For additional information and examples, see the [`layer`]
207/// module and [`MockLayerBuilder`] documentation.
208///
209/// # Examples
210///
211/// The example from [`MockLayerBuilder::named`] could be rewritten as:
212///
213/// ```should_panic
214/// use tracing_mock::{expect, layer};
215/// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
216///
217/// let (layer_1, handle_1) = layer::named("subscriber-1")
218///     .event(expect::event())
219///     .run_with_handle();
220///
221/// let (layer_2, handle_2) = layer::named("subscriber-2")
222///     .event(expect::event())
223///     .run_with_handle();
224///
225/// let _subscriber =  tracing_subscriber::registry()
226///     .with(
227///         layer_2.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true))
228///     )
229///     .set_default();
230/// {
231///     let _subscriber =  tracing_subscriber::registry()
232///         .with(
233///             layer_1
234///                 .with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true))
235///         )
236///         .set_default();
237///
238///     tracing::info!("a");
239/// }
240///
241/// handle_1.assert_finished();
242/// handle_2.assert_finished();
243/// ```
244///
245/// [`MockLayerBuilder::named`]: fn@crate::layer::MockLayerBuilder::named
246/// [`layer`]: mod@crate::layer
247#[must_use]
248pub fn named(name: impl std::fmt::Display) -> MockLayerBuilder {
249    mock().named(name)
250}
251
252/// A builder for constructing [`MockLayer`]s.
253///
254/// The methods on this builder set expectations which are then
255/// validated by the constructed [`MockLayer`].
256///
257/// For a detailed description and examples see the documentation
258/// for the methods and the [`layer`] module.
259///
260/// [`layer`]: mod@crate::layer
261
262#[derive(Debug)]
263pub struct MockLayerBuilder {
264    expected: VecDeque<Expect>,
265    name: String,
266}
267
268/// A layer which validates the traces it receives.
269///
270/// A `MockLayer` is constructed with a
271/// [`MockLayerBuilder`]. For a detailed description and examples,
272/// see the documentation for that struct and for the [`layer`]
273/// module.
274///
275/// [`layer`]: mod@crate::layer
276pub struct MockLayer {
277    expected: Arc<Mutex<VecDeque<Expect>>>,
278    current: Mutex<Vec<Id>>,
279    name: String,
280}
281
282impl MockLayerBuilder {
283    /// Overrides the name printed by the mock layer's debugging output.
284    ///
285    /// The debugging output is displayed if the test panics, or if the test is
286    /// run with `--nocapture`.
287    ///
288    /// By default, the mock layer's name is the  name of the test
289    /// (*technically*, the name of the thread where it was created, which is
290    /// the name of the test unless tests are run with `--test-threads=1`).
291    /// When a test has only one mock layer, this is sufficient. However,
292    /// some tests may include multiple layers, in order to test
293    /// interactions between multiple layers. In that case, it can be
294    /// helpful to give each layers a separate name to distinguish where the
295    /// debugging output comes from.
296    ///
297    /// # Examples
298    ///
299    /// In the following example, we create two layers, both
300    /// expecting to receive an event. As we only record a single
301    /// event, the test will fail:
302    ///
303    /// ```should_panic
304    /// use tracing_mock::{layer, expect};
305    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
306    ///
307    /// let (layer_1, handle_1) = layer::mock()
308    ///     .named("layer-1")
309    ///     .event(expect::event())
310    ///     .run_with_handle();
311    ///
312    /// let (layer_2, handle_2) = layer::mock()
313    ///     .named("layer-2")
314    ///     .event(expect::event())
315    ///     .run_with_handle();
316    ///
317    /// let _subscriber =  tracing_subscriber::registry()
318    ///     .with(
319    ///         layer_2.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true))
320    ///     )
321    ///     .set_default();
322    /// {
323    ///     let _subscriber =  tracing_subscriber::registry()
324    ///         .with(
325    ///             layer_1
326    ///                 .with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true))
327    ///         )
328    ///         .set_default();
329    ///
330    ///     tracing::info!("a");
331    /// }
332    ///
333    /// handle_1.assert_finished();
334    /// handle_2.assert_finished();
335    /// ```
336    ///
337    /// In the test output, we see that the layer which didn't
338    /// received the event was the one named `layer-2`, which is
339    /// correct as the layer named `layer-1` was the default
340    /// when the event was recorded:
341    ///
342    /// ```text
343    /// [main::layer-2] more notifications expected: [
344    ///     Event(
345    ///         MockEvent,
346    ///     ),
347    /// ]', tracing-mock/src/subscriber.rs:472:13
348    /// ```
349    pub fn named(mut self, name: impl fmt::Display) -> Self {
350        use std::fmt::Write;
351        if !self.name.is_empty() {
352            write!(&mut self.name, "::{}", name).unwrap();
353        } else {
354            self.name = name.to_string();
355        }
356        self
357    }
358
359    /// Adds an expectation that an event matching the [`ExpectedEvent`]
360    /// will be recorded next.
361    ///
362    /// The `event` can be a default mock which will match any event
363    /// (`expect::event()`) or can include additional expectations.
364    /// See the [`ExpectedEvent`] documentation for more details.
365    ///
366    /// If an event is recorded that doesn't match the `ExpectedEvent`,
367    /// or if something else (such as entering a span) is recorded
368    /// first, then the expectation will fail.
369    ///
370    /// # Examples
371    ///
372    /// ```
373    /// use tracing_mock::{expect, layer};
374    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
375    ///
376    /// let (layer, handle) = layer::mock()
377    ///     .event(expect::event())
378    ///     .run_with_handle();
379    ///
380    /// let _subscriber = tracing_subscriber::registry()
381    ///     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
382    ///     .set_default();
383    ///
384    /// tracing::info!("event");
385    ///
386    /// handle.assert_finished();
387    /// ```
388    ///
389    /// A span is entered before the event, causing the test to fail:
390    ///
391    /// ```should_panic
392    /// use tracing_mock::{expect, layer};
393    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
394    ///
395    /// let (layer, handle) = layer::mock()
396    ///     .event(expect::event())
397    ///     .run_with_handle();
398    ///
399    /// let _subscriber =  tracing_subscriber::registry()
400    ///     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
401    ///     .set_default();
402    ///
403    /// let span = tracing::info_span!("span");
404    /// let _guard = span.enter();
405    /// tracing::info!("event");
406    ///
407    /// handle.assert_finished();
408    /// ```
409    pub fn event(mut self, event: ExpectedEvent) -> Self {
410        self.expected.push_back(Expect::Event(event));
411        self
412    }
413
414    /// Adds an expectation that the creation of a span will be
415    /// recorded next.
416    ///
417    /// This function accepts `Into<NewSpan>` instead of
418    /// [`ExpectedSpan`] directly. [`NewSpan`] can be used to test
419    /// span fields and the span ancestry.
420    ///
421    /// The new span doesn't need to be entered for this expectation
422    /// to succeed.
423    ///
424    /// If a span is recorded that doesn't match the `ExpectedSpan`,
425    /// or if something else (such as an event) is recorded first,
426    /// then the expectation will fail.
427    ///
428    /// # Examples
429    ///
430    /// ```
431    /// use tracing_mock::{expect, layer};
432    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
433    ///
434    /// let span = expect::span()
435    ///     .at_level(tracing::Level::INFO)
436    ///     .named("the span we're testing")
437    ///     .with_fields(expect::field("testing").with_value(&"yes"));
438    /// let (layer, handle) = layer::mock()
439    ///     .new_span(span)
440    ///     .run_with_handle();
441    ///
442    /// let _subscriber =  tracing_subscriber::registry()
443    ///     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
444    ///     .set_default();
445    ///
446    /// _ = tracing::info_span!("the span we're testing", testing = "yes");
447    ///
448    /// handle.assert_finished();
449    /// ```
450    ///
451    /// An event is recorded before the span is created, causing the
452    /// test to fail:
453    ///
454    /// ```should_panic
455    /// use tracing_mock::{expect, layer};
456    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
457    ///
458    /// let span = expect::span()
459    ///     .at_level(tracing::Level::INFO)
460    ///     .named("the span we're testing")
461    ///     .with_fields(expect::field("testing").with_value(&"yes"));
462    /// let (layer, handle) = layer::mock()
463    ///     .new_span(span)
464    ///     .run_with_handle();
465    ///
466    /// let _subscriber =  tracing_subscriber::registry()
467    ///     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
468    ///     .set_default();
469    ///
470    /// tracing::info!("an event");
471    /// _ = tracing::info_span!("the span we're testing", testing = "yes");
472    ///
473    /// handle.assert_finished();
474    /// ```
475    ///
476    /// [`ExpectedSpan`]: struct@crate::span::ExpectedSpan
477    /// [`NewSpan`]: struct@crate::span::NewSpan
478    pub fn new_span<I>(mut self, new_span: I) -> Self
479    where
480        I: Into<NewSpan>,
481    {
482        self.expected.push_back(Expect::NewSpan(new_span.into()));
483        self
484    }
485
486    /// Adds an expectation that entering a span matching the
487    /// [`ExpectedSpan`] will be recorded next.
488    ///
489    /// This expectation is generally accompanied by a call to
490    /// [`exit`], since an entered span will typically be exited. If used
491    /// together with [`only`], this is likely necessary, because the span
492    /// will be dropped before the test completes (except in rare cases,
493    /// such as if [`std::mem::forget`] is used).
494    ///
495    /// If the span that is entered doesn't match the [`ExpectedSpan`],
496    /// or if something else (such as an event) is recorded first,
497    /// then the expectation will fail.
498    ///
499    /// # Examples
500    ///
501    /// ```
502    /// use tracing_mock::{expect, layer};
503    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
504    ///
505    /// let span = expect::span()
506    ///     .at_level(tracing::Level::INFO)
507    ///     .named("the span we're testing");
508    /// let (layer, handle) = layer::mock()
509    ///     .enter(&span)
510    ///     .exit(&span)
511    ///     .only()
512    ///     .run_with_handle();
513    ///
514    /// let _subscriber =  tracing_subscriber::registry()
515    ///     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
516    ///     .set_default();
517    ///
518    /// {
519    ///     let span = tracing::info_span!("the span we're testing");
520    ///     let _entered = span.enter();
521    /// }
522    ///
523    /// handle.assert_finished();
524    /// ```
525    ///
526    /// An event is recorded before the span is entered, causing the
527    /// test to fail:
528    ///
529    /// ```should_panic
530    /// use tracing_mock::{expect, layer};
531    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
532    ///
533    /// let span = expect::span()
534    ///     .at_level(tracing::Level::INFO)
535    ///     .named("the span we're testing");
536    /// let (layer, handle) = layer::mock()
537    ///     .enter(&span)
538    ///     .exit(&span)
539    ///     .only()
540    ///     .run_with_handle();
541    ///
542    /// let _subscriber =  tracing_subscriber::registry()
543    ///     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
544    ///     .set_default();
545    ///
546    /// {
547    ///     tracing::info!("an event");
548    ///     let span = tracing::info_span!("the span we're testing");
549    ///     let _entered = span.enter();
550    /// }
551    ///
552    /// handle.assert_finished();
553    /// ```
554    ///
555    /// [`exit`]: fn@Self::exit
556    /// [`only`]: fn@Self::only
557    pub fn enter<S>(mut self, span: S) -> Self
558    where
559        S: Into<ExpectedSpan>,
560    {
561        self.expected.push_back(Expect::Enter(span.into()));
562        self
563    }
564
565    /// Adds an expectation that exiting a span matching the
566    /// [`ExpectedSpan`] will be recorded next.
567    ///
568    /// As a span may be entered and exited multiple times,
569    /// this is different from the span being closed. In
570    /// general [`enter`] and `exit` should be paired.
571    ///
572    /// If the span that is exited doesn't match the [`ExpectedSpan`],
573    /// or if something else (such as an event) is recorded first,
574    /// then the expectation will fail.
575    ///
576    /// **Note**: Ensure that the guard returned by [`Span::enter`]
577    /// is dropped before calling [`MockHandle::assert_finished`].
578    ///
579    /// # Examples
580    ///
581    /// ```
582    /// use tracing_mock::{expect, layer};
583    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
584    ///
585    /// let span = expect::span()
586    ///     .at_level(tracing::Level::INFO)
587    ///     .named("the span we're testing");
588    /// let (layer, handle) = layer::mock()
589    ///     .enter(&span)
590    ///     .exit(&span)
591    ///     .only()
592    ///     .run_with_handle();
593    ///
594    /// let _subscriber =  tracing_subscriber::registry()
595    ///     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
596    ///     .set_default();
597    /// {
598    ///     let span = tracing::info_span!("the span we're testing");
599    ///     let _entered = span.enter();
600    /// }
601    ///
602    /// handle.assert_finished();
603    /// ```
604    ///
605    /// An event is recorded before the span is exited, causing the
606    /// test to fail:
607    ///
608    /// ```should_panic
609    /// use tracing_mock::{expect, layer};
610    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
611    ///
612    /// let span = expect::span()
613    ///     .at_level(tracing::Level::INFO)
614    ///     .named("the span we're testing");
615    /// let (layer, handle) = layer::mock()
616    ///     .enter(&span)
617    ///     .exit(&span)
618    ///     .only()
619    ///     .run_with_handle();
620    ///
621    /// let _subscriber =  tracing_subscriber::registry()
622    ///     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
623    ///     .set_default();
624    ///
625    /// {
626    ///     let span = tracing::info_span!("the span we're testing");
627    ///     let _entered = span.enter();
628    ///     tracing::info!("an event");
629    /// }
630    ///
631    /// handle.assert_finished();
632    /// ```
633    ///
634    /// [`enter`]: fn@Self::enter
635    /// [`MockHandle::assert_finished`]: fn@crate::subscriber::MockHandle::assert_finished
636    /// [`Span::enter`]: fn@tracing::Span::enter
637    pub fn exit<S>(mut self, span: S) -> Self
638    where
639        S: Into<ExpectedSpan>,
640    {
641        self.expected.push_back(Expect::Exit(span.into()));
642        self
643    }
644
645    /// Expects that no further traces are received.
646    ///
647    /// The call to `only` should appear immediately before the final
648    /// call to [`run`] or [`run_with_handle`], as any expectations which
649    /// are added after `only` will not be considered.
650    ///
651    /// # Examples
652    ///
653    /// Consider this simple test. It passes even though we only
654    /// expect a single event, but receive three:
655    ///
656    /// ```
657    /// use tracing_mock::{expect, layer};
658    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
659    ///
660    /// let (layer, handle) = layer::mock()
661    ///     .event(expect::event())
662    ///     .run_with_handle();
663    ///
664    /// let _subscriber = tracing_subscriber::registry()
665    ///     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
666    ///     .set_default();
667    ///
668    /// tracing::info!("a");
669    /// tracing::info!("b");
670    /// tracing::info!("c");
671    ///
672    /// handle.assert_finished();
673    /// ```
674    ///
675    /// After including `only`, the test will fail:
676    ///
677    /// ```should_panic
678    /// use tracing_mock::{expect, layer};
679    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
680    ///
681    /// let (layer, handle) = layer::mock()
682    ///     .event(expect::event())
683    ///     .only()
684    ///     .run_with_handle();
685    ///
686    /// let _subscriber =  tracing_subscriber::registry()
687    ///     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
688    ///     .set_default();
689    ///
690    /// tracing::info!("a");
691    /// tracing::info!("b");
692    /// tracing::info!("c");
693    ///
694    /// handle.assert_finished();
695    /// ```
696    ///
697    /// [`run`]: fn@Self::run
698    /// [`run_with_handle`]: fn@Self::run_with_handle
699    pub fn only(mut self) -> Self {
700        self.expected.push_back(Expect::Nothing);
701        self
702    }
703
704    /// Consume this builder and return a [`MockLayer`] which can
705    /// be set as the default subscriber.
706    ///
707    /// This function is similar to [`run_with_handle`], but it doesn't
708    /// return a [`MockHandle`]. This is useful if the desired
709    /// assertions can be checked externally to the subscriber.
710    ///
711    /// # Examples
712    ///
713    /// The following test is used within the `tracing-subscriber`
714    /// codebase:
715    ///
716    /// ```
717    /// use tracing::Subscriber;
718    /// use tracing_mock::layer;
719    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
720    ///
721    /// let unfiltered = layer::named("unfiltered").run().boxed();
722    /// let info = layer::named("info")
723    ///     .run()
724    ///     .with_filter(tracing_core::LevelFilter::INFO)
725    ///     .boxed();
726    /// let debug = layer::named("debug")
727    ///     .run()
728    ///     .with_filter(tracing_core::LevelFilter::DEBUG)
729    ///     .boxed();
730    ///
731    /// let subscriber = tracing_subscriber::registry().with(vec![unfiltered, info, debug]);
732    ///
733    /// assert_eq!(subscriber.max_level_hint(), None);
734    /// ```
735    ///
736    /// [`MockHandle`]: struct@crate::subscriber::MockHandle
737    /// [`run_with_handle`]: fn@Self::run_with_handle
738    pub fn run(self) -> MockLayer {
739        MockLayer {
740            expected: Arc::new(Mutex::new(self.expected)),
741            name: self.name,
742            current: Mutex::new(Vec::new()),
743        }
744    }
745
746    /// Consume this builder and return a [`MockLayer`] which can
747    /// be set as the default subscriber and a [`MockHandle`] which can
748    /// be used to validate the provided expectations.
749    ///
750    /// # Examples
751    ///
752    /// ```
753    /// use tracing_mock::{expect, layer};
754    /// use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer};
755    ///
756    /// let (layer, handle) = layer::mock()
757    ///     .event(expect::event())
758    ///     .run_with_handle();
759    ///
760    /// let _subscriber =  tracing_subscriber::registry()
761    ///     .with(layer.with_filter(tracing_subscriber::filter::filter_fn(move |_meta| true)))
762    ///     .set_default();
763    ///
764    /// tracing::info!("event");
765    ///
766    /// handle.assert_finished();
767    /// ```
768    ///
769    /// [`MockHandle`]: struct@crate::subscriber::MockHandle
770    /// [`MockLayer`]: struct@crate::layer::MockLayer
771    pub fn run_with_handle(self) -> (MockLayer, MockHandle) {
772        let expected = Arc::new(Mutex::new(self.expected));
773        let handle = MockHandle::new(expected.clone(), self.name.clone());
774        let subscriber = MockLayer {
775            expected,
776            name: self.name,
777            current: Mutex::new(Vec::new()),
778        };
779        (subscriber, handle)
780    }
781}
782
783impl<'a, S> From<&SpanRef<'a, S>> for ActualSpan
784where
785    S: LookupSpan<'a>,
786{
787    fn from(span_ref: &SpanRef<'a, S>) -> Self {
788        Self::new(span_ref.id(), Some(span_ref.metadata()))
789    }
790}
791
792impl MockLayer {
793    fn check_event_scope<C>(
794        &self,
795        current_scope: Option<tracing_subscriber::registry::Scope<'_, C>>,
796        expected_scope: &mut [ExpectedSpan],
797    ) where
798        C: for<'lookup> tracing_subscriber::registry::LookupSpan<'lookup>,
799    {
800        let mut current_scope = current_scope.into_iter().flatten();
801        let mut i = 0;
802        for (expected, actual) in expected_scope.iter_mut().zip(&mut current_scope) {
803            println!(
804                "[{}] event_scope[{}] actual={} ({:?}); expected={}",
805                self.name,
806                i,
807                actual.name(),
808                actual.id(),
809                expected
810            );
811            expected.check(
812                &(&actual).into(),
813                format_args!("the {}th span in the event's scope to be", i),
814                &self.name,
815            );
816            i += 1;
817        }
818        let remaining_expected = &expected_scope[i..];
819        assert!(
820            remaining_expected.is_empty(),
821            "\n[{}] did not observe all expected spans in event scope!\n[{}] missing: {:#?}",
822            self.name,
823            self.name,
824            remaining_expected,
825        );
826        assert!(
827            current_scope.next().is_none(),
828            "\n[{}] did not expect all spans in the actual event scope!",
829            self.name,
830        );
831    }
832}
833
834impl<C> Layer<C> for MockLayer
835where
836    C: Subscriber + for<'a> LookupSpan<'a>,
837{
838    fn register_callsite(
839        &self,
840        metadata: &'static tracing::Metadata<'static>,
841    ) -> tracing_core::Interest {
842        println!("[{}] register_callsite {:#?}", self.name, metadata);
843        tracing_core::Interest::always()
844    }
845
846    fn on_record(&self, _: &Id, _: &Record<'_>, _: Context<'_, C>) {
847        unimplemented!(
848            "so far, we don't have any tests that need an `on_record` \
849            implementation.\nif you just wrote one that does, feel free to \
850            implement it!"
851        );
852    }
853
854    fn on_event(&self, event: &Event<'_>, cx: Context<'_, C>) {
855        let name = event.metadata().name();
856        println!(
857            "[{}] event: {}; level: {}; target: {}",
858            self.name,
859            name,
860            event.metadata().level(),
861            event.metadata().target(),
862        );
863        match self.expected.lock().unwrap().pop_front() {
864            None => {}
865            Some(Expect::Event(mut expected)) => {
866                expected.check(event, || context_get_ancestry(event, &cx), &self.name);
867
868                if let Some(expected_scope) = expected.scope_mut() {
869                    self.check_event_scope(cx.event_scope(event), expected_scope);
870                }
871            }
872            Some(ex) => ex.bad(&self.name, format_args!("observed event {:#?}", event)),
873        }
874    }
875
876    fn on_follows_from(&self, _span: &Id, _follows: &Id, _: Context<'_, C>) {
877        unimplemented!(
878            "so far, we don't have any tests that need an `on_follows_from` \
879            implementation.\nif you just wrote one that does, feel free to \
880            implement it!"
881        );
882    }
883
884    fn on_new_span(&self, span: &Attributes<'_>, id: &Id, cx: Context<'_, C>) {
885        let meta = span.metadata();
886        println!(
887            "[{}] new_span: name={:?}; target={:?}; id={:?};",
888            self.name,
889            meta.name(),
890            meta.target(),
891            id
892        );
893        let mut expected = self.expected.lock().unwrap();
894        let was_expected = matches!(expected.front(), Some(Expect::NewSpan(_)));
895        if was_expected {
896            if let Expect::NewSpan(mut expected) = expected.pop_front().unwrap() {
897                expected.check(span, || context_get_ancestry(span, &cx), &self.name);
898            }
899        }
900    }
901
902    fn on_enter(&self, id: &Id, cx: Context<'_, C>) {
903        let span = cx
904            .span(id)
905            .unwrap_or_else(|| panic!("[{}] no span for ID {:?}", self.name, id));
906        println!("[{}] enter: {}; id={:?};", self.name, span.name(), id);
907        match self.expected.lock().unwrap().pop_front() {
908            None => {}
909            Some(Expect::Enter(ref expected_span)) => {
910                expected_span.check(&(&span).into(), "to enter", &self.name);
911            }
912            Some(ex) => ex.bad(&self.name, format_args!("entered span {:?}", span.name())),
913        }
914        self.current.lock().unwrap().push(id.clone());
915    }
916
917    fn on_exit(&self, id: &Id, cx: Context<'_, C>) {
918        if std::thread::panicking() {
919            // `exit()` can be called in `drop` impls, so we must guard against
920            // double panics.
921            println!("[{}] exit {:?} while panicking", self.name, id);
922            return;
923        }
924        let span = cx
925            .span(id)
926            .unwrap_or_else(|| panic!("[{}] no span for ID {:?}", self.name, id));
927        println!("[{}] exit: {}; id={:?};", self.name, span.name(), id);
928        match self.expected.lock().unwrap().pop_front() {
929            None => {}
930            Some(Expect::Exit(ref expected_span)) => {
931                expected_span.check(&(&span).into(), "to exit", &self.name);
932                let curr = self.current.lock().unwrap().pop();
933                assert_eq!(
934                    Some(id),
935                    curr.as_ref(),
936                    "[{}] exited span {:?}, but the current span was {:?}",
937                    self.name,
938                    span.name(),
939                    curr.as_ref().and_then(|id| cx.span(id)).map(|s| s.name())
940                );
941            }
942            Some(ex) => ex.bad(&self.name, format_args!("exited span {:?}", span.name())),
943        };
944    }
945
946    fn on_close(&self, id: Id, cx: Context<'_, C>) {
947        if std::thread::panicking() {
948            // `try_close` can be called in `drop` impls, so we must guard against
949            // double panics.
950            println!("[{}] close {:?} while panicking", self.name, id);
951            return;
952        }
953        let span = cx.span(&id);
954        let name = span.as_ref().map(|span| {
955            println!("[{}] close_span: {}; id={:?};", self.name, span.name(), id,);
956            span.name()
957        });
958        if name.is_none() {
959            println!("[{}] drop_span: id={:?}", self.name, id);
960        }
961        if let Ok(mut expected) = self.expected.try_lock() {
962            let was_expected = match expected.front() {
963                Some(Expect::DropSpan(ref expected_span)) => {
964                    // Don't assert if this function was called while panicking,
965                    // as failing the assertion can cause a double panic.
966                    if !::std::thread::panicking() {
967                        if let Some(ref span) = span {
968                            expected_span.check(&span.into(), "to close a span", &self.name);
969                        }
970                    }
971                    true
972                }
973                Some(Expect::Event(_)) => {
974                    if !::std::thread::panicking() {
975                        panic!(
976                            "[{}] expected an event, but dropped span {} (id={:?}) instead",
977                            self.name,
978                            name.unwrap_or("<unknown name>"),
979                            id
980                        );
981                    }
982                    true
983                }
984                _ => false,
985            };
986            if was_expected {
987                expected.pop_front();
988            }
989        }
990    }
991
992    fn on_id_change(&self, _old: &Id, _new: &Id, _ctx: Context<'_, C>) {
993        panic!("well-behaved subscribers should never do this to us, lol");
994    }
995}
996
997fn context_get_ancestry<C>(item: impl HasAncestry, ctx: &Context<'_, C>) -> ActualAncestry
998where
999    C: Subscriber + for<'a> LookupSpan<'a>,
1000{
1001    get_ancestry(
1002        item,
1003        || ctx.lookup_current().map(|s| s.id()),
1004        |span_id| ctx.span(span_id).map(|span| (&span).into()),
1005    )
1006}
1007
1008impl fmt::Debug for MockLayer {
1009    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1010        let mut s = f.debug_struct("ExpectSubscriber");
1011        s.field("name", &self.name);
1012
1013        if let Ok(expected) = self.expected.try_lock() {
1014            s.field("expected", &expected);
1015        } else {
1016            s.field("expected", &format_args!("<locked>"));
1017        }
1018
1019        if let Ok(current) = self.current.try_lock() {
1020            s.field("current", &format_args!("{:?}", &current));
1021        } else {
1022            s.field("current", &format_args!("<locked>"));
1023        }
1024
1025        s.finish()
1026    }
1027}