tracing_timing/
layer.rs

1use super::*;
2use hdrhistogram::SyncHistogram;
3use indexmap::IndexMap;
4use std::hash::Hash;
5use std::sync::atomic;
6
7/// Timing-gathering tracing layer.
8///
9/// This type is constructed using a [`Builder`].
10///
11/// See the [crate-level docs] for details.
12///
13pub struct TimingLayer<S = group::ByName, E = group::ByMessage>
14where
15    S: SpanGroup,
16    S::Id: Hash + Eq,
17    E: EventGroup,
18    E::Id: Hash + Eq,
19{
20    timing: Timing<S, E>,
21}
22
23impl<S, E> std::fmt::Debug for TimingLayer<S, E>
24where
25    S: SpanGroup + std::fmt::Debug,
26    S::Id: Hash + Eq + std::fmt::Debug,
27    E: EventGroup + std::fmt::Debug,
28    E::Id: Hash + Eq + std::fmt::Debug,
29{
30    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
31        f.debug_struct("TimingLayer")
32            .field("timing", &self.timing)
33            .finish()
34    }
35}
36
37impl<S, E> TimingLayer<S, E>
38where
39    S: SpanGroup,
40    E: EventGroup,
41    S::Id: Hash + Eq,
42    E::Id: Hash + Eq,
43{
44    pub(crate) fn new(timing: Timing<S, E>) -> Self {
45        Self { timing }
46    }
47
48    /// Force all current timing information to be refreshed immediately.
49    ///
50    /// Note that this will interrupt all concurrent metrics gathering until it returns.
51    pub fn force_synchronize(&self) {
52        self.timing.force_synchronize()
53    }
54
55    /// Access the timing histograms.
56    ///
57    /// Be aware that the contained histograms are not automatically updated to reflect recently
58    /// gathered samples. For each histogram you wish to read from, you must call `refresh` or
59    /// `refresh_timeout` to gather up-to-date samples.
60    ///
61    /// For information about what you can do with the histograms, see the [`hdrhistogram`
62    /// documentation].
63    ///
64    ///   [`hdrhistogram` documentation]: https://docs.rs/hdrhistogram/
65    pub fn with_histograms<F, R>(&self, f: F) -> R
66    where
67        F: FnOnce(&mut HashMap<S::Id, IndexMap<E::Id, SyncHistogram<u64>, Hasher>>) -> R,
68    {
69        self.timing.with_histograms(f)
70    }
71}
72
73impl<S, SG, EG> tracing_subscriber::Layer<S> for TimingLayer<SG, EG>
74where
75    S: Subscriber + for<'span> tracing_subscriber::registry::LookupSpan<'span>,
76    Self: 'static,
77    SG: SpanGroup,
78    EG: EventGroup,
79    SG::Id: Clone + Hash + Eq + Send + Sync,
80    EG::Id: Clone + Hash + Eq + Send + Sync,
81{
82    fn on_new_span(
83        &self,
84        attrs: &span::Attributes,
85        id: &span::Id,
86        ctx: tracing_subscriber::layer::Context<S>,
87    ) {
88        let group = self.timing.span_group.group(attrs);
89        self.timing.ensure_group(group.clone());
90        let span = ctx.span(id).unwrap();
91        span.extensions_mut().insert(SpanState {
92            group,
93            last_event: atomic::AtomicU64::new(self.timing.time.raw()),
94        });
95    }
96
97    fn on_event(&self, event: &Event, ctx: tracing_subscriber::layer::Context<S>) {
98        let span = event
99            .parent()
100            .cloned()
101            .or_else(|| ctx.current_span().id().cloned());
102        if let Some(id) = span {
103            let current = ctx.span(&id);
104            self.timing.time(event, |on_each| {
105                if let Some(ref span) = current {
106                    {
107                        let ext = span.extensions();
108                        if !on_each(ext.get::<SpanState<SG::Id>>().unwrap()) {
109                            return;
110                        }
111                    }
112
113                    for span in span.scope().skip(1) {
114                        let ext = span.extensions();
115                        if !on_each(ext.get::<SpanState<SG::Id>>().unwrap()) {
116                            break;
117                        }
118                    }
119                }
120            });
121        } else {
122            // recorded free-standing event -- ignoring
123        }
124    }
125
126    fn on_close(&self, id: span::Id, ctx: tracing_subscriber::layer::Context<'_, S>) {
127        if self.timing.span_close_events {
128            let span = ctx.span(&id).expect("Span not found, this is a bug");
129            let meta = span.metadata();
130            let fs = field::FieldSet::new(&["message"], meta.callsite());
131            let fld = fs.iter().next().unwrap();
132            let v = [(&fld, Some(&"close" as &dyn field::Value))];
133            let vs = fs.value_set(&v);
134            let e = Event::new_child_of(id, meta, &vs);
135            self.timing.time(&e, |on_each| {
136                {
137                    let ext = span.extensions();
138                    if !on_each(ext.get::<SpanState<SG::Id>>().unwrap()) {
139                        return;
140                    }
141                }
142
143                for span in span.scope().skip(1) {
144                    let ext = span.extensions();
145                    if !on_each(ext.get::<SpanState<SG::Id>>().unwrap()) {
146                        break;
147                    }
148                }
149            });
150        }
151    }
152}
153
154/// A convenience type for getting access to [`TimingLayer`] through a `Dispatch`.
155///
156/// See [`TimingLayer::downcaster`].
157#[derive(Debug, Copy)]
158pub struct Downcaster<S, E> {
159    phantom: PhantomData<fn(S, E)>,
160}
161
162impl<S, E> Clone for Downcaster<S, E> {
163    fn clone(&self) -> Self {
164        Self {
165            phantom: PhantomData,
166        }
167    }
168}
169
170impl<S, E> TimingLayer<S, E>
171where
172    S: SpanGroup,
173    E: EventGroup,
174    S::Id: Clone + Hash + Eq,
175    E::Id: Clone + Hash + Eq,
176{
177    /// Returns an identifier that can later be used to get access to this [`TimingLayer`]
178    /// after it has been turned into a `tracing::Dispatch`.
179    ///
180    /// ```rust
181    /// use tracing::*;
182    /// use tracing_timing::{Builder, Histogram, TimingLayer};
183    /// use tracing_subscriber::{registry::Registry, Layer};
184    /// let layer = Builder::default()
185    ///     .layer(|| Histogram::new_with_max(1_000_000, 2).unwrap());
186    /// let downcaster = layer.downcaster();
187    /// let dispatch = Dispatch::new(layer.with_subscriber(Registry::default()));
188    /// // ...
189    /// // code that hands off clones of the dispatch
190    /// // maybe to other threads
191    /// // ...
192    /// downcaster.downcast(&dispatch).unwrap().with_histograms(|hs| {
193    ///     for (span_group, hs) in hs {
194    ///         for (event_group, h) in hs {
195    ///             // make sure we see the latest samples:
196    ///             h.refresh();
197    ///             // print the median:
198    ///             println!("{} -> {}: {}ns", span_group, event_group, h.value_at_quantile(0.5))
199    ///         }
200    ///     }
201    /// });
202    /// ```
203    ///
204    pub fn downcaster(&self) -> Downcaster<S, E> {
205        Downcaster {
206            phantom: PhantomData,
207        }
208    }
209}
210
211impl<S, E> Downcaster<S, E>
212where
213    S: SpanGroup + 'static,
214    E: EventGroup + 'static,
215    S::Id: Clone + Hash + Eq + 'static,
216    E::Id: Clone + Hash + Eq + 'static,
217{
218    /// Retrieve a reference to this ident's original [`TimingLayer`].
219    ///
220    /// This method returns `None` if the given `Dispatch` is not holding a layer of the same
221    /// type as this ident was created from.
222    pub fn downcast<'a>(&self, d: &'a Dispatch) -> Option<&'a TimingLayer<S, E>> {
223        d.downcast_ref()
224    }
225}
tracing_timing/layer.rs

tracing_timing/
layer.rs
