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!("{:?}", ¤t));
1021 } else {
1022 s.field("current", &format_args!("<locked>"));
1023 }
1024
1025 s.finish()
1026 }
1027}