zebra_chain/
diagnostic.rs

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    /// The description configured when the timer is started.
41    description: &'static str,
42
43    /// `true` if this timer has finished.
44    has_finished: bool,
45}
46
47impl CodeTimer {
48    /// Start timing the execution of a function, method, or other code region.
49    ///
50    /// See [`CodeTimer::start_desc`] for more details.
51    #[track_caller]
52    pub fn start() -> Self {
53        Self::start_desc("")
54    }
55
56    /// Start timing the execution of a function, method, or other code region.
57    ///
58    /// Returns a guard that finishes timing the code when dropped,
59    /// or when [`CodeTimer::finish_inner()`] is called with an empty description.
60    #[track_caller]
61    pub fn start_desc(description: &'static str) -> Self {
62        let start = Instant::now();
63        trace!(
64            target: "run time",
65            ?start,
66            "started code timer",
67        );
68
69        Self {
70            start,
71            description,
72            min_info_time: DEFAULT_MIN_INFO_TIME,
73            min_warn_time: DEFAULT_MIN_WARN_TIME,
74            has_finished: false,
75        }
76    }
77
78    /// Finish timing the execution of a function, method, or other code region.
79    #[track_caller]
80    pub fn finish_desc(mut self, description: &'static str) {
81        let location = std::panic::Location::caller();
82        self.finish_inner(Some(location.file()), Some(location.line()), description);
83    }
84
85    /// Ignore this timer: it will not check the elapsed time or log any warnings.
86    pub fn ignore(mut self) {
87        self.has_finished = true;
88    }
89
90    /// Finish timing the execution of a function, method, or other code region.
91    pub fn finish_inner(
92        &mut self,
93        file: impl Into<Option<&'static str>>,
94        line: impl Into<Option<u32>>,
95        description: &'static str,
96    ) {
97        if self.has_finished {
98            return;
99        }
100
101        let description = if description.is_empty() {
102            self.description
103        } else {
104            description
105        };
106
107        self.has_finished = true;
108
109        let execution = self.start.elapsed();
110        let time = duration_short(execution);
111        let time = time.as_str();
112
113        let file = file.into().unwrap_or_default();
114
115        let line = line.into().map(|line| line.to_string()).unwrap_or_default();
116        let line = line.as_str();
117
118        if execution >= self.min_warn_time {
119            warn!(
120                target: "run time",
121                %time,
122                %file,
123                %line,
124                "very long {description}",
125            );
126        } else if execution >= self.min_info_time {
127            info!(
128                target: "run time",
129                %time,
130                %file,
131                %line,
132                "long {description}",
133            );
134        } else {
135            trace!(
136                target: "run time",
137                %time,
138                %file,
139                %line,
140                "finished {description} code timer",
141            );
142        }
143    }
144}
145
146impl Drop for CodeTimer {
147    fn drop(&mut self) {
148        self.finish_inner(None, None, "(dropped, cancelled, or aborted)")
149    }
150}
zebra_chain/diagnostic.rs

zebra_chain/
diagnostic.rs
