sled/
metrics.rs

1#![allow(unused_results)]
2#![allow(clippy::print_stdout)]
3
4use std::sync::atomic::AtomicUsize;
5
6#[cfg(not(target_arch = "x86_64"))]
7use std::time::{Duration, Instant};
8
9#[cfg(feature = "no_metrics")]
10use std::marker::PhantomData;
11
12#[cfg(not(feature = "no_metrics"))]
13use std::sync::atomic::Ordering::{Acquire, Relaxed};
14
15use crate::Lazy;
16
17use super::*;
18
19/// A metric collector for all pagecache users running in this
20/// process.
21pub static M: Lazy<Metrics, fn() -> Metrics> = Lazy::new(Metrics::default);
22
23#[allow(clippy::cast_precision_loss)]
24pub(crate) fn clock() -> u64 {
25    if cfg!(feature = "no_metrics") {
26        0
27    } else {
28        #[cfg(target_arch = "x86_64")]
29        #[allow(unsafe_code)]
30        unsafe {
31            let mut aux = 0;
32            core::arch::x86_64::__rdtscp(&mut aux)
33        }
34
35        #[cfg(not(target_arch = "x86_64"))]
36        {
37            let u = uptime();
38            (u.as_secs() * 1_000_000_000) + u64::from(u.subsec_nanos())
39        }
40    }
41}
42
43// not correct, since it starts counting at the first observance...
44#[cfg(not(target_arch = "x86_64"))]
45pub(crate) fn uptime() -> Duration {
46    static START: Lazy<Instant, fn() -> Instant> = Lazy::new(Instant::now);
47
48    if cfg!(feature = "no_metrics") {
49        Duration::new(0, 0)
50    } else {
51        START.elapsed()
52    }
53}
54
55/// Measure the duration of an event, and call `Histogram::measure()`.
56pub struct Measure<'h> {
57    _start: u64,
58    #[cfg(not(feature = "no_metrics"))]
59    histo: &'h Histogram,
60    #[cfg(feature = "no_metrics")]
61    _pd: PhantomData<&'h ()>,
62}
63
64impl<'h> Measure<'h> {
65    /// The time delta from ctor to dtor is recorded in `histo`.
66    #[inline]
67    pub fn new(_histo: &'h Histogram) -> Measure<'h> {
68        Measure {
69            #[cfg(feature = "no_metrics")]
70            _pd: PhantomData,
71            #[cfg(not(feature = "no_metrics"))]
72            histo: _histo,
73            _start: clock(),
74        }
75    }
76}
77
78impl<'h> Drop for Measure<'h> {
79    #[inline]
80    fn drop(&mut self) {
81        #[cfg(not(feature = "no_metrics"))]
82        self.histo.measure(clock() - self._start);
83    }
84}
85
86#[derive(Default, Debug)]
87pub struct Metrics {
88    pub accountant_bump_tip: Histogram,
89    pub accountant_hold: Histogram,
90    pub accountant_lock: Histogram,
91    pub accountant_mark_link: Histogram,
92    pub accountant_mark_replace: Histogram,
93    pub accountant_next: Histogram,
94    pub advance_snapshot: Histogram,
95    pub assign_offset: Histogram,
96    pub compress: Histogram,
97    pub decompress: Histogram,
98    pub deserialize: Histogram,
99    pub get_page: Histogram,
100    pub get_pagetable: Histogram,
101    pub link_page: Histogram,
102    pub log_reservation_attempts: CachePadded<AtomicUsize>,
103    pub log_reservations: CachePadded<AtomicUsize>,
104    pub make_stable: Histogram,
105    pub page_out: Histogram,
106    pub pull: Histogram,
107    pub read: Histogram,
108    pub read_segment_message: Histogram,
109    pub replace_page: Histogram,
110    pub reserve_lat: Histogram,
111    pub reserve_sz: Histogram,
112    pub rewrite_page: Histogram,
113    pub segment_read: Histogram,
114    pub segment_utilization_startup: Histogram,
115    pub segment_utilization_shutdown: Histogram,
116    pub serialize: Histogram,
117    pub snapshot_apply: Histogram,
118    pub start_pagecache: Histogram,
119    pub start_segment_accountant: Histogram,
120    pub tree_cas: Histogram,
121    pub tree_child_split_attempt: CachePadded<AtomicUsize>,
122    pub tree_child_split_success: CachePadded<AtomicUsize>,
123    pub tree_del: Histogram,
124    pub tree_get: Histogram,
125    pub tree_loops: CachePadded<AtomicUsize>,
126    pub tree_merge: Histogram,
127    pub tree_parent_split_attempt: CachePadded<AtomicUsize>,
128    pub tree_parent_split_success: CachePadded<AtomicUsize>,
129    pub tree_reverse_scan: Histogram,
130    pub tree_root_split_attempt: CachePadded<AtomicUsize>,
131    pub tree_root_split_success: CachePadded<AtomicUsize>,
132    pub tree_scan: Histogram,
133    pub tree_set: Histogram,
134    pub tree_start: Histogram,
135    pub tree_traverse: Histogram,
136    pub write_to_log: Histogram,
137    pub written_bytes: Histogram,
138    #[cfg(feature = "measure_allocs")]
139    pub allocations: CachePadded<AtomicUsize>,
140    #[cfg(feature = "measure_allocs")]
141    pub allocated_bytes: CachePadded<AtomicUsize>,
142}
143
144#[cfg(not(feature = "no_metrics"))]
145impl Metrics {
146    #[inline]
147    pub fn tree_looped(&self) {
148        self.tree_loops.fetch_add(1, Relaxed);
149    }
150
151    #[inline]
152    pub fn log_reservation_attempted(&self) {
153        self.log_reservation_attempts.fetch_add(1, Relaxed);
154    }
155
156    #[inline]
157    pub fn log_reservation_success(&self) {
158        self.log_reservations.fetch_add(1, Relaxed);
159    }
160
161    #[inline]
162    pub fn tree_child_split_attempt(&self) {
163        self.tree_child_split_attempt.fetch_add(1, Relaxed);
164    }
165
166    #[inline]
167    pub fn tree_child_split_success(&self) {
168        self.tree_child_split_success.fetch_add(1, Relaxed);
169    }
170
171    #[inline]
172    pub fn tree_parent_split_attempt(&self) {
173        self.tree_parent_split_attempt.fetch_add(1, Relaxed);
174    }
175
176    #[inline]
177    pub fn tree_parent_split_success(&self) {
178        self.tree_parent_split_success.fetch_add(1, Relaxed);
179    }
180
181    #[inline]
182    pub fn tree_root_split_attempt(&self) {
183        self.tree_root_split_attempt.fetch_add(1, Relaxed);
184    }
185
186    #[inline]
187    pub fn tree_root_split_success(&self) {
188        self.tree_root_split_success.fetch_add(1, Relaxed);
189    }
190
191    pub fn print_profile(&self) {
192        println!(
193            "sled profile:\n\
194             {0: >17} | {1: >10} | {2: >10} | {3: >10} | {4: >10} | {5: >10} | {6: >10} | {7: >10} | {8: >10} | {9: >10}",
195            "op",
196            "min (us)",
197            "med (us)",
198            "90 (us)",
199            "99 (us)",
200            "99.9 (us)",
201            "99.99 (us)",
202            "max (us)",
203            "count",
204            "sum (s)"
205        );
206        println!("{}", std::iter::repeat("-").take(134).collect::<String>());
207
208        let p = |mut tuples: Vec<(String, _, _, _, _, _, _, _, _, _)>| {
209            tuples.sort_by_key(|t| (t.9 * -1. * 1e3) as i64);
210            for v in tuples {
211                println!(
212                    "{0: >17} | {1: >10.1} | {2: >10.1} | {3: >10.1} \
213                     | {4: >10.1} | {5: >10.1} | {6: >10.1} | {7: >10.1} \
214                     | {8: >10.1} | {9: >10.3}",
215                    v.0, v.1, v.2, v.3, v.4, v.5, v.6, v.7, v.8, v.9,
216                );
217            }
218        };
219
220        let lat = |name: &str, histo: &Histogram| {
221            (
222                name.to_string(),
223                histo.percentile(0.) / 1e3,
224                histo.percentile(50.) / 1e3,
225                histo.percentile(90.) / 1e3,
226                histo.percentile(99.) / 1e3,
227                histo.percentile(99.9) / 1e3,
228                histo.percentile(99.99) / 1e3,
229                histo.percentile(100.) / 1e3,
230                histo.count(),
231                histo.sum() as f64 / 1e9,
232            )
233        };
234
235        let sz = |name: &str, histo: &Histogram| {
236            (
237                name.to_string(),
238                histo.percentile(0.),
239                histo.percentile(50.),
240                histo.percentile(90.),
241                histo.percentile(99.),
242                histo.percentile(99.9),
243                histo.percentile(99.99),
244                histo.percentile(100.),
245                histo.count(),
246                histo.sum() as f64,
247            )
248        };
249
250        println!("tree:");
251        p(vec![
252            lat("traverse", &self.tree_traverse),
253            lat("get", &self.tree_get),
254            lat("set", &self.tree_set),
255            lat("merge", &self.tree_merge),
256            lat("del", &self.tree_del),
257            lat("cas", &self.tree_cas),
258            lat("scan", &self.tree_scan),
259            lat("rev scan", &self.tree_reverse_scan),
260        ]);
261        let total_loops = self.tree_loops.load(Acquire);
262        let total_ops = self.tree_get.count()
263            + self.tree_set.count()
264            + self.tree_merge.count()
265            + self.tree_del.count()
266            + self.tree_cas.count()
267            + self.tree_scan.count()
268            + self.tree_reverse_scan.count();
269        let loop_pct = total_loops * 100 / (total_ops + 1);
270        println!(
271            "tree contention loops: {} ({}% retry rate)",
272            total_loops, loop_pct
273        );
274        println!(
275            "tree split success rates: child({}/{}) parent({}/{}) root({}/{})",
276            self.tree_child_split_success.load(Acquire),
277            self.tree_child_split_attempt.load(Acquire),
278            self.tree_parent_split_success.load(Acquire),
279            self.tree_parent_split_attempt.load(Acquire),
280            self.tree_root_split_success.load(Acquire),
281            self.tree_root_split_attempt.load(Acquire),
282        );
283
284        println!("{}", std::iter::repeat("-").take(134).collect::<String>());
285        println!("pagecache:");
286        p(vec![
287            lat("get", &self.get_page),
288            lat("get pt", &self.get_pagetable),
289            lat("rewrite", &self.rewrite_page),
290            lat("replace", &self.replace_page),
291            lat("link", &self.link_page),
292            lat("pull", &self.pull),
293            lat("page_out", &self.page_out),
294        ]);
295        let hit_ratio = (self.get_page.count() - self.pull.count()) * 100
296            / (self.get_page.count() + 1);
297        println!("hit ratio: {}%", hit_ratio);
298
299        println!("{}", std::iter::repeat("-").take(134).collect::<String>());
300        println!("serialization and compression:");
301        p(vec![
302            lat("serialize", &self.serialize),
303            lat("deserialize", &self.deserialize),
304            #[cfg(feature = "compression")]
305            lat("compress", &self.compress),
306            #[cfg(feature = "compression")]
307            lat("decompress", &self.decompress),
308        ]);
309
310        println!("{}", std::iter::repeat("-").take(134).collect::<String>());
311        println!("log:");
312        p(vec![
313            lat("make_stable", &self.make_stable),
314            lat("read", &self.read),
315            lat("write", &self.write_to_log),
316            sz("written bytes", &self.written_bytes),
317            lat("assign offset", &self.assign_offset),
318            lat("reserve lat", &self.reserve_lat),
319            sz("reserve sz", &self.reserve_sz),
320        ]);
321        let log_reservations =
322            std::cmp::max(1, self.log_reservations.load(Acquire));
323        let log_reservation_attempts =
324            std::cmp::max(1, self.log_reservation_attempts.load(Acquire));
325        let log_reservation_retry_rate =
326            (log_reservation_attempts - log_reservations) * 100
327                / (log_reservations + 1);
328        println!("log reservations: {}", log_reservations);
329        println!(
330            "log res attempts: {}, ({}% retry rate)",
331            log_reservation_attempts, log_reservation_retry_rate,
332        );
333
334        println!("{}", std::iter::repeat("-").take(134).collect::<String>());
335        println!("segment accountant:");
336        p(vec![
337            lat("acquire", &self.accountant_lock),
338            lat("hold", &self.accountant_hold),
339            lat("next", &self.accountant_next),
340            lat("replace", &self.accountant_mark_replace),
341            lat("link", &self.accountant_mark_link),
342        ]);
343
344        println!("{}", std::iter::repeat("-").take(134).collect::<String>());
345        println!("recovery:");
346        p(vec![
347            lat("start", &self.tree_start),
348            lat("advance snapshot", &self.advance_snapshot),
349            lat("load SA", &self.start_segment_accountant),
350            lat("load PC", &self.start_pagecache),
351            lat("snap apply", &self.snapshot_apply),
352            lat("segment read", &self.segment_read),
353            lat("log message read", &self.read_segment_message),
354            sz("seg util start", &self.segment_utilization_startup),
355            sz("seg util end", &self.segment_utilization_shutdown),
356        ]);
357
358        #[cfg(feature = "measure_allocs")]
359        {
360            println!(
361                "{}",
362                std::iter::repeat("-").take(134).collect::<String>()
363            );
364            println!("allocation statistics:");
365            println!(
366                "total allocations: {}",
367                measure_allocs::ALLOCATIONS.load(Acquire)
368            );
369            println!(
370                "allocated bytes: {}",
371                measure_allocs::ALLOCATED_BYTES.load(Acquire)
372            );
373        }
374    }
375}
376
377#[cfg(feature = "no_metrics")]
378impl Metrics {
379    pub const fn log_reservation_attempted(&self) {}
380
381    pub const fn log_reservation_success(&self) {}
382
383    pub const fn tree_child_split_attempt(&self) {}
384
385    pub const fn tree_child_split_success(&self) {}
386
387    pub const fn tree_parent_split_attempt(&self) {}
388
389    pub const fn tree_parent_split_success(&self) {}
390
391    pub const fn tree_root_split_attempt(&self) {}
392
393    pub const fn tree_root_split_success(&self) {}
394
395    pub const fn tree_looped(&self) {}
396
397    pub const fn print_profile(&self) {}
398}
sled/metrics.rs

sled/
metrics.rs
