typed_store/
metrics.rs

1// Copyright (c) Mysten Labs, Inc.
2// Modifications Copyright (c) 2024 IOTA Stiftung
3// SPDX-License-Identifier: Apache-2.0
4
5use std::{
6    cell::RefCell,
7    sync::{
8        Arc,
9        atomic::{AtomicU64, Ordering},
10    },
11    time::Duration,
12};
13
14use once_cell::sync::OnceCell;
15use prometheus_filtered::{
16    HistogramVec, IntCounterVec, IntGaugeVec, MetricLevel, Registry,
17    register_histogram_vec_with_registry, register_int_counter_vec_with_registry,
18    register_int_gauge_vec_with_registry,
19};
20use rocksdb::{PerfContext, PerfMetric, PerfStatsLevel, perf::set_perf_stats};
21use tap::TapFallible;
22use tracing::warn;
23
24thread_local! {
25    static PER_THREAD_ROCKS_PERF_CONTEXT: std::cell::RefCell<rocksdb::PerfContext>  = RefCell::new(PerfContext::default());
26}
27
28const LATENCY_SEC_BUCKETS: &[f64] = &[
29    0.00001, 0.00005, // 10 mcs, 50 mcs
30    0.0001, 0.0002, 0.0003, 0.0004, 0.0005, // 100..500 mcs
31    0.001, 0.002, 0.003, 0.004, 0.005, // 1..5ms
32    0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1., 2.5, 5., 10.,
33];
34
35#[derive(Debug, Clone)]
36// A struct for sampling based on number of operations or duration.
37// Sampling happens if the duration expires and after number of operations
38pub struct SamplingInterval {
39    // Sample once every time duration
40    pub once_every_duration: Duration,
41    // Sample once every number of operations
42    pub after_num_ops: u64,
43    // Counter for keeping track of previous sample
44    pub counter: Arc<AtomicU64>,
45}
46
47impl Default for SamplingInterval {
48    fn default() -> Self {
49        // Enabled with 60 second interval
50        SamplingInterval::new(Duration::from_secs(60), 0)
51    }
52}
53
54impl SamplingInterval {
55    pub fn new(once_every_duration: Duration, after_num_ops: u64) -> Self {
56        let counter = Arc::new(AtomicU64::new(1));
57        if !once_every_duration.is_zero() {
58            let counter = counter.clone();
59            tokio::task::spawn(async move {
60                loop {
61                    if counter.load(Ordering::SeqCst) > after_num_ops {
62                        counter.store(0, Ordering::SeqCst);
63                    }
64                    tokio::time::sleep(once_every_duration).await;
65                }
66            });
67        }
68        SamplingInterval {
69            once_every_duration,
70            after_num_ops,
71            counter,
72        }
73    }
74    pub fn new_from_self(&self) -> SamplingInterval {
75        SamplingInterval::new(self.once_every_duration, self.after_num_ops)
76    }
77    pub fn sample(&self) -> bool {
78        if self.once_every_duration.is_zero() {
79            self.counter
80                .fetch_add(1, Ordering::Relaxed)
81                .is_multiple_of(self.after_num_ops + 1)
82        } else {
83            self.counter.fetch_add(1, Ordering::Relaxed) == 0
84        }
85    }
86}
87
88#[derive(Debug)]
89pub struct ColumnFamilyMetrics {
90    pub rocksdb_total_sst_files_size: IntGaugeVec,
91    pub rocksdb_total_blob_files_size: IntGaugeVec,
92    pub rocksdb_total_num_files: IntGaugeVec,
93    pub rocksdb_num_level0_files: IntGaugeVec,
94    pub rocksdb_current_size_active_mem_tables: IntGaugeVec,
95    pub rocksdb_size_all_mem_tables: IntGaugeVec,
96    pub rocksdb_num_snapshots: IntGaugeVec,
97    pub rocksdb_oldest_snapshot_time: IntGaugeVec,
98    pub rocksdb_actual_delayed_write_rate: IntGaugeVec,
99    pub rocksdb_is_write_stopped: IntGaugeVec,
100    pub rocksdb_block_cache_capacity: IntGaugeVec,
101    pub rocksdb_block_cache_usage: IntGaugeVec,
102    pub rocksdb_block_cache_pinned_usage: IntGaugeVec,
103    pub rocksdb_estimate_table_readers_mem: IntGaugeVec,
104    pub rocksdb_num_immutable_mem_tables: IntGaugeVec,
105    pub rocksdb_mem_table_flush_pending: IntGaugeVec,
106    pub rocksdb_compaction_pending: IntGaugeVec,
107    pub rocksdb_estimate_pending_compaction_bytes: IntGaugeVec,
108    pub rocksdb_num_running_compactions: IntGaugeVec,
109    pub rocksdb_num_running_flushes: IntGaugeVec,
110    pub rocksdb_estimate_oldest_key_time: IntGaugeVec,
111    pub rocksdb_background_errors: IntGaugeVec,
112    pub rocksdb_estimated_num_keys: IntGaugeVec,
113    pub rocksdb_base_level: IntGaugeVec,
114}
115
116impl ColumnFamilyMetrics {
117    pub(crate) fn new(registry: &Registry) -> Self {
118        ColumnFamilyMetrics {
119            rocksdb_total_sst_files_size: register_int_gauge_vec_with_registry!(
120                "rocksdb_total_sst_files_size",
121                "The storage size occupied by the sst files in the column family",
122                &["cf_name"],
123                registry;
124                MetricLevel::Trace,
125            )
126            .unwrap(),
127            rocksdb_total_blob_files_size: register_int_gauge_vec_with_registry!(
128                "rocksdb_total_blob_files_size",
129                "The storage size occupied by the blob files in the column family",
130                &["cf_name"],
131                registry;
132                MetricLevel::Trace,
133            )
134            .unwrap(),
135            rocksdb_total_num_files: register_int_gauge_vec_with_registry!(
136                "rocksdb_total_num_files",
137                "Total number of files used in the column family",
138                &["cf_name"],
139                registry;
140                MetricLevel::Trace,
141            )
142            .unwrap(),
143            rocksdb_num_level0_files: register_int_gauge_vec_with_registry!(
144                "rocksdb_num_level0_files",
145                "Number of level 0 files in the column family",
146                &["cf_name"],
147                registry;
148                MetricLevel::Trace,
149            )
150            .unwrap(),
151            rocksdb_current_size_active_mem_tables: register_int_gauge_vec_with_registry!(
152                "rocksdb_current_size_active_mem_tables",
153                "The current approximate size of active memtable (bytes).",
154                &["cf_name"],
155                registry;
156                MetricLevel::Trace,
157            )
158            .unwrap(),
159            rocksdb_size_all_mem_tables: register_int_gauge_vec_with_registry!(
160                "rocksdb_size_all_mem_tables",
161                "The memory size occupied by the column family's in-memory buffer",
162                &["cf_name"],
163                registry;
164                MetricLevel::Trace,
165            )
166            .unwrap(),
167            rocksdb_num_snapshots: register_int_gauge_vec_with_registry!(
168                "rocksdb_num_snapshots",
169                "Number of snapshots held for the column family",
170                &["cf_name"],
171                registry;
172                MetricLevel::Trace,
173            )
174            .unwrap(),
175            rocksdb_oldest_snapshot_time: register_int_gauge_vec_with_registry!(
176                "rocksdb_oldest_snapshot_time",
177                "Unit timestamp of the oldest unreleased snapshot",
178                &["cf_name"],
179                registry;
180                MetricLevel::Trace,
181            )
182            .unwrap(),
183            rocksdb_actual_delayed_write_rate: register_int_gauge_vec_with_registry!(
184                "rocksdb_actual_delayed_write_rate",
185                "The current actual delayed write rate. 0 means no delay",
186                &["cf_name"],
187                registry;
188                MetricLevel::Trace,
189            )
190            .unwrap(),
191            rocksdb_is_write_stopped: register_int_gauge_vec_with_registry!(
192                "rocksdb_is_write_stopped",
193                "A flag indicating whether writes are stopped on this column family. 1 indicates writes have been stopped.",
194                &["cf_name"],
195                registry;
196                MetricLevel::Trace,
197            )
198            .unwrap(),
199            rocksdb_block_cache_capacity: register_int_gauge_vec_with_registry!(
200                "rocksdb_block_cache_capacity",
201                "The block cache capacity of the column family.",
202                &["cf_name"],
203                registry;
204                MetricLevel::Trace,
205            )
206            .unwrap(),
207            rocksdb_block_cache_usage: register_int_gauge_vec_with_registry!(
208                "rocksdb_block_cache_usage",
209                "The memory size used by the column family in the block cache.",
210                &["cf_name"],
211                registry;
212                MetricLevel::Trace,
213            )
214            .unwrap(),
215            rocksdb_block_cache_pinned_usage: register_int_gauge_vec_with_registry!(
216                "rocksdb_block_cache_pinned_usage",
217                "The memory size used by the column family in the block cache where entries are pinned",
218                &["cf_name"],
219                registry;
220                MetricLevel::Trace,
221            )
222            .unwrap(),
223            rocksdb_estimate_table_readers_mem: register_int_gauge_vec_with_registry!(
224                "rocksdb_estimate_table_readers_mem",
225                "The estimated memory size used for reading SST tables in this column
226                family such as filters and index blocks. Note that this number does not
227                include the memory used in block cache.",
228                &["cf_name"],
229                registry;
230                MetricLevel::Trace,
231            )
232            .unwrap(),
233            rocksdb_num_immutable_mem_tables: register_int_gauge_vec_with_registry!(
234                "rocksdb_num_immutable_mem_tables",
235                "The number of immutable memtables that have not yet been flushed.",
236                &["cf_name"],
237                registry;
238                MetricLevel::Trace,
239            )
240            .unwrap(),
241            rocksdb_mem_table_flush_pending: register_int_gauge_vec_with_registry!(
242                "rocksdb_mem_table_flush_pending",
243                "A 1 or 0 flag indicating whether a memtable flush is pending.
244                If this number is 1, it means a memtable is waiting for being flushed,
245                but there might be too many L0 files that prevents it from being flushed.",
246                &["cf_name"],
247                registry;
248                MetricLevel::Trace,
249            )
250            .unwrap(),
251            rocksdb_compaction_pending: register_int_gauge_vec_with_registry!(
252                "rocksdb_compaction_pending",
253                "A 1 or 0 flag indicating whether a compaction job is pending.
254                If this number is 1, it means some part of the column family requires
255                compaction in order to maintain shape of LSM tree, but the compaction
256                is pending because the desired compaction job is either waiting for
257                other dependent compactions to be finished or waiting for an available
258                compaction thread.",
259                &["cf_name"],
260                registry;
261                MetricLevel::Trace,
262            )
263            .unwrap(),
264            rocksdb_estimate_pending_compaction_bytes: register_int_gauge_vec_with_registry!(
265                "rocksdb_estimate_pending_compaction_bytes",
266                "Estimated total number of bytes compaction needs to rewrite to get all levels down
267                to under target size. Not valid for other compactions than level-based.",
268                &["cf_name"],
269                registry;
270                MetricLevel::Trace,
271            )
272            .unwrap(),
273            rocksdb_num_running_compactions: register_int_gauge_vec_with_registry!(
274                "rocksdb_num_running_compactions",
275                "The number of compactions that are currently running for the column family.",
276                &["cf_name"],
277                registry;
278                MetricLevel::Trace,
279            )
280            .unwrap(),
281            rocksdb_num_running_flushes: register_int_gauge_vec_with_registry!(
282                "rocksdb_num_running_flushes",
283                "The number of flushes that are currently running for the column family.",
284                &["cf_name"],
285                registry;
286                MetricLevel::Trace,
287            )
288            .unwrap(),
289            rocksdb_estimate_oldest_key_time: register_int_gauge_vec_with_registry!(
290                "rocksdb_estimate_oldest_key_time",
291                "Estimation of the oldest key timestamp in the DB. Only available
292                for FIFO compaction with compaction_options_fifo.allow_compaction = false.",
293                &["cf_name"],
294                registry;
295                MetricLevel::Trace,
296            )
297            .unwrap(),
298            rocksdb_estimated_num_keys: register_int_gauge_vec_with_registry!(
299                "rocksdb_estimated_num_keys",
300                "The estimated number of keys in the table",
301                &["cf_name"],
302                registry;
303                MetricLevel::Trace,
304            )
305            .unwrap(),
306            rocksdb_background_errors: register_int_gauge_vec_with_registry!(
307                "rocksdb_background_errors",
308                "The accumulated number of RocksDB background errors.",
309                &["cf_name"],
310                registry;
311                MetricLevel::Trace,
312            )
313            .unwrap(),
314            rocksdb_base_level: register_int_gauge_vec_with_registry!(
315                "rocksdb_base_level",
316                "The number of level to which L0 data will be compacted.",
317                &["cf_name"],
318                registry;
319                MetricLevel::Trace,
320            )
321            .unwrap(),
322        }
323    }
324}
325
326#[derive(Debug)]
327pub struct OperationMetrics {
328    pub rocksdb_iter_latency_seconds: HistogramVec,
329    pub rocksdb_iter_bytes: HistogramVec,
330    pub rocksdb_iter_keys: HistogramVec,
331    pub rocksdb_get_latency_seconds: HistogramVec,
332    pub rocksdb_get_bytes: HistogramVec,
333    pub rocksdb_multiget_latency_seconds: HistogramVec,
334    pub rocksdb_multiget_bytes: HistogramVec,
335    pub rocksdb_put_latency_seconds: HistogramVec,
336    pub rocksdb_put_bytes: HistogramVec,
337    pub rocksdb_batch_put_bytes: HistogramVec,
338    pub rocksdb_delete_latency_seconds: HistogramVec,
339    pub rocksdb_deletes: IntCounterVec,
340    pub rocksdb_batch_commit_latency_seconds: HistogramVec,
341    pub rocksdb_batch_commit_bytes: HistogramVec,
342    pub rocksdb_num_active_db_handles: IntGaugeVec,
343    pub rocksdb_very_slow_batch_writes_count: IntCounterVec,
344    pub rocksdb_very_slow_batch_writes_duration_ms: IntCounterVec,
345    pub rocksdb_very_slow_puts_count: IntCounterVec,
346    pub rocksdb_very_slow_puts_duration_ms: IntCounterVec,
347}
348
349impl OperationMetrics {
350    pub(crate) fn new(registry: &Registry) -> Self {
351        OperationMetrics {
352            rocksdb_iter_latency_seconds: register_histogram_vec_with_registry!(
353                "rocksdb_iter_latency_seconds",
354                "Rocksdb iter latency in seconds",
355                &["cf_name"],
356                LATENCY_SEC_BUCKETS.to_vec(),
357                registry;
358                MetricLevel::Trace,
359            )
360            .unwrap(),
361            rocksdb_iter_bytes: register_histogram_vec_with_registry!(
362                "rocksdb_iter_bytes",
363                "Rocksdb iter size in bytes",
364                &["cf_name"],
365                prometheus_filtered::exponential_buckets(1.0, 4.0, 15)
366                    .unwrap()
367                    .to_vec(),
368                registry;
369                MetricLevel::Trace,
370            )
371            .unwrap(),
372            rocksdb_iter_keys: register_histogram_vec_with_registry!(
373                "rocksdb_iter_keys",
374                "Rocksdb iter num keys",
375                &["cf_name"],
376                registry;
377                MetricLevel::Trace,
378            )
379            .unwrap(),
380            rocksdb_get_latency_seconds: register_histogram_vec_with_registry!(
381                "rocksdb_get_latency_seconds",
382                "Rocksdb get latency in seconds",
383                &["cf_name"],
384                LATENCY_SEC_BUCKETS.to_vec(),
385                registry;
386                MetricLevel::Trace,
387            )
388            .unwrap(),
389            rocksdb_get_bytes: register_histogram_vec_with_registry!(
390                "rocksdb_get_bytes",
391                "Rocksdb get call returned data size in bytes",
392                &["cf_name"],
393                prometheus_filtered::exponential_buckets(1.0, 4.0, 15)
394                    .unwrap()
395                    .to_vec(),
396                registry;
397                MetricLevel::Trace,
398            )
399            .unwrap(),
400            rocksdb_multiget_latency_seconds: register_histogram_vec_with_registry!(
401                "rocksdb_multiget_latency_seconds",
402                "Rocksdb multiget latency in seconds",
403                &["cf_name"],
404                LATENCY_SEC_BUCKETS.to_vec(),
405                registry;
406                MetricLevel::Trace,
407            )
408            .unwrap(),
409            rocksdb_multiget_bytes: register_histogram_vec_with_registry!(
410                "rocksdb_multiget_bytes",
411                "Rocksdb multiget call returned data size in bytes",
412                &["cf_name"],
413                prometheus_filtered::exponential_buckets(1.0, 4.0, 15)
414                    .unwrap()
415                    .to_vec(),
416                registry;
417                MetricLevel::Trace,
418            )
419            .unwrap(),
420            rocksdb_put_latency_seconds: register_histogram_vec_with_registry!(
421                "rocksdb_put_latency_seconds",
422                "Rocksdb put latency in seconds",
423                &["cf_name"],
424                LATENCY_SEC_BUCKETS.to_vec(),
425                registry;
426                MetricLevel::Trace,
427            )
428            .unwrap(),
429            rocksdb_put_bytes: register_histogram_vec_with_registry!(
430                "rocksdb_put_bytes",
431                "Rocksdb put call puts data size in bytes",
432                &["cf_name"],
433                prometheus_filtered::exponential_buckets(1.0, 4.0, 15)
434                    .unwrap()
435                    .to_vec(),
436                registry;
437                MetricLevel::Trace,
438            )
439            .unwrap(),
440            rocksdb_batch_put_bytes: register_histogram_vec_with_registry!(
441                "rocksdb_batch_put_bytes",
442                "Rocksdb batch put call puts data size in bytes",
443                &["cf_name"],
444                prometheus_filtered::exponential_buckets(1.0, 4.0, 15)
445                    .unwrap()
446                    .to_vec(),
447                registry;
448                MetricLevel::Trace,
449            )
450            .unwrap(),
451            rocksdb_delete_latency_seconds: register_histogram_vec_with_registry!(
452                "rocksdb_delete_latency_seconds",
453                "Rocksdb delete latency in seconds",
454                &["cf_name"],
455                LATENCY_SEC_BUCKETS.to_vec(),
456                registry;
457                MetricLevel::Trace,
458            )
459            .unwrap(),
460            rocksdb_deletes: register_int_counter_vec_with_registry!(
461                "rocksdb_deletes",
462                "Rocksdb delete calls",
463                &["cf_name"],
464                registry;
465                MetricLevel::Trace,
466            )
467            .unwrap(),
468            rocksdb_batch_commit_latency_seconds: register_histogram_vec_with_registry!(
469                "rocksdb_write_batch_commit_latency_seconds",
470                "Rocksdb schema batch commit latency in seconds",
471                &["db_name"],
472                LATENCY_SEC_BUCKETS.to_vec(),
473                registry;
474                MetricLevel::Trace,
475            )
476            .unwrap(),
477            rocksdb_batch_commit_bytes: register_histogram_vec_with_registry!(
478                "rocksdb_batch_commit_bytes",
479                "Rocksdb schema batch commit size in bytes",
480                &["db_name"],
481                prometheus_filtered::exponential_buckets(1.0, 4.0, 15)
482                    .unwrap()
483                    .to_vec(),
484                registry;
485                MetricLevel::Trace,
486            )
487            .unwrap(),
488            rocksdb_num_active_db_handles: register_int_gauge_vec_with_registry!(
489                "rocksdb_num_active_db_handles",
490                "Number of active db handles",
491                &["db_name"],
492                registry;
493                MetricLevel::Trace,
494            )
495            .unwrap(),
496            rocksdb_very_slow_batch_writes_count: register_int_counter_vec_with_registry!(
497                "rocksdb_num_very_slow_batch_writes",
498                "Number of batch writes that took more than 1 second",
499                &["db_name"],
500                registry;
501                MetricLevel::Trace,
502            )
503            .unwrap(),
504            rocksdb_very_slow_batch_writes_duration_ms: register_int_counter_vec_with_registry!(
505                "rocksdb_very_slow_batch_writes_duration",
506                "Total duration of batch writes that took more than 1 second",
507                &["db_name"],
508                registry;
509                MetricLevel::Trace,
510            )
511            .unwrap(),
512            rocksdb_very_slow_puts_count: register_int_counter_vec_with_registry!(
513                "rocksdb_num_very_slow_puts",
514                "Number of puts that took more than 1 second",
515                &["cf_name"],
516                registry;
517                MetricLevel::Trace,
518            )
519            .unwrap(),
520            rocksdb_very_slow_puts_duration_ms: register_int_counter_vec_with_registry!(
521                "rocksdb_very_slow_puts_duration",
522                "Total duration of puts that took more than 1 second",
523                &["cf_name"],
524                registry;
525                MetricLevel::Trace,
526            )
527            .unwrap(),
528        }
529    }
530}
531
532pub struct RocksDBPerfContext;
533
534impl Default for RocksDBPerfContext {
535    fn default() -> Self {
536        set_perf_stats(PerfStatsLevel::EnableTime);
537        PER_THREAD_ROCKS_PERF_CONTEXT.with(|perf_context| {
538            perf_context.borrow_mut().reset();
539        });
540        RocksDBPerfContext {}
541    }
542}
543
544impl Drop for RocksDBPerfContext {
545    fn drop(&mut self) {
546        set_perf_stats(PerfStatsLevel::Disable);
547    }
548}
549
550#[derive(Debug)]
551pub struct ReadPerfContextMetrics {
552    pub user_key_comparison_count: IntCounterVec,
553    pub block_cache_hit_count: IntCounterVec,
554    pub block_read_count: IntCounterVec,
555    pub block_read_byte: IntCounterVec,
556    pub block_read_nanos: IntCounterVec,
557    pub block_checksum_nanos: IntCounterVec,
558    pub block_decompress_nanos: IntCounterVec,
559    pub get_read_bytes: IntCounterVec,
560    pub multiget_read_bytes: IntCounterVec,
561    pub get_snapshot_nanos: IntCounterVec,
562    pub get_from_memtable_nanos: IntCounterVec,
563    pub get_from_memtable_count: IntCounterVec,
564    pub get_post_process_nanos: IntCounterVec,
565    pub get_from_output_files_nanos: IntCounterVec,
566    pub db_mutex_lock_nanos: IntCounterVec,
567    pub db_condition_wait_nanos: IntCounterVec,
568    pub merge_operator_nanos: IntCounterVec,
569    pub read_index_block_nanos: IntCounterVec,
570    pub read_filter_block_nanos: IntCounterVec,
571    pub new_table_block_iter_nanos: IntCounterVec,
572    pub block_seek_nanos: IntCounterVec,
573    pub find_table_nanos: IntCounterVec,
574    pub bloom_memtable_hit_count: IntCounterVec,
575    pub bloom_memtable_miss_count: IntCounterVec,
576    pub bloom_sst_hit_count: IntCounterVec,
577    pub bloom_sst_miss_count: IntCounterVec,
578    pub key_lock_wait_time: IntCounterVec,
579    pub key_lock_wait_count: IntCounterVec,
580    pub internal_delete_skipped_count: IntCounterVec,
581    pub internal_skipped_count: IntCounterVec,
582}
583
584impl ReadPerfContextMetrics {
585    pub(crate) fn new(registry: &Registry) -> Self {
586        ReadPerfContextMetrics {
587            user_key_comparison_count: register_int_counter_vec_with_registry!(
588                "user_key_comparison_count",
589                "Helps us figure out whether too many comparisons in binary search can be a problem,
590                especially when a more expensive comparator is used. Moreover, since number of comparisons
591                is usually uniform based on the memtable size, the SST file size for Level 0 and size of other
592                levels, an significant increase of the counter can indicate unexpected LSM-tree shape.
593                You may want to check whether flush/compaction can keep up with the write speed",
594                &["cf_name"],
595                registry;
596                MetricLevel::Trace,
597            )
598            .unwrap(),
599            block_cache_hit_count: register_int_counter_vec_with_registry!(
600                "block_cache_hit_count",
601                "Tells us how many times we read data blocks from block cache, and block_read_count tells us how many
602                times we have to read blocks from the file system (either block cache is disabled or it is a cache miss).
603                We can evaluate the block cache efficiency by looking at the two counters over time.",
604                &["cf_name"],
605                registry;
606                MetricLevel::Trace,
607            )
608            .unwrap(),
609            block_read_count: register_int_counter_vec_with_registry!(
610                "block_read_count",
611                "Tells us how many times we have to read blocks from the file system (either block cache is disabled or it is a cache miss)",
612                &["cf_name"],
613                registry;
614                MetricLevel::Trace,
615            )
616            .unwrap(),
617            block_read_byte: register_int_counter_vec_with_registry!(
618                "block_read_byte",
619                "Tells us how many total bytes we read from the file system. It can tell us whether a slow query can be caused by reading
620                large blocks from the file system. Index and bloom filter blocks are usually large blocks. A large block can also be the result
621                of a very large key or value",
622                &["cf_name"],
623                registry;
624                MetricLevel::Trace,
625            )
626            .unwrap(),
627            block_read_nanos: register_int_counter_vec_with_registry!(
628                "block_read_nanos",
629                "Total nanos spent on block reads",
630                &["cf_name"],
631                registry;
632                MetricLevel::Trace,
633            )
634            .unwrap(),
635            block_checksum_nanos: register_int_counter_vec_with_registry!(
636                "block_checksum_nanos",
637                "Total nanos spent on verifying block checksum",
638                &["cf_name"],
639                registry;
640                MetricLevel::Trace,
641            )
642            .unwrap(),
643            block_decompress_nanos: register_int_counter_vec_with_registry!(
644                "block_decompress_nanos",
645                "Total nanos spent on decompressing a block",
646                &["cf_name"],
647                registry;
648                MetricLevel::Trace,
649            )
650            .unwrap(),
651            get_read_bytes: register_int_counter_vec_with_registry!(
652                "get_read_bytes",
653                "Total bytes for values returned by Get",
654                &["cf_name"],
655                registry;
656                MetricLevel::Trace,
657            )
658            .unwrap(),
659            multiget_read_bytes: register_int_counter_vec_with_registry!(
660                "multiget_read_bytes",
661                "Total bytes for values returned by MultiGet.",
662                &["cf_name"],
663                registry;
664                MetricLevel::Trace,
665            )
666            .unwrap(),
667            get_snapshot_nanos: register_int_counter_vec_with_registry!(
668                "get_snapshot_nanos",
669                "Time spent in getting snapshot.",
670                &["cf_name"],
671                registry;
672                MetricLevel::Trace,
673            )
674            .unwrap(),
675            get_from_memtable_nanos: register_int_counter_vec_with_registry!(
676                "get_from_memtable_nanos",
677                "Time spent on reading data from memtable.",
678                &["cf_name"],
679                registry;
680                MetricLevel::Trace,
681            )
682            .unwrap(),
683            get_from_memtable_count: register_int_counter_vec_with_registry!(
684                "get_from_memtable_count",
685                "Number of memtables queried",
686                &["cf_name"],
687                registry;
688                MetricLevel::Trace,
689            )
690            .unwrap(),
691            get_post_process_nanos: register_int_counter_vec_with_registry!(
692                "get_post_process_nanos",
693                "Total nanos spent after Get() finds a key",
694                &["cf_name"],
695                registry;
696                MetricLevel::Trace,
697            )
698            .unwrap(),
699            get_from_output_files_nanos: register_int_counter_vec_with_registry!(
700                "get_from_output_files_nanos",
701                "Total nanos reading from output files",
702                &["cf_name"],
703                registry;
704                MetricLevel::Trace,
705            )
706            .unwrap(),
707            db_mutex_lock_nanos: register_int_counter_vec_with_registry!(
708                "db_mutex_lock_nanos",
709                "Time spent on acquiring db mutex",
710                &["cf_name"],
711                registry;
712                MetricLevel::Trace,
713            )
714            .unwrap(),
715            db_condition_wait_nanos: register_int_counter_vec_with_registry!(
716                "db_condition_wait_nanos",
717                "Time spent waiting with a condition variable created with DB Mutex.",
718                &["cf_name"],
719                registry;
720                MetricLevel::Trace,
721            )
722            .unwrap(),
723            merge_operator_nanos: register_int_counter_vec_with_registry!(
724                "merge_operator_nanos",
725                "Time spent on merge operator.",
726                &["cf_name"],
727                registry;
728                MetricLevel::Trace,
729            )
730            .unwrap(),
731            read_index_block_nanos: register_int_counter_vec_with_registry!(
732                "read_index_block_nanos",
733                "Time spent on reading index block from block cache or SST file",
734                &["cf_name"],
735                registry;
736                MetricLevel::Trace,
737            )
738            .unwrap(),
739            read_filter_block_nanos: register_int_counter_vec_with_registry!(
740                "read_filter_block_nanos",
741                "Time spent on reading filter block from block cache or SST file",
742                &["cf_name"],
743                registry;
744                MetricLevel::Trace,
745            )
746            .unwrap(),
747            new_table_block_iter_nanos: register_int_counter_vec_with_registry!(
748                "new_table_block_iter_nanos",
749                "Time spent on creating data block iterator",
750                &["cf_name"],
751                registry;
752                MetricLevel::Trace,
753            )
754            .unwrap(),
755            block_seek_nanos: register_int_counter_vec_with_registry!(
756                "block_seek_nanos",
757                "Time spent on seeking a key in data/index blocks",
758                &["cf_name"],
759                registry;
760                MetricLevel::Trace,
761            )
762            .unwrap(),
763            find_table_nanos: register_int_counter_vec_with_registry!(
764                "find_table_nanos",
765                "Time spent on finding or creating a table reader",
766                &["cf_name"],
767                registry;
768                MetricLevel::Trace,
769            )
770            .unwrap(),
771            bloom_memtable_hit_count: register_int_counter_vec_with_registry!(
772                "bloom_memtable_hit_count",
773                "Total number of mem table bloom hits",
774                &["cf_name"],
775                registry;
776                MetricLevel::Trace,
777            )
778            .unwrap(),
779            bloom_memtable_miss_count: register_int_counter_vec_with_registry!(
780                "bloom_memtable_miss_count",
781                "Total number of mem table bloom misses",
782                &["cf_name"],
783                registry;
784                MetricLevel::Trace,
785            )
786            .unwrap(),
787            bloom_sst_hit_count: register_int_counter_vec_with_registry!(
788                "bloom_sst_hit_count",
789                "Total number of SST table bloom hits",
790                &["cf_name"],
791                registry;
792                MetricLevel::Trace,
793            )
794            .unwrap(),
795            bloom_sst_miss_count: register_int_counter_vec_with_registry!(
796                "bloom_sst_miss_count",
797                "Total number of SST table bloom misses",
798                &["cf_name"],
799                registry;
800                MetricLevel::Trace,
801            )
802            .unwrap(),
803            key_lock_wait_time: register_int_counter_vec_with_registry!(
804                "key_lock_wait_time",
805                "Time spent waiting on key locks in transaction lock manager",
806                &["cf_name"],
807                registry;
808                MetricLevel::Trace,
809            )
810            .unwrap(),
811            key_lock_wait_count: register_int_counter_vec_with_registry!(
812                "key_lock_wait_count",
813                "Number of times acquiring a lock was blocked by another transaction",
814                &["cf_name"],
815                registry;
816                MetricLevel::Trace,
817            )
818            .unwrap(),
819            internal_delete_skipped_count: register_int_counter_vec_with_registry!(
820                "internal_delete_skipped_count",
821                "Total number of deleted keys skipped during iteration",
822                &["cf_name"],
823                registry;
824                MetricLevel::Trace,
825            )
826                .unwrap(),
827            internal_skipped_count: register_int_counter_vec_with_registry!(
828                "internal_skipped_count",
829                "Totall number of internal keys skipped during iteration",
830                &["cf_name"],
831                registry;
832                MetricLevel::Trace,
833            )
834                .unwrap(),
835        }
836    }
837
838    pub fn report_metrics(&self, cf_name: &str) {
839        PER_THREAD_ROCKS_PERF_CONTEXT.with(|perf_context_cell| {
840            set_perf_stats(PerfStatsLevel::Disable);
841            let perf_context = perf_context_cell.borrow();
842            self.user_key_comparison_count
843                .with_label_values(&[cf_name])
844                .inc_by(perf_context.metric(PerfMetric::UserKeyComparisonCount));
845            self.block_cache_hit_count
846                .with_label_values(&[cf_name])
847                .inc_by(perf_context.metric(PerfMetric::BlockCacheHitCount));
848            self.block_read_count
849                .with_label_values(&[cf_name])
850                .inc_by(perf_context.metric(PerfMetric::BlockReadCount));
851            self.block_read_byte
852                .with_label_values(&[cf_name])
853                .inc_by(perf_context.metric(PerfMetric::BlockReadByte));
854            self.block_read_nanos
855                .with_label_values(&[cf_name])
856                .inc_by(perf_context.metric(PerfMetric::BlockReadTime));
857            self.block_read_count
858                .with_label_values(&[cf_name])
859                .inc_by(perf_context.metric(PerfMetric::BlockReadCount));
860            self.block_checksum_nanos
861                .with_label_values(&[cf_name])
862                .inc_by(perf_context.metric(PerfMetric::BlockChecksumTime));
863            self.block_decompress_nanos
864                .with_label_values(&[cf_name])
865                .inc_by(perf_context.metric(PerfMetric::BlockDecompressTime));
866            self.get_read_bytes
867                .with_label_values(&[cf_name])
868                .inc_by(perf_context.metric(PerfMetric::GetReadBytes));
869            self.multiget_read_bytes
870                .with_label_values(&[cf_name])
871                .inc_by(perf_context.metric(PerfMetric::MultigetReadBytes));
872            self.get_snapshot_nanos
873                .with_label_values(&[cf_name])
874                .inc_by(perf_context.metric(PerfMetric::GetSnapshotTime));
875            self.get_from_memtable_nanos
876                .with_label_values(&[cf_name])
877                .inc_by(perf_context.metric(PerfMetric::GetFromMemtableTime));
878            self.get_from_memtable_count
879                .with_label_values(&[cf_name])
880                .inc_by(perf_context.metric(PerfMetric::GetFromMemtableCount));
881            self.get_post_process_nanos
882                .with_label_values(&[cf_name])
883                .inc_by(perf_context.metric(PerfMetric::GetPostProcessTime));
884            self.get_from_output_files_nanos
885                .with_label_values(&[cf_name])
886                .inc_by(perf_context.metric(PerfMetric::GetFromOutputFilesTime));
887            self.db_mutex_lock_nanos
888                .with_label_values(&[cf_name])
889                .inc_by(perf_context.metric(PerfMetric::DbMutexLockNanos));
890            self.db_condition_wait_nanos
891                .with_label_values(&[cf_name])
892                .inc_by(perf_context.metric(PerfMetric::DbConditionWaitNanos));
893            self.merge_operator_nanos
894                .with_label_values(&[cf_name])
895                .inc_by(perf_context.metric(PerfMetric::MergeOperatorTimeNanos));
896            self.read_index_block_nanos
897                .with_label_values(&[cf_name])
898                .inc_by(perf_context.metric(PerfMetric::ReadIndexBlockNanos));
899            self.read_filter_block_nanos
900                .with_label_values(&[cf_name])
901                .inc_by(perf_context.metric(PerfMetric::ReadFilterBlockNanos));
902            self.new_table_block_iter_nanos
903                .with_label_values(&[cf_name])
904                .inc_by(perf_context.metric(PerfMetric::NewTableBlockIterNanos));
905            self.block_seek_nanos
906                .with_label_values(&[cf_name])
907                .inc_by(perf_context.metric(PerfMetric::BlockSeekNanos));
908            self.find_table_nanos
909                .with_label_values(&[cf_name])
910                .inc_by(perf_context.metric(PerfMetric::FindTableNanos));
911            self.bloom_memtable_hit_count
912                .with_label_values(&[cf_name])
913                .inc_by(perf_context.metric(PerfMetric::BloomMemtableHitCount));
914            self.bloom_memtable_miss_count
915                .with_label_values(&[cf_name])
916                .inc_by(perf_context.metric(PerfMetric::BloomMemtableMissCount));
917            self.bloom_sst_hit_count
918                .with_label_values(&[cf_name])
919                .inc_by(perf_context.metric(PerfMetric::BloomSstHitCount));
920            self.bloom_sst_miss_count
921                .with_label_values(&[cf_name])
922                .inc_by(perf_context.metric(PerfMetric::BloomSstMissCount));
923            self.key_lock_wait_time
924                .with_label_values(&[cf_name])
925                .inc_by(perf_context.metric(PerfMetric::KeyLockWaitTime));
926            self.key_lock_wait_count
927                .with_label_values(&[cf_name])
928                .inc_by(perf_context.metric(PerfMetric::KeyLockWaitCount));
929            self.internal_delete_skipped_count
930                .with_label_values(&[cf_name])
931                .inc_by(perf_context.metric(PerfMetric::InternalDeleteSkippedCount));
932            self.internal_skipped_count
933                .with_label_values(&[cf_name])
934                .inc_by(perf_context.metric(PerfMetric::InternalKeySkippedCount));
935        });
936    }
937}
938
939#[derive(Debug)]
940pub struct WritePerfContextMetrics {
941    pub write_wal_nanos: IntCounterVec,
942    pub write_memtable_nanos: IntCounterVec,
943    pub write_delay_nanos: IntCounterVec,
944    pub write_pre_and_post_process_nanos: IntCounterVec,
945    pub write_db_mutex_lock_nanos: IntCounterVec,
946    pub write_db_condition_wait_nanos: IntCounterVec,
947    pub write_key_lock_wait_nanos: IntCounterVec,
948    pub write_key_lock_wait_count: IntCounterVec,
949}
950
951impl WritePerfContextMetrics {
952    pub(crate) fn new(registry: &Registry) -> Self {
953        WritePerfContextMetrics {
954            write_wal_nanos: register_int_counter_vec_with_registry!(
955                "write_wal_nanos",
956                "Total nanos spent on writing to WAL",
957                &["cf_name"],
958                registry;
959                MetricLevel::Trace,
960            )
961            .unwrap(),
962            write_memtable_nanos: register_int_counter_vec_with_registry!(
963                "write_memtable_nanos",
964                "Total nanos spent on writing to memtable",
965                &["cf_name"],
966                registry;
967                MetricLevel::Trace,
968            )
969            .unwrap(),
970            write_delay_nanos: register_int_counter_vec_with_registry!(
971                "write_delay_nanos",
972                "Total nanos spent on delaying or throttling write",
973                &["cf_name"],
974                registry;
975                MetricLevel::Trace,
976            )
977            .unwrap(),
978            write_pre_and_post_process_nanos: register_int_counter_vec_with_registry!(
979                "write_pre_and_post_process_nanos",
980                "Total nanos spent on writing a record, excluding the above four things",
981                &["cf_name"],
982                registry;
983                MetricLevel::Trace,
984            )
985            .unwrap(),
986            write_db_mutex_lock_nanos: register_int_counter_vec_with_registry!(
987                "write_db_mutex_lock_nanos",
988                "Time spent on acquiring db mutex",
989                &["cf_name"],
990                registry;
991                MetricLevel::Trace,
992            )
993            .unwrap(),
994            write_db_condition_wait_nanos: register_int_counter_vec_with_registry!(
995                "write_db_condition_wait_nanos",
996                "Time spent waiting with a condition variable created with DB Mutex.",
997                &["cf_name"],
998                registry;
999                MetricLevel::Trace,
1000            )
1001            .unwrap(),
1002            write_key_lock_wait_nanos: register_int_counter_vec_with_registry!(
1003                "write_key_lock_wait_time",
1004                "Time spent waiting on key locks in transaction lock manager",
1005                &["cf_name"],
1006                registry;
1007                MetricLevel::Trace,
1008            )
1009            .unwrap(),
1010            write_key_lock_wait_count: register_int_counter_vec_with_registry!(
1011                "write_key_lock_wait_count",
1012                "Number of times acquiring a lock was blocked by another transaction",
1013                &["cf_name"],
1014                registry;
1015                MetricLevel::Trace,
1016            )
1017            .unwrap(),
1018        }
1019    }
1020    pub fn report_metrics(&self, db_name: &str) {
1021        PER_THREAD_ROCKS_PERF_CONTEXT.with(|perf_context_cell| {
1022            set_perf_stats(PerfStatsLevel::Disable);
1023            let perf_context = perf_context_cell.borrow();
1024            self.write_wal_nanos
1025                .with_label_values(&[db_name])
1026                .inc_by(perf_context.metric(PerfMetric::WriteWalTime));
1027            self.write_memtable_nanos
1028                .with_label_values(&[db_name])
1029                .inc_by(perf_context.metric(PerfMetric::WriteMemtableTime));
1030            self.write_delay_nanos
1031                .with_label_values(&[db_name])
1032                .inc_by(perf_context.metric(PerfMetric::WriteDelayTime));
1033            self.write_pre_and_post_process_nanos
1034                .with_label_values(&[db_name])
1035                .inc_by(perf_context.metric(PerfMetric::WritePreAndPostProcessTime));
1036            self.write_db_mutex_lock_nanos
1037                .with_label_values(&[db_name])
1038                .inc_by(perf_context.metric(PerfMetric::DbMutexLockNanos));
1039            self.write_db_condition_wait_nanos
1040                .with_label_values(&[db_name])
1041                .inc_by(perf_context.metric(PerfMetric::DbConditionWaitNanos));
1042            self.write_key_lock_wait_nanos
1043                .with_label_values(&[db_name])
1044                .inc_by(perf_context.metric(PerfMetric::KeyLockWaitTime));
1045            self.write_key_lock_wait_count
1046                .with_label_values(&[db_name])
1047                .inc_by(perf_context.metric(PerfMetric::KeyLockWaitCount));
1048        });
1049    }
1050}
1051
1052#[derive(Debug)]
1053pub struct DBMetrics {
1054    pub op_metrics: OperationMetrics,
1055    pub cf_metrics: ColumnFamilyMetrics,
1056    pub read_perf_ctx_metrics: ReadPerfContextMetrics,
1057    pub write_perf_ctx_metrics: WritePerfContextMetrics,
1058}
1059
1060static ONCE: OnceCell<Arc<DBMetrics>> = OnceCell::new();
1061
1062impl DBMetrics {
1063    fn new(registry: &Registry) -> Self {
1064        DBMetrics {
1065            op_metrics: OperationMetrics::new(registry),
1066            cf_metrics: ColumnFamilyMetrics::new(registry),
1067            read_perf_ctx_metrics: ReadPerfContextMetrics::new(registry),
1068            write_perf_ctx_metrics: WritePerfContextMetrics::new(registry),
1069        }
1070    }
1071    pub fn init(registry: &Registry) -> &'static Arc<DBMetrics> {
1072        // Initialize this before creating any instance of DBMap
1073        // TODO: Remove static initialization because this basically means we can
1074        // only ever initialize db metrics once with a registry whereas
1075        // in the code we might want to initialize it with different
1076        // registries. The problem is underlying metrics cannot be re-initialized
1077        // or prometheus complains. We essentially need to pass in DBMetrics
1078        // everywhere we create DBMap as the right fix
1079        let _ = ONCE
1080            .set(Arc::new(DBMetrics::new(registry)))
1081            // this happens many times during tests
1082            .tap_err(|_| warn!("DBMetrics registry overwritten"));
1083        ONCE.get().unwrap()
1084    }
1085    pub fn increment_num_active_dbs(&self, db_name: &str) {
1086        self.op_metrics
1087            .rocksdb_num_active_db_handles
1088            .with_label_values(&[db_name])
1089            .inc();
1090    }
1091    pub fn decrement_num_active_dbs(&self, db_name: &str) {
1092        self.op_metrics
1093            .rocksdb_num_active_db_handles
1094            .with_label_values(&[db_name])
1095            .dec();
1096    }
1097    pub fn get() -> &'static Arc<DBMetrics> {
1098        // Lazily initialize against the global default registry when no explicit
1099        // `init` has run. `get_or_init` ensures the rocksdb metrics are
1100        // registered at most once even when first reached concurrently.
1101        ONCE.get_or_init(|| Arc::new(DBMetrics::new(prometheus_filtered::default_registry())))
1102    }
1103}
typed_store/metrics.rs

typed_store/
metrics.rs
