🛈 Note: This is pre-release documentation for the upcoming tracing 0.2.0 ecosystem.

For the release documentation, please see docs.rs, instead.

tracing_subscriber/registry/
sharded.rs

1use sharded_slab::{pool::Ref, Clear, Pool};
2use thread_local::ThreadLocal;
3
4use super::stack::SpanStack;
5use crate::{
6    filter::{FilterId, FilterMap, FilterState},
7    registry::{
8        extensions::{Extensions, ExtensionsInner, ExtensionsMut},
9        LookupSpan, SpanData,
10    },
11    sync::RwLock,
12};
13use std::{
14    cell::{self, Cell, RefCell},
15    sync::atomic::{fence, AtomicUsize, Ordering},
16};
17use tracing_core::{
18    dispatch::{self, Dispatch},
19    span::{self, Current, Id},
20    Collect, Event, Interest, Metadata,
21};
22
23/// A shared, reusable store for spans.
24///
25/// A `Registry` is a [`Collect`] around which multiple subscribers
26/// implementing various behaviors may be [added]. Unlike other types
27/// implementing `Collect`, `Registry` does not actually record traces itself:
28/// instead, it collects and stores span data that is exposed to any [subscriber]s
29/// wrapping it through implementations of the [`LookupSpan`] trait.
30/// The `Registry` is responsible for storing span metadata, recording
31/// relationships between spans, and tracking which spans are active and which
32/// are closed. In addition, it provides a mechanism for [subscriber]s to store
33/// user-defined per-span data, called [extensions], in the registry. This
34/// allows `Subscriber`-specific data to benefit from the `Registry`'s
35/// high-performance concurrent storage.
36///
37/// This registry is implemented using a [lock-free sharded slab][slab], and is
38/// highly optimized for concurrent access.
39///
40/// # Span ID Generation
41///
42/// Span IDs are not globally unique, but the registry ensures that
43/// no two currently active spans have the same ID within a process.
44///
45/// One of the primary responsibilities of the registry is to generate [span
46/// IDs]. Therefore, it's important for other code that interacts with the
47/// registry, such as [subscriber]s, to understand the guarantees of the
48/// span IDs that are generated.
49///
50/// The registry's span IDs are guaranteed to be unique **at a given point
51/// in time**. This means that an active span will never be assigned the
52/// same ID as another **currently active** span. However, the registry
53/// **will** eventually reuse the IDs of [closed] spans, although an ID
54/// will never be reassigned immediately after a span has closed.
55///
56/// Spans are not [considered closed] by the `Registry` until *every*
57/// [`Span`] reference with that ID has been dropped.
58///
59/// Thus: span IDs generated by the registry should be considered unique
60/// only at a given point in time, and only relative to other spans
61/// generated by the same process. Two spans with the same ID will not exist
62/// in the same process concurrently. However, if historical span data is
63/// being stored, the same ID may occur for multiple spans times in that
64/// data. If spans must be uniquely identified in historical data, the user
65/// code storing this data must assign its own unique identifiers to those
66/// spans. A counter is generally sufficient for this.
67///
68/// Similarly, span IDs generated by the registry are not unique outside of
69/// a given process. Distributed tracing systems may require identifiers
70/// that are unique across multiple processes on multiple machines (for
71/// example, [OpenTelemetry's `SpanId`s and `TraceId`s][ot]). `tracing` span
72/// IDs generated by the registry should **not** be used for this purpose.
73/// Instead, code which integrates with a distributed tracing system should
74/// generate and propagate its own IDs according to the rules specified by
75/// the distributed tracing system. These IDs can be associated with
76/// `tracing` spans using [fields] and/or [stored span data].
77///
78/// [span IDs]: https://docs.rs/tracing-core/latest/tracing_core/span/struct.Id.html
79/// [slab]: https://docs.rs/crate/sharded-slab/
80/// [subscriber]: crate::Subscribe
81/// [added]: crate::subscribe::Subscribe#composing-subscribers
82/// [extensions]: super::Extensions
83/// [closed]: https://docs.rs/tracing/latest/tracing/span/index.html#closing-spans
84/// [considered closed]: https://docs.rs/tracing-core/latest/tracing_core/subscriber/trait.Subscriber.html#method.try_close
85/// [`Span`]: https://docs.rs/tracing/latest/tracing/span/struct.Span.html
86/// [ot]: https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/api.md#spancontext
87/// [fields]: https://docs.rs/tracing-core/latest/tracing-core/field/index.html
88/// [stored span data]: crate::registry::SpanData::extensions_mut
89#[cfg(feature = "registry")]
90#[cfg_attr(docsrs, doc(cfg(all(feature = "registry", feature = "std"))))]
91#[derive(Debug)]
92pub struct Registry {
93    spans: Pool<DataInner>,
94    current_spans: ThreadLocal<RefCell<SpanStack>>,
95    next_filter_id: u8,
96}
97
98/// Span data stored in a [`Registry`].
99///
100/// The registry stores well-known data defined by tracing: span relationships,
101/// metadata and reference counts. Additional user-defined data provided by
102/// [`Subscriber`s], such as formatted fields, metrics, or distributed traces should
103/// be stored in the [extensions] typemap.
104///
105/// [`Subscriber`s]: crate::Subscribe
106/// [extensions]: Extensions
107/// [`Registry`]: struct.Registry.html
108#[cfg(feature = "registry")]
109#[cfg_attr(docsrs, doc(cfg(all(feature = "registry", feature = "std"))))]
110#[derive(Debug)]
111pub struct Data<'a> {
112    /// Immutable reference to the pooled `DataInner` entry.
113    inner: Ref<'a, DataInner>,
114}
115
116/// Stored data associated with a span.
117///
118/// This type is pooled using `sharded_slab::Pool`; when a span is dropped, the
119/// `DataInner` entry at that span's slab index is cleared in place and reused
120/// by a future span. Thus, the `Default` and `sharded_slab::Clear`
121/// implementations for this type are load-bearing.
122#[derive(Debug)]
123struct DataInner {
124    filter_map: FilterMap,
125    metadata: &'static Metadata<'static>,
126    parent: Option<Id>,
127    ref_count: AtomicUsize,
128    // The span's `Extensions` typemap. Allocations for the `HashMap` backing
129    // this are pooled and reused in place.
130    pub(crate) extensions: RwLock<ExtensionsInner>,
131}
132
133// === impl Registry ===
134
135impl Default for Registry {
136    fn default() -> Self {
137        Self {
138            spans: Pool::new(),
139            current_spans: ThreadLocal::new(),
140            next_filter_id: 0,
141        }
142    }
143}
144
145#[inline]
146fn idx_to_id(idx: usize) -> Id {
147    Id::from_u64(idx as u64 + 1)
148}
149
150#[inline]
151fn id_to_idx(id: &Id) -> usize {
152    id.into_u64() as usize - 1
153}
154
155/// A guard that tracks how many [`Registry`]-backed `Subscriber`s have
156/// processed an `on_close` event.
157///
158/// This is needed to enable a [`Registry`]-backed Subscriber to access span
159/// data after the subscriber has received the `on_close` callback.
160///
161/// Once all subscribers have processed this event, the [`Registry`] knows
162/// that is able to safely remove the span tracked by `id`. `CloseGuard`
163/// accomplishes this through a two-step process:
164/// 1. Whenever a [`Registry`]-backed `Subscriber::on_close` method is
165///    called, `Registry::start_close` is closed.
166///    `Registry::start_close` increments a thread-local `CLOSE_COUNT`
167///    by 1 and returns a `CloseGuard`.
168/// 2. The `CloseGuard` is dropped at the end of `Subscribe::on_close`. On
169///    drop, `CloseGuard` checks thread-local `CLOSE_COUNT`. If
170///    `CLOSE_COUNT` is 0, the `CloseGuard` removes the span with the
171///    `id` from the registry, as all subscribers that might have seen the
172///    `on_close` notification have processed it. If `CLOSE_COUNT` is
173///    greater than 0, `CloseGuard` decrements the counter by one and
174///    _does not_ remove the span from the [`Registry`].
175///
176pub(crate) struct CloseGuard<'a> {
177    id: Id,
178    registry: &'a Registry,
179    is_closing: bool,
180}
181
182impl Registry {
183    fn get(&self, id: &Id) -> Option<Ref<'_, DataInner>> {
184        self.spans.get(id_to_idx(id))
185    }
186
187    /// Returns a guard which tracks how many `Subscriber`s have
188    /// processed an `on_close` notification via the `CLOSE_COUNT` thread-local.
189    /// For additional details, see [`CloseGuard`].
190    ///
191    pub(crate) fn start_close(&self, id: Id) -> CloseGuard<'_> {
192        CLOSE_COUNT.with(|count| {
193            let c = count.get();
194            count.set(c + 1);
195        });
196        CloseGuard {
197            id,
198            registry: self,
199            is_closing: false,
200        }
201    }
202
203    pub(crate) fn has_per_subscriber_filters(&self) -> bool {
204        self.next_filter_id > 0
205    }
206
207    pub(crate) fn span_stack(&self) -> cell::Ref<'_, SpanStack> {
208        self.current_spans.get_or_default().borrow()
209    }
210}
211
212thread_local! {
213    /// `CLOSE_COUNT` is the thread-local counter used by `CloseGuard` to
214    /// track how many subscribers have processed the close.
215    /// For additional details, see [`CloseGuard`].
216    ///
217    static CLOSE_COUNT: Cell<usize> = const { Cell::new(0) };
218}
219
220impl Collect for Registry {
221    fn register_callsite(&self, _: &'static Metadata<'static>) -> Interest {
222        if self.has_per_subscriber_filters() {
223            return FilterState::take_interest().unwrap_or_else(Interest::always);
224        }
225
226        Interest::always()
227    }
228
229    fn enabled(&self, _: &Metadata<'_>) -> bool {
230        if self.has_per_subscriber_filters() {
231            return FilterState::event_enabled();
232        }
233        true
234    }
235
236    #[inline]
237    fn new_span(&self, attrs: &span::Attributes<'_>) -> span::Id {
238        let parent = if attrs.is_root() {
239            None
240        } else if attrs.is_contextual() {
241            self.current_span().id().map(|id| self.clone_span(id))
242        } else {
243            attrs.parent().map(|id| self.clone_span(id))
244        };
245
246        let id = self
247            .spans
248            // Check out a `DataInner` entry from the pool for the new span. If
249            // there are free entries already allocated in the pool, this will
250            // preferentially reuse one; otherwise, a new `DataInner` is
251            // allocated and added to the pool.
252            .create_with(|data| {
253                data.metadata = attrs.metadata();
254                data.parent = parent;
255                data.filter_map = crate::filter::FILTERING.with(|filtering| filtering.filter_map());
256                #[cfg(debug_assertions)]
257                {
258                    if data.filter_map != FilterMap::new() {
259                        debug_assert!(self.has_per_subscriber_filters());
260                    }
261                }
262
263                let refs = data.ref_count.get_mut();
264                debug_assert_eq!(*refs, 0);
265                *refs = 1;
266            })
267            .expect("Unable to allocate another span");
268        idx_to_id(id)
269    }
270
271    /// This is intentionally not implemented, as recording fields
272    /// on a span is the responsibility of subscribers atop of this registry.
273    #[inline]
274    fn record(&self, _: &span::Id, _: &span::Record<'_>) {}
275
276    fn record_follows_from(&self, _span: &span::Id, _follows: &span::Id) {}
277
278    fn event_enabled(&self, _event: &Event<'_>) -> bool {
279        if self.has_per_subscriber_filters() {
280            return FilterState::event_enabled();
281        }
282        true
283    }
284
285    /// This is intentionally not implemented, as recording events
286    /// is the responsibility of subscribers atop of this registry.
287    fn event(&self, _: &Event<'_>) {}
288
289    fn enter(&self, id: &span::Id) {
290        if self
291            .current_spans
292            .get_or_default()
293            .borrow_mut()
294            .push(id.clone())
295        {
296            self.clone_span(id);
297        }
298    }
299
300    fn exit(&self, id: &span::Id) {
301        if let Some(spans) = self.current_spans.get() {
302            if spans.borrow_mut().pop(id) {
303                dispatch::get_default(|dispatch| dispatch.try_close(id.clone()));
304            }
305        }
306    }
307
308    fn clone_span(&self, id: &span::Id) -> span::Id {
309        let span = self
310            .get(id)
311            .unwrap_or_else(|| panic!("tried to clone {:?}, but no span exists with that ID", id));
312        // Like `std::sync::Arc`, adds to the ref count (on clone) don't require
313        // a strong ordering; if we call` clone_span`, the reference count must
314        // always at least 1. The only synchronization necessary is between
315        // calls to `try_close`: we have to ensure that all threads have
316        // dropped their refs to the span before the span is closed.
317        let refs = span.ref_count.fetch_add(1, Ordering::Relaxed);
318        assert_ne!(
319            refs, 0,
320            "tried to clone a span ({:?}) that already closed",
321            id
322        );
323        id.clone()
324    }
325
326    fn current_span(&self) -> Current {
327        self.current_spans
328            .get()
329            .and_then(|spans| {
330                let spans = spans.borrow();
331                let id = spans.current()?;
332                let span = self.get(id)?;
333                Some(Current::new(id.clone(), span.metadata))
334            })
335            .unwrap_or_else(Current::none)
336    }
337
338    /// Decrements the reference count of the span with the given `id`, and
339    /// removes the span if it is zero.
340    ///
341    /// The allocated span slot will be reused when a new span is created.
342    fn try_close(&self, id: span::Id) -> bool {
343        let span = match self.get(&id) {
344            Some(span) => span,
345            None if std::thread::panicking() => return false,
346            None => panic!("tried to drop a ref to {:?}, but no such span exists!", id),
347        };
348
349        let refs = span.ref_count.fetch_sub(1, Ordering::Release);
350        if !std::thread::panicking() {
351            assert!(refs < usize::MAX, "reference count overflow!");
352        }
353        if refs > 1 {
354            return false;
355        }
356
357        // Synchronize if we are actually removing the span (stolen
358        // from std::Arc); this ensures that all other `try_close` calls on
359        // other threads happen-before we actually remove the span.
360        fence(Ordering::Acquire);
361        true
362    }
363}
364
365impl<'a> LookupSpan<'a> for Registry {
366    type Data = Data<'a>;
367
368    fn span_data(&'a self, id: &Id) -> Option<Self::Data> {
369        let inner = self.get(id)?;
370        Some(Data { inner })
371    }
372
373    fn register_filter(&mut self) -> FilterId {
374        let id = FilterId::new(self.next_filter_id);
375        self.next_filter_id += 1;
376        id
377    }
378}
379
380// === impl CloseGuard ===
381
382impl CloseGuard<'_> {
383    pub(crate) fn set_closing(&mut self) {
384        self.is_closing = true;
385    }
386}
387
388impl Drop for CloseGuard<'_> {
389    fn drop(&mut self) {
390        // If this returns with an error, we are already panicking. At
391        // this point, there's nothing we can really do to recover
392        // except by avoiding a double-panic.
393        let _ = CLOSE_COUNT.try_with(|count| {
394            let c = count.get();
395            // Decrement the count to indicate that _this_ guard's
396            // `on_close` callback has completed.
397            //
398            // Note that we *must* do this before we actually remove the span
399            // from the registry, since dropping the `DataInner` may trigger a
400            // new close, if this span is the last reference to a parent span.
401            count.set(c - 1);
402
403            // If the current close count is 1, this stack frame is the last
404            // `on_close` call. If the span is closing, it's okay to remove the
405            // span.
406            if c == 1 && self.is_closing {
407                self.registry.spans.clear(id_to_idx(&self.id));
408            }
409        });
410    }
411}
412
413// === impl Data ===
414
415impl<'a> SpanData<'a> for Data<'a> {
416    fn id(&self) -> Id {
417        idx_to_id(self.inner.key())
418    }
419
420    fn metadata(&self) -> &'static Metadata<'static> {
421        self.inner.metadata
422    }
423
424    fn parent(&self) -> Option<&Id> {
425        self.inner.parent.as_ref()
426    }
427
428    fn extensions(&self) -> Extensions<'_> {
429        Extensions::new(self.inner.extensions.read().expect("Mutex poisoned"))
430    }
431
432    fn extensions_mut(&self) -> ExtensionsMut<'_> {
433        ExtensionsMut::new(self.inner.extensions.write().expect("Mutex poisoned"))
434    }
435
436    #[inline]
437    fn is_enabled_for(&self, filter: FilterId) -> bool {
438        self.inner.filter_map.is_enabled(filter)
439    }
440}
441
442// === impl DataInner ===
443
444impl Default for DataInner {
445    fn default() -> Self {
446        // Since `DataInner` owns a `&'static Callsite` pointer, we need
447        // something to use as the initial default value for that callsite.
448        // Since we can't access a `DataInner` until it has had actual span data
449        // inserted into it, the null metadata will never actually be accessed.
450        struct NullCallsite;
451        impl tracing_core::callsite::Callsite for NullCallsite {
452            fn set_interest(&self, _: Interest) {
453                unreachable!(
454                    "/!\\ Tried to register the null callsite /!\\\n \
455                    This should never have happened and is definitely a bug. \
456                    A `tracing` bug report would be appreciated."
457                )
458            }
459
460            fn metadata(&self) -> &Metadata<'_> {
461                unreachable!(
462                    "/!\\ Tried to access the null callsite's metadata /!\\\n \
463                    This should never have happened and is definitely a bug. \
464                    A `tracing` bug report would be appreciated."
465                )
466            }
467        }
468
469        static NULL_CALLSITE: NullCallsite = NullCallsite;
470        static NULL_METADATA: Metadata<'static> = tracing_core::metadata! {
471            name: "",
472            target: "",
473            level: tracing_core::Level::TRACE,
474            fields: &[],
475            callsite: &NULL_CALLSITE,
476            kind: tracing_core::metadata::Kind::SPAN,
477        };
478
479        Self {
480            filter_map: FilterMap::new(),
481            metadata: &NULL_METADATA,
482            parent: None,
483            ref_count: AtomicUsize::new(0),
484            extensions: RwLock::new(ExtensionsInner::new()),
485        }
486    }
487}
488
489impl Clear for DataInner {
490    /// Clears the span's data in place, dropping the parent's reference count.
491    fn clear(&mut self) {
492        // A span is not considered closed until all of its children have closed.
493        // Therefore, each span's `DataInner` holds a "reference" to the parent
494        // span, keeping the parent span open until all its children have closed.
495        // When we close a span, we must then decrement the parent's ref count
496        // (potentially, allowing it to close, if this child is the last reference
497        // to that span).
498        // We have to actually unpack the option inside the `get_default`
499        // closure, since it is a `FnMut`, but testing that there _is_ a value
500        // here lets us avoid the thread-local access if we don't need the
501        // dispatcher at all.
502        if self.parent.is_some() {
503            // Note that --- because `Layered::try_close` works by calling
504            // `try_close` on the inner subscriber and using the return value to
505            // determine whether to call the subscriber's `on_close` callback ---
506            // we must call `try_close` on the entire subscriber stack, rather
507            // than just on the registry. If the registry called `try_close` on
508            // itself directly, the subscribers wouldn't see the close notification.
509            let subscriber = dispatch::get_default(Dispatch::clone);
510            if let Some(parent) = self.parent.take() {
511                let _ = subscriber.try_close(parent);
512            }
513        }
514
515        // Clear (but do not deallocate!) the pooled `HashMap` for the span's extensions.
516        self.extensions
517            .get_mut()
518            .unwrap_or_else(|l| {
519                // This function can be called in a `Drop` impl, such as while
520                // panicking, so ignore lock poisoning.
521                l.into_inner()
522            })
523            .clear();
524
525        self.filter_map = FilterMap::new();
526    }
527}
528
529#[cfg(test)]
530mod tests {
531    use super::Registry;
532    use crate::{registry::LookupSpan, subscribe::Context, Subscribe};
533    use std::{
534        collections::HashMap,
535        sync::{Arc, Mutex, Weak},
536    };
537    use tracing::{self, collect::with_default};
538    use tracing_core::{
539        dispatch,
540        span::{Attributes, Id},
541        Collect,
542    };
543
544    struct AssertionSubscriber;
545    impl<C> Subscribe<C> for AssertionSubscriber
546    where
547        C: Collect + for<'a> LookupSpan<'a>,
548    {
549        fn on_close(&self, id: Id, ctx: Context<'_, C>) {
550            dbg!(format_args!("closing {:?}", id));
551            assert!(&ctx.span(&id).is_some());
552        }
553    }
554
555    #[test]
556    fn single_subscriber_can_access_closed_span() {
557        let subscriber = AssertionSubscriber.with_collector(Registry::default());
558
559        with_default(subscriber, || {
560            let span = tracing::debug_span!("span");
561            drop(span);
562        });
563    }
564
565    #[test]
566    fn multiple_subscribers_can_access_closed_span() {
567        let subscriber = AssertionSubscriber
568            .and_then(AssertionSubscriber)
569            .with_collector(Registry::default());
570
571        with_default(subscriber, || {
572            let span = tracing::debug_span!("span");
573            drop(span);
574        });
575    }
576
577    struct CloseSubscriber {
578        inner: Arc<Mutex<CloseState>>,
579    }
580
581    struct CloseHandle {
582        state: Arc<Mutex<CloseState>>,
583    }
584
585    #[derive(Default)]
586    struct CloseState {
587        open: HashMap<&'static str, Weak<()>>,
588        closed: Vec<(&'static str, Weak<()>)>,
589    }
590
591    #[allow(dead_code)] // Field is exercised via checking `Arc::downgrade()`
592    struct SetRemoved(Arc<()>);
593
594    impl<C> Subscribe<C> for CloseSubscriber
595    where
596        C: Collect + for<'a> LookupSpan<'a>,
597    {
598        fn on_new_span(&self, _: &Attributes<'_>, id: &Id, ctx: Context<'_, C>) {
599            let span = ctx.span(id).expect("Missing span; this is a bug");
600            let mut lock = self.inner.lock().unwrap();
601            let is_removed = Arc::new(());
602            assert!(
603                lock.open
604                    .insert(span.name(), Arc::downgrade(&is_removed))
605                    .is_none(),
606                "test subscriber saw multiple spans with the same name, the test is probably messed up"
607            );
608            let mut extensions = span.extensions_mut();
609            extensions.insert(SetRemoved(is_removed));
610        }
611
612        fn on_close(&self, id: Id, ctx: Context<'_, C>) {
613            let span = if let Some(span) = ctx.span(&id) {
614                span
615            } else {
616                println!(
617                    "span {:?} did not exist in `on_close`, are we panicking?",
618                    id
619                );
620                return;
621            };
622            let name = span.name();
623            println!("close {} ({:?})", name, id);
624            if let Ok(mut lock) = self.inner.lock() {
625                if let Some(is_removed) = lock.open.remove(name) {
626                    assert!(is_removed.upgrade().is_some());
627                    lock.closed.push((name, is_removed));
628                }
629            }
630        }
631    }
632
633    impl CloseSubscriber {
634        fn new() -> (Self, CloseHandle) {
635            let state = Arc::new(Mutex::new(CloseState::default()));
636            (
637                Self {
638                    inner: state.clone(),
639                },
640                CloseHandle { state },
641            )
642        }
643    }
644
645    impl CloseState {
646        fn is_open(&self, span: &str) -> bool {
647            self.open.contains_key(span)
648        }
649
650        fn is_closed(&self, span: &str) -> bool {
651            self.closed.iter().any(|(name, _)| name == &span)
652        }
653    }
654
655    impl CloseHandle {
656        fn assert_closed(&self, span: &str) {
657            let lock = self.state.lock().unwrap();
658            assert!(
659                lock.is_closed(span),
660                "expected {} to be closed{}",
661                span,
662                if lock.is_open(span) {
663                    " (it was still open)"
664                } else {
665                    ", but it never existed (is there a problem with the test?)"
666                }
667            )
668        }
669
670        fn assert_open(&self, span: &str) {
671            let lock = self.state.lock().unwrap();
672            assert!(
673                lock.is_open(span),
674                "expected {} to be open{}",
675                span,
676                if lock.is_closed(span) {
677                    " (it was still open)"
678                } else {
679                    ", but it never existed (is there a problem with the test?)"
680                }
681            )
682        }
683
684        fn assert_removed(&self, span: &str) {
685            let lock = self.state.lock().unwrap();
686            let is_removed = match lock.closed.iter().find(|(name, _)| name == &span) {
687                Some((_, is_removed)) => is_removed,
688                None => panic!(
689                    "expected {} to be removed from the registry, but it was not closed {}",
690                    span,
691                    if lock.is_closed(span) {
692                        " (it was still open)"
693                    } else {
694                        ", but it never existed (is there a problem with the test?)"
695                    }
696                ),
697            };
698            assert!(
699                is_removed.upgrade().is_none(),
700                "expected {} to have been removed from the registry",
701                span
702            )
703        }
704
705        fn assert_not_removed(&self, span: &str) {
706            let lock = self.state.lock().unwrap();
707            let is_removed = match lock.closed.iter().find(|(name, _)| name == &span) {
708                Some((_, is_removed)) => is_removed,
709                None if lock.is_open(span) => return,
710                None => unreachable!(),
711            };
712            assert!(
713                is_removed.upgrade().is_some(),
714                "expected {} to have been removed from the registry",
715                span
716            )
717        }
718
719        #[allow(unused)] // may want this for future tests
720        fn assert_last_closed(&self, span: Option<&str>) {
721            let lock = self.state.lock().unwrap();
722            let last = lock.closed.last().map(|(span, _)| span);
723            assert_eq!(
724                last,
725                span.as_ref(),
726                "expected {:?} to have closed last",
727                span
728            );
729        }
730
731        fn assert_closed_in_order(&self, order: impl AsRef<[&'static str]>) {
732            let lock = self.state.lock().unwrap();
733            let order = order.as_ref();
734            for (i, name) in order.iter().enumerate() {
735                assert_eq!(
736                    lock.closed.get(i).map(|(span, _)| span),
737                    Some(name),
738                    "expected close order: {:?}, actual: {:?}",
739                    order,
740                    lock.closed.iter().map(|(name, _)| name).collect::<Vec<_>>()
741                );
742            }
743        }
744    }
745
746    #[test]
747    fn spans_are_removed_from_registry() {
748        let (close_subscriber, state) = CloseSubscriber::new();
749        let subscriber = AssertionSubscriber
750            .and_then(close_subscriber)
751            .with_collector(Registry::default());
752
753        // Create a `Dispatch` (which is internally reference counted) so that
754        // the subscriber lives to the end of the test. Otherwise, if we just
755        // passed the subscriber itself to `with_default`, we could see the span
756        // be dropped when the subscriber itself is dropped, destroying the
757        // registry.
758        let dispatch = dispatch::Dispatch::new(subscriber);
759
760        dispatch::with_default(&dispatch, || {
761            let span = tracing::debug_span!("span1");
762            drop(span);
763            let span = tracing::info_span!("span2");
764            drop(span);
765        });
766
767        state.assert_removed("span1");
768        state.assert_removed("span2");
769
770        // Ensure the registry itself outlives the span.
771        drop(dispatch);
772    }
773
774    #[test]
775    fn spans_are_only_closed_when_the_last_ref_drops() {
776        let (close_subscriber, state) = CloseSubscriber::new();
777        let subscriber = AssertionSubscriber
778            .and_then(close_subscriber)
779            .with_collector(Registry::default());
780
781        // Create a `Dispatch` (which is internally reference counted) so that
782        // the subscriber lives to the end of the test. Otherwise, if we just
783        // passed the subscriber itself to `with_default`, we could see the span
784        // be dropped when the subscriber itself is dropped, destroying the
785        // registry.
786        let dispatch = dispatch::Dispatch::new(subscriber);
787
788        let span2 = dispatch::with_default(&dispatch, || {
789            let span = tracing::debug_span!("span1");
790            drop(span);
791            let span2 = tracing::info_span!("span2");
792            let span2_clone = span2.clone();
793            drop(span2);
794            span2_clone
795        });
796
797        state.assert_removed("span1");
798        state.assert_not_removed("span2");
799
800        drop(span2);
801        state.assert_removed("span1");
802
803        // Ensure the registry itself outlives the span.
804        drop(dispatch);
805    }
806
807    #[test]
808    fn span_enter_guards_are_dropped_out_of_order() {
809        let (close_subscriber, state) = CloseSubscriber::new();
810        let subscriber = AssertionSubscriber
811            .and_then(close_subscriber)
812            .with_collector(Registry::default());
813
814        // Create a `Dispatch` (which is internally reference counted) so that
815        // the subscriber lives to the end of the test. Otherwise, if we just
816        // passed the subscriber itself to `with_default`, we could see the span
817        // be dropped when the subscriber itself is dropped, destroying the
818        // registry.
819        let dispatch = dispatch::Dispatch::new(subscriber);
820
821        dispatch::with_default(&dispatch, || {
822            let span1 = tracing::debug_span!("span1");
823            let span2 = tracing::info_span!("span2");
824
825            let enter1 = span1.enter();
826            let enter2 = span2.enter();
827
828            drop(enter1);
829            drop(span1);
830
831            state.assert_removed("span1");
832            state.assert_not_removed("span2");
833
834            drop(enter2);
835            state.assert_not_removed("span2");
836
837            drop(span2);
838            state.assert_removed("span1");
839            state.assert_removed("span2");
840        });
841    }
842
843    #[test]
844    fn child_closes_parent() {
845        // This test asserts that if a parent span's handle is dropped before
846        // a child span's handle, the parent will remain open until child
847        // closes, and will then be closed.
848
849        let (close_subscriber, state) = CloseSubscriber::new();
850        let subscriber = close_subscriber.with_collector(Registry::default());
851
852        let dispatch = dispatch::Dispatch::new(subscriber);
853
854        dispatch::with_default(&dispatch, || {
855            let span1 = tracing::info_span!("parent");
856            let span2 = tracing::info_span!(parent: &span1, "child");
857
858            state.assert_open("parent");
859            state.assert_open("child");
860
861            drop(span1);
862            state.assert_open("parent");
863            state.assert_open("child");
864
865            drop(span2);
866            state.assert_closed("parent");
867            state.assert_closed("child");
868        });
869    }
870
871    #[test]
872    fn child_closes_grandparent() {
873        // This test asserts that, when a span is kept open by a child which
874        // is *itself* kept open by a child, closing the grandchild will close
875        // both the parent *and* the grandparent.
876        let (close_subscriber, state) = CloseSubscriber::new();
877        let subscriber = close_subscriber.with_collector(Registry::default());
878
879        let dispatch = dispatch::Dispatch::new(subscriber);
880
881        dispatch::with_default(&dispatch, || {
882            let span1 = tracing::info_span!("grandparent");
883            let span2 = tracing::info_span!(parent: &span1, "parent");
884            let span3 = tracing::info_span!(parent: &span2, "child");
885
886            state.assert_open("grandparent");
887            state.assert_open("parent");
888            state.assert_open("child");
889
890            drop(span1);
891            drop(span2);
892            state.assert_open("grandparent");
893            state.assert_open("parent");
894            state.assert_open("child");
895
896            drop(span3);
897
898            state.assert_closed_in_order(["child", "parent", "grandparent"]);
899        });
900    }
901}