fedimint_core/
timing.rs

1use std::borrow::Cow;
2use std::time;
3
4use fedimint_logging::LOG_TIMING;
5use tracing::{debug, info, trace, warn, Level};
6
7/// Data inside `TimeReporter`, in another struct to be able to move it out of
8/// without violating `drop` consistency
9struct TimeReporterInner {
10    name: Cow<'static, str>,
11    level: Level,
12    start: time::SystemTime,
13    threshold: Option<time::Duration>,
14}
15
16impl TimeReporterInner {
17    fn report(&self) {
18        let duration = crate::time::now()
19            .duration_since(self.start)
20            .map_err(|error| {
21                warn!(
22                    target: LOG_TIMING,
23                    %error,
24                    "Timer reporter duration overflow. This should not happen."
25                );
26                error
27            })
28            .unwrap_or_default();
29
30        // even `event!` doesn't support non-constant values, so we have to do a match
31        // here
32        let duration_ms = duration.as_millis();
33        match self.level {
34            Level::TRACE => {
35                trace!(
36                    target: LOG_TIMING,
37                    name = %self.name,
38                    duration_ms,
39                    "Operation timing"
40                );
41            }
42            Level::DEBUG => {
43                debug!(
44                    target: LOG_TIMING,
45                    name = %self.name,
46                    duration_ms,
47                    "Operation timing"
48                );
49            }
50            Level::INFO => {
51                info!(
52                    target: LOG_TIMING,
53                    name = %self.name,
54                    duration_ms,
55                    "Operation timing"
56                );
57            }
58            // anything else is just a warn, whatever; it's long enough
59            _ => {
60                warn!(
61                    target: LOG_TIMING,
62                    name = %self.name,
63                    duration_ms,
64                    "Operation timing"
65                );
66            }
67        }
68        if let Some(threshold) = self.threshold {
69            if duration < threshold {
70                warn!(
71                    target: LOG_TIMING,
72                    name = %self.name,
73                    duration_ms = duration.as_millis(),
74                    threshold_ms = threshold.as_millis(),
75                    "Operation time exceeded threshold"
76                );
77            }
78        }
79    }
80}
81
82pub struct TimeReporter {
83    /// Inner data
84    ///
85    /// If `None`, time reported has been moved out from and is now a no-op
86    inner: Option<TimeReporterInner>,
87}
88
89impl TimeReporter {
90    pub fn new(name: impl Into<Cow<'static, str>>) -> Self {
91        Self {
92            inner: Some(TimeReporterInner {
93                name: name.into(),
94                level: Level::DEBUG,
95                start: crate::time::now(),
96                threshold: None,
97            }),
98        }
99    }
100
101    pub fn level(mut self, level: tracing::Level) -> Self {
102        Self {
103            inner: self
104                .inner
105                .take()
106                .map(|inner| TimeReporterInner { level, ..inner }),
107        }
108    }
109
110    /// Add a threshold, which will log a warning if exceeded
111    pub fn threshold(mut self, threshold: time::Duration) -> Self {
112        Self {
113            inner: self.inner.take().map(|inner| TimeReporterInner {
114                threshold: Some(threshold),
115                ..inner
116            }),
117        }
118    }
119
120    /// Handy alias for [`Self::threshold`]
121    pub fn threshold_millis(self, millis: u64) -> Self {
122        self.threshold(time::Duration::from_millis(millis))
123    }
124
125    pub fn info(self) -> Self {
126        self.level(Level::INFO)
127    }
128
129    pub fn cancel(&mut self) {
130        self.inner.take();
131    }
132
133    pub fn finish(self) {
134        /* drop */
135    }
136}
137
138impl Drop for TimeReporter {
139    fn drop(&mut self) {
140        if let Some(inner) = self.inner.take() {
141            inner.report();
142        }
143    }
144}
fedimint_core/timing.rs

fedimint_core/
timing.rs
