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