zebra_chain/
diagnostic.rs

Help
1//! Diagnostic types and functions for Zebra:
2//! - code performance
3//! - task handling
4//! - errors and panics
5
6pub mod task;
7
8// Tracing the execution time of functions.
9//
10// TODO:
11// - move this to a `timing` submodule
12// - also trace polling time for futures, using a `Future` wrapper
13
14use std::time::{Duration, Instant};
15
16use crate::fmt::duration_short;
17
18/// The default minimum info-level message time.
19///
20/// This is high enough to ignore most slow code.
21pub const DEFAULT_MIN_INFO_TIME: Duration = Duration::from_secs(5 * 60);
22
23/// The default minimum warning message time.
24///
25/// This is a little lower than the block verify timeout.
26pub const DEFAULT_MIN_WARN_TIME: Duration = Duration::from_secs(9 * 60);
27
28/// A guard that logs code execution time when dropped.
29#[derive(Debug)]
30pub struct CodeTimer {
31    /// The time that the code started executing.
32    start: Instant,
33
34    /// The minimum duration for info-level messages.
35    min_info_time: Duration,
36
37    /// The minimum duration for warning messages.
38    min_warn_time: Duration,
39
40    /// `true` if this timer has finished.
41    has_finished: bool,
42}
43
44impl CodeTimer {
45    /// Start timing the execution of a function, method, or other code region.
46    ///
47    /// Returns a guard that finishes timing the code when dropped,
48    /// or when [`CodeTimer::finish()`] is called.
49    #[track_caller]
50    pub fn start() -> Self {
51        let start = Instant::now();
52        trace!(
53            target: "run time",
54            ?start,
55            "started code timer",
56        );
57
58        Self {
59            start,
60            min_info_time: DEFAULT_MIN_INFO_TIME,
61            min_warn_time: DEFAULT_MIN_WARN_TIME,
62            has_finished: false,
63        }
64    }
65
66    /// Finish timing the execution of a function, method, or other code region.
67    pub fn finish<S>(
68        mut self,
69        module_path: &'static str,
70        line: u32,
71        description: impl Into<Option<S>>,
72    ) where
73        S: ToString,
74    {
75        self.finish_inner(Some(module_path), Some(line), description);
76    }
77
78    /// Ignore this timer: it will not check the elapsed time or log any warnings.
79    pub fn ignore(mut self) {
80        self.has_finished = true;
81    }
82
83    /// Finish timing the execution of a function, method, or other code region.
84    ///
85    /// This private method can be called from [`CodeTimer::finish()`] or `drop()`.
86    fn finish_inner<S>(
87        &mut self,
88        module_path: impl Into<Option<&'static str>>,
89        line: impl Into<Option<u32>>,
90        description: impl Into<Option<S>>,
91    ) where
92        S: ToString,
93    {
94        if self.has_finished {
95            return;
96        }
97
98        self.has_finished = true;
99
100        let execution = self.start.elapsed();
101        let time = duration_short(execution);
102        let time = time.as_str();
103
104        let module = module_path.into().unwrap_or_default();
105
106        let line = line.into().map(|line| line.to_string()).unwrap_or_default();
107        let line = line.as_str();
108
109        let description = description
110            .into()
111            .map(|desc| desc.to_string())
112            .unwrap_or_default();
113
114        if execution >= self.min_warn_time {
115            warn!(
116                target: "run time",
117                %time,
118                %module,
119                %line,
120                "very long {description}",
121            );
122        } else if execution >= self.min_info_time {
123            info!(
124                target: "run time",
125                %time,
126                %module,
127                %line,
128                "long {description}",
129            );
130        } else {
131            trace!(
132                target: "run time",
133                %time,
134                %module,
135                %line,
136                "finished {description} code timer",
137            );
138        }
139    }
140}
141
142impl Drop for CodeTimer {
143    fn drop(&mut self) {
144        self.finish_inner(None, None, "(dropped, cancelled, or aborted)")
145    }
146}
zebra_chain/diagnostic.rs

zebra_chain/
diagnostic.rs
