1#![deny(missing_docs)]
2#[macro_use]
5extern crate diesel;
6#[macro_use]
7extern crate diesel_migrations;
8use tracing::{debug, error, info, warn};
9
10use diesel::prelude::*;
11use diesel::{insert_into, sql_query};
12
13use metrics::{GaugeValue, Key, KeyName, SetRecorderError, SharedString, Unit};
14
15use diesel_migrations::{EmbeddedMigrations, MigrationHarness};
16use std::sync::Mutex;
17use std::{
18 collections::{HashMap, VecDeque},
19 path::{Path, PathBuf},
20 sync::mpsc::{Receiver, RecvTimeoutError, SyncSender},
21 thread::{self, JoinHandle},
22 time::{Duration, Instant},
23};
24use thiserror::Error;
25
26const FLUSH_QUEUE_LIMIT: usize = 1000;
28const BACKGROUND_CHANNEL_LIMIT: usize = 8000;
29const SQLITE_DEFAULT_MAX_VARIABLES: usize = 999;
30const METRIC_FIELDS_PER_ROW: usize = 3;
31const INSERT_BATCH_SIZE: usize = SQLITE_DEFAULT_MAX_VARIABLES / METRIC_FIELDS_PER_ROW;
32const QUEUE_HARD_LIMIT: usize = 100_000;
36const RECONNECT_AFTER_FAILURES: u64 = 3;
39const RECONNECT_BACKOFF: Duration = Duration::from_secs(30);
41const ERROR_LOG_INTERVAL: Duration = Duration::from_secs(60);
43
44struct LogThrottle {
47 interval: Duration,
48 last_logged: Option<Instant>,
49 suppressed: u64,
50}
51impl LogThrottle {
52 const fn new(interval: Duration) -> Self {
53 LogThrottle {
54 interval,
55 last_logged: None,
56 suppressed: 0,
57 }
58 }
59 fn allow(&mut self) -> Option<u64> {
62 let now = Instant::now();
63 let due = match self.last_logged {
64 Some(last) => now.duration_since(last) >= self.interval,
65 None => true,
66 };
67 if due {
68 self.last_logged = Some(now);
69 Some(std::mem::take(&mut self.suppressed))
70 } else {
71 self.suppressed += 1;
72 None
73 }
74 }
75
76 fn log_if_due(&mut self, emit: impl FnOnce(u64)) {
80 if let Some(suppressed) = self.allow() {
81 emit(suppressed);
82 }
83 }
84}
85
86#[derive(Debug, Error)]
88pub enum MetricsError {
89 #[error("Database error: {0}")]
91 DbConnectionError(#[from] ConnectionError),
92 #[error("Migration error: {0}")]
94 MigrationError(Box<dyn std::error::Error + Send + Sync>),
95 #[error("Error querying DB: {0}")]
97 QueryError(#[from] diesel::result::Error),
98 #[error("Invalid database path")]
100 InvalidDatabasePath,
101 #[cfg(feature = "csv")]
103 #[error("IO Error: {0}")]
104 IoError(#[from] std::io::Error),
105 #[cfg(feature = "csv")]
107 #[error("CSV Error: {0}")]
108 CsvError(#[from] csv::Error),
109 #[error("Database has no metrics stored in it")]
111 EmptyDatabase,
112 #[error("Metric key {0} not found in database")]
114 KeyNotFound(String),
115 #[error("Exporter task has been stopped or crashed")]
117 ExporterUnavailable,
118 #[error("Session for signpost `{0}` has zero duration")]
120 ZeroLengthSession(String),
121 #[error("No metrics recorded for `{0}` in requested session")]
123 NoMetricsForKey(String),
124}
125
126impl MetricsError {
127 fn is_malformed_db(&self) -> bool {
129 self.to_string().contains("malformed")
130 }
131}
132
133pub type Result<T, E = MetricsError> = std::result::Result<T, E>;
135
136mod maintenance;
137mod metrics_db;
138mod models;
139mod recorder;
140mod schema;
141
142use crate::metrics_db::query;
143pub use metrics_db::{MetricsDb, Session};
144pub use models::{Metric, MetricKey, NewMetric};
145
146pub(crate) const MIGRATIONS: EmbeddedMigrations = embed_migrations!();
147
148#[derive(QueryableByName)]
149struct PragmaCheckResult {
150 #[diesel(sql_type = diesel::sql_types::Text)]
151 #[diesel(column_name = quick_check)]
152 result: String,
153}
154
155fn remove_db_files(path: &Path) {
157 let db_path = PathBuf::from(path);
158 for suffix in &["", "-wal", "-shm"] {
159 let mut file_path = db_path.clone().into_os_string();
160 file_path.push(suffix);
161 let file_path = PathBuf::from(file_path);
162 if file_path.exists() {
163 if let Err(e) = std::fs::remove_file(&file_path) {
164 error!("Failed to remove {}: {}", file_path.display(), e);
165 } else {
166 info!("Removed corrupt database file: {}", file_path.display());
167 }
168 }
169 }
170}
171
172fn setup_db<P: AsRef<Path>>(path: P) -> Result<SqliteConnection> {
173 let url = path
174 .as_ref()
175 .to_str()
176 .ok_or(MetricsError::InvalidDatabasePath)?;
177 let mut db = SqliteConnection::establish(url)?;
178
179 sql_query("PRAGMA journal_mode=WAL;").execute(&mut db)?;
181
182 sql_query("PRAGMA busy_timeout = 5000;").execute(&mut db)?;
184
185 sql_query("PRAGMA journal_size_limit = 4194304;").execute(&mut db)?;
188
189 db.run_pending_migrations(MIGRATIONS)
190 .map_err(MetricsError::MigrationError)?;
191
192 let check: String = sql_query("PRAGMA quick_check;")
194 .get_result::<PragmaCheckResult>(&mut db)?
195 .result;
196 if check != "ok" {
197 return Err(MetricsError::QueryError(
198 diesel::result::Error::DatabaseError(
199 diesel::result::DatabaseErrorKind::Unknown,
200 Box::new(format!("database disk image is malformed: {check}")),
201 ),
202 ));
203 }
204
205 Ok(db)
206}
207
208fn setup_db_or_reset<P: AsRef<Path>>(path: P) -> Result<(SqliteConnection, bool)> {
213 let path = path.as_ref();
214 match setup_db(path) {
215 Ok(db) => Ok((db, false)),
216 Err(err) if err.is_malformed_db() => {
217 warn!(
218 "Database is malformed, removing and recreating: {}",
219 path.display()
220 );
221 remove_db_files(path);
222 setup_db(path).map(|db| (db, true))
223 }
224 Err(err) => Err(err),
225 }
226}
227enum RegisterType {
228 Counter,
229 Gauge,
230 Histogram,
231}
232
233enum Event {
234 Stop,
235 DescribeKey(RegisterType, KeyName, Option<Unit>, SharedString),
236 IncrementCounter(Duration, Key, u64),
237 AbsoluteCounter(Duration, Key, u64),
238 UpdateGauge(Duration, Key, GaugeValue),
239 UpdateHistogram(Duration, Key, f64),
240 SetHousekeeping {
241 retention_period: Option<Duration>,
242 housekeeping_period: Option<Duration>,
243 record_limit: Option<usize>,
244 },
245 RequestSummaryFromSignpost {
246 signpost_key: String,
247 keys: Vec<String>,
248 tx: tokio::sync::oneshot::Sender<Result<HashMap<String, f64>>>,
249 },
250}
251
252pub struct SqliteExporterHandle {
254 sender: SyncSender<Event>,
255}
256impl SqliteExporterHandle {
257 pub fn request_average_metrics(
259 &self,
260 from_signpost: &str,
261 with_keys: &[&str],
262 ) -> Result<HashMap<String, f64>> {
263 let (tx, rx) = tokio::sync::oneshot::channel();
264 self.sender
265 .send(Event::RequestSummaryFromSignpost {
266 signpost_key: from_signpost.to_string(),
267 keys: with_keys.iter().map(|s| s.to_string()).collect(),
268 tx,
269 })
270 .map_err(|_| MetricsError::ExporterUnavailable)?;
271 match rx.blocking_recv() {
272 Ok(metrics) => Ok(metrics?),
273 Err(_) => Err(MetricsError::ExporterUnavailable),
274 }
275 }
276}
277
278pub struct SqliteExporter {
280 thread: Option<JoinHandle<()>>,
281 sender: SyncSender<Event>,
282 send_error_throttle: Mutex<LogThrottle>,
283}
284struct InnerState {
285 db: SqliteConnection,
286 db_path: PathBuf,
287 last_housekeeping: Instant,
288 housekeeping: Option<Duration>,
289 retention: Option<Duration>,
290 default_retention: Option<Duration>,
291 record_limit: Option<usize>,
292 inserted_since_housekeeping: usize,
293 maintenance: Option<maintenance::Maintenance>,
294 startup_cleanup_pending: bool,
295 last_maintenance_step: Instant,
296 last_vacuum_attempt: Option<Instant>,
297 flush_duration: Duration,
298 last_flush: Instant,
299 last_values: HashMap<Key, f64>,
300 counters: HashMap<Key, u64>,
301 key_ids: HashMap<String, i64>,
302 queue: VecDeque<NewMetric>,
303 consecutive_flush_failures: u64,
304 last_reconnect: Option<Instant>,
305}
306impl InnerState {
307 fn new(flush_duration: Duration, db: SqliteConnection, db_path: PathBuf) -> Self {
308 InnerState {
309 db,
310 db_path,
311 last_housekeeping: Instant::now(),
312 housekeeping: None,
313 retention: None,
314 default_retention: None,
315 record_limit: None,
316 inserted_since_housekeeping: 0,
317 maintenance: None,
318 startup_cleanup_pending: false,
319 last_maintenance_step: Instant::now(),
320 last_vacuum_attempt: None,
321 flush_duration,
322 last_flush: Instant::now(),
323 last_values: HashMap::new(),
324 counters: HashMap::new(),
325 key_ids: HashMap::new(),
326 queue: VecDeque::with_capacity(FLUSH_QUEUE_LIMIT),
327 consecutive_flush_failures: 0,
328 last_reconnect: None,
329 }
330 }
331 fn set_housekeeping(
332 &mut self,
333 retention: Option<Duration>,
334 housekeeping_duration: Option<Duration>,
335 record_limit: Option<usize>,
336 ) {
337 self.retention = retention.or(self.default_retention);
338 self.housekeeping = housekeeping_duration;
339 self.last_housekeeping = Instant::now();
340 self.record_limit = record_limit;
341 if !self.startup_cleanup_pending {
344 self.maintenance = self.maintenance.as_ref().and_then(|_| {
345 housekeeping_duration
346 .map(|_| maintenance::Maintenance::new(self.retention, self.record_limit))
347 });
348 }
349 self.inserted_since_housekeeping = 0;
350 }
351 fn should_housekeep(&self) -> bool {
352 match self.housekeeping {
353 Some(duration) => {
354 let row_trigger = self.record_limit.map_or(100_000, |limit| {
355 (limit / 4).clamp(FLUSH_QUEUE_LIMIT, 100_000)
356 });
357 self.last_housekeeping.elapsed() >= duration
358 || ((self.retention.is_some() || self.record_limit.is_some())
359 && self.inserted_since_housekeeping >= row_trigger
360 && self.last_housekeeping.elapsed() >= Duration::from_secs(1))
361 }
362 None => false,
363 }
364 }
365 fn housekeep(&mut self) -> Result<(), diesel::result::Error> {
366 let result = self.housekeep_step();
367 self.last_maintenance_step = Instant::now();
370 result
371 }
372 fn housekeep_step(&mut self) -> Result<(), diesel::result::Error> {
373 if self.maintenance.is_none() {
374 self.maintenance = Some(maintenance::Maintenance::new(
375 self.retention,
376 self.record_limit,
377 ));
378 self.last_housekeeping = Instant::now();
379 self.inserted_since_housekeeping = 0;
380 }
381 if self.maintenance.as_mut().unwrap().step(&mut self.db)? {
382 self.maintenance = None;
383 self.startup_cleanup_pending = false;
384 let reclaim = maintenance::reclaim(&mut self.db, &mut self.last_vacuum_attempt);
385 let checkpoint = maintenance::checkpoint(&mut self.db);
387 reclaim?;
388 checkpoint?;
389 }
390 Ok(())
391 }
392 fn should_flush(&self) -> bool {
393 if self.last_flush.elapsed() > self.flush_duration {
394 true
395 } else if self.queue.len() >= FLUSH_QUEUE_LIMIT {
396 debug!("Flushing due to queue size ({} items)", self.queue.len());
397 true
398 } else {
399 false
400 }
401 }
402 fn flush(&mut self) -> Result<(), diesel::result::Error> {
403 if self.queue.is_empty() {
404 self.last_flush = Instant::now();
405 return Ok(());
406 }
407 let (front, back) = self.queue.as_slices();
413 match Self::insert_metrics(&mut self.db, [front, back]) {
414 Ok(()) => {
415 self.inserted_since_housekeeping = self
416 .inserted_since_housekeeping
417 .saturating_add(self.queue.len());
418 self.queue.clear();
419 self.last_flush = Instant::now();
420 self.consecutive_flush_failures = 0;
421 Ok(())
422 }
423 Err(e) => {
424 self.consecutive_flush_failures += 1;
425 self.enforce_queue_cap();
427 if Self::is_connection_fatal(&e)
431 || self.consecutive_flush_failures >= RECONNECT_AFTER_FAILURES
432 {
433 self.reconnect();
434 }
435 Err(e)
436 }
437 }
438 }
439
440 fn insert_metrics<'a, S>(
444 db: &mut SqliteConnection,
445 slabs: S,
446 ) -> Result<(), diesel::result::Error>
447 where
448 S: IntoIterator<Item = &'a [NewMetric]>,
449 {
450 use crate::schema::metrics::dsl::metrics;
451 db.transaction::<_, diesel::result::Error, _>(|db| {
452 let chunk_size = INSERT_BATCH_SIZE.max(1);
453 for slab in slabs {
454 for chunk in slab.chunks(chunk_size) {
455 insert_into(metrics).values(chunk).execute(db)?;
456 }
457 }
458 Ok(())
459 })
460 }
461
462 fn enforce_queue_cap(&mut self) {
465 if self.queue.len() > QUEUE_HARD_LIMIT {
466 let overflow = self.queue.len() - QUEUE_HARD_LIMIT;
467 self.queue.drain(..overflow);
468 warn!(
469 "metrics-sqlite queue exceeded {} items while flushing kept failing, dropped {} oldest metrics",
470 QUEUE_HARD_LIMIT, overflow
471 );
472 }
473 }
474
475 fn is_connection_fatal(e: &diesel::result::Error) -> bool {
478 matches!(e, diesel::result::Error::BrokenTransactionManager)
479 }
480
481 fn reconnect(&mut self) {
484 if let Some(last) = self.last_reconnect {
485 if last.elapsed() < RECONNECT_BACKOFF {
486 return;
487 }
488 }
489 self.last_reconnect = Some(Instant::now());
490 warn!(
491 "metrics-sqlite database connection is broken, reconnecting to {}",
492 self.db_path.display()
493 );
494 match setup_db_or_reset(&self.db_path) {
495 Ok((db, was_reset)) => {
496 self.db = db;
497 self.key_ids.clear();
499 self.consecutive_flush_failures = 0;
500 if was_reset {
501 let dropped = self.queue.len();
506 if dropped > 0 {
507 warn!(
508 "metrics-sqlite database was recreated; dropping {dropped} queued metrics with stale key ids"
509 );
510 self.queue.clear();
511 }
512 }
513 info!("metrics-sqlite database connection re-established");
514 }
515 Err(e) => {
516 error!("metrics-sqlite failed to reconnect to database: {:?}", e);
517 }
518 }
519 }
520 fn queue_metric(&mut self, timestamp: Duration, key: &str, value: f64) -> Result<()> {
521 let metric_key_id = match self.key_ids.get(key) {
522 Some(key) => *key,
523 None => {
524 debug!("Looking up {}", key);
525 let key_id = MetricKey::key_by_name(key, &mut self.db)?.id;
526 self.key_ids.insert(key.to_string(), key_id);
527 key_id
528 }
529 };
530 let metric = NewMetric {
531 timestamp: timestamp.as_secs_f64(),
532 metric_key_id,
533 value: value as _,
534 };
535 self.queue.push_back(metric);
536 Ok(())
537 }
538
539 pub fn metrics_summary_for_signpost_and_keys(
542 &mut self,
543 signpost: String,
544 metrics: Vec<String>,
545 ) -> Result<HashMap<String, f64>> {
546 query::metrics_summary_for_signpost_and_keys(&mut self.db, &signpost, metrics)
547 }
548}
549
550fn run_worker(
551 db: SqliteConnection,
552 db_path: PathBuf,
553 receiver: Receiver<Event>,
554 flush_duration: Duration,
555 keep_duration: Option<Duration>,
556) -> JoinHandle<()> {
557 thread::Builder::new()
558 .name("metrics-sqlite: worker".to_string())
559 .spawn(move || {
560 let mut state = InnerState::new(flush_duration, db, db_path);
561 state.default_retention = keep_duration;
562 state.retention = keep_duration;
563 if keep_duration.is_some() {
564 state.maintenance = Some(maintenance::Maintenance::new(keep_duration, None));
565 state.startup_cleanup_pending = true;
566 }
567 let mut flush_error_throttle = LogThrottle::new(ERROR_LOG_INTERVAL);
568 let mut queue_error_throttle = LogThrottle::new(ERROR_LOG_INTERVAL);
569 info!("SQLite worker started");
570 loop {
571 let time_based_flush = state.last_flush.elapsed() >= flush_duration;
573
574 let mut should_flush = false;
575 let mut should_exit = false;
576 let wait = if state.maintenance.is_some() {
577 flush_duration.min(maintenance::STEP_INTERVAL)
578 } else {
579 flush_duration
580 };
581 match receiver.recv_timeout(wait) {
582 Ok(Event::Stop) => {
583 info!("Stopping SQLiteExporter worker, flushing & exiting");
584 should_flush = true;
585 should_exit = true;
586 }
587 Ok(Event::SetHousekeeping {
588 retention_period,
589 housekeeping_period,
590 record_limit,
591 }) => {
592 state.set_housekeeping(retention_period, housekeeping_period, record_limit);
593 }
594 Ok(Event::DescribeKey(_key_type, key, unit, desc)) => {
595 info!("Describing key {:?}", key);
596 if let Err(e) = MetricKey::create_or_update(
597 key.as_str(),
598 unit,
599 Some(desc.as_ref()),
600 &mut state.db,
601 ) {
602 error!("Failed to create key entry: {:?}", e);
603 }
604 }
605 Ok(Event::IncrementCounter(timestamp, key, value)) => {
606 let key_name = key.name();
607 let entry = state.counters.entry(key.clone()).or_insert(0);
608 let value = {
609 *entry += value;
610 *entry
611 };
612 if let Err(e) = state.queue_metric(timestamp, key_name, value as _) {
613 queue_error_throttle.log_if_due(|suppressed| {
614 if suppressed > 0 {
615 error!(
616 "Error queueing metric: {:?} ({} similar errors suppressed in the last {}s)",
617 e,
618 suppressed,
619 ERROR_LOG_INTERVAL.as_secs()
620 );
621 } else {
622 error!("Error queueing metric: {:?}", e);
623 }
624 });
625 }
626 should_flush = state.should_flush();
627 }
628 Ok(Event::AbsoluteCounter(timestamp, key, value)) => {
629 let key_name = key.name();
630 state.counters.insert(key.clone(), value);
631 if let Err(e) = state.queue_metric(timestamp, key_name, value as _) {
632 queue_error_throttle.log_if_due(|suppressed| {
633 if suppressed > 0 {
634 error!(
635 "Error queueing metric: {:?} ({} similar errors suppressed in the last {}s)",
636 e,
637 suppressed,
638 ERROR_LOG_INTERVAL.as_secs()
639 );
640 } else {
641 error!("Error queueing metric: {:?}", e);
642 }
643 });
644 }
645 should_flush = state.should_flush();
646 }
647 Ok(Event::UpdateGauge(timestamp, key, value)) => {
648 let key_name = key.name();
649 let entry = state.last_values.entry(key.clone()).or_insert(0.0);
650 let value = match value {
651 GaugeValue::Absolute(v) => {
652 *entry = v;
653 *entry
654 }
655 GaugeValue::Increment(v) => {
656 *entry += v;
657 *entry
658 }
659 GaugeValue::Decrement(v) => {
660 *entry -= v;
661 *entry
662 }
663 };
664 if let Err(e) = state.queue_metric(timestamp, key_name, value) {
665 queue_error_throttle.log_if_due(|suppressed| {
666 if suppressed > 0 {
667 error!(
668 "Error queueing metric: {:?} ({} similar errors suppressed in the last {}s)",
669 e,
670 suppressed,
671 ERROR_LOG_INTERVAL.as_secs()
672 );
673 } else {
674 error!("Error queueing metric: {:?}", e);
675 }
676 });
677 }
678 should_flush = state.should_flush();
679 }
680 Ok(Event::UpdateHistogram(timestamp, key, value)) => {
681 let key_name = key.name();
682 if let Err(e) = state.queue_metric(timestamp, key_name, value) {
683 queue_error_throttle.log_if_due(|suppressed| {
684 if suppressed > 0 {
685 error!(
686 "Error queueing metric: {:?} ({} similar errors suppressed in the last {}s)",
687 e,
688 suppressed,
689 ERROR_LOG_INTERVAL.as_secs()
690 );
691 } else {
692 error!("Error queueing metric: {:?}", e);
693 }
694 });
695 }
696 should_flush = state.should_flush();
697 }
698 Ok(Event::RequestSummaryFromSignpost {
699 signpost_key,
700 keys,
701 tx,
702 }) => {
703 match state.flush() {
704 Ok(()) => match state
705 .metrics_summary_for_signpost_and_keys(signpost_key, keys)
706 {
707 Ok(metrics) => {
708 if tx.send(Ok(metrics)).is_err() {
709 error!(
710 "Failed to respond with metrics results, discarding"
711 );
712 }
713 }
714 Err(e) => {
715 if let Err(e) = tx.send(Err(e)) {
716 error!(
717 "Failed to respond with metrics error result, discarding: {e:?}"
718 );
719 }
720 }
721 },
722 Err(e) => {
723 let err = MetricsError::from(e);
724 error!(
725 "Failed to flush pending metrics before summary request: {err:?}"
726 );
727 if let Err(send_err) = tx.send(Err(err)) {
728 error!(
729 "Failed to respond with metrics flush error result, discarding: {send_err:?}"
730 );
731 }
732 }
733 }
734 }
735 Err(RecvTimeoutError::Timeout) => {
736 should_flush = state.should_flush();
737 }
738 Err(RecvTimeoutError::Disconnected) => {
739 warn!("SQLiteExporter channel disconnected, exiting worker");
740 should_flush = true;
741 should_exit = true;
742 }
743 }
744
745 if time_based_flush || should_flush {
747 if time_based_flush {
748 debug!("Flushing due to elapsed time ({}s)", flush_duration.as_secs());
749 }
750 if let Err(e) = state.flush() {
751 if let Some(suppressed) = flush_error_throttle.allow() {
752 if suppressed > 0 {
753 error!(
754 "Error flushing metrics: {} ({} similar errors suppressed in the last {}s)",
755 e,
756 suppressed,
757 ERROR_LOG_INTERVAL.as_secs()
758 );
759 } else {
760 error!("Error flushing metrics: {}", e);
761 }
762 }
763 }
764 }
765 if should_exit {
766 let _ = maintenance::checkpoint(&mut state.db);
767 break;
768 }
769 if (state.maintenance.is_some() || state.should_housekeep())
770 && state.last_maintenance_step.elapsed() >= maintenance::STEP_INTERVAL
771 {
772 if let Err(e) = state.housekeep() {
773 error!("Failed running house keeping: {:?}", e);
774 state.maintenance = None;
775 state.startup_cleanup_pending = false;
776 state.last_housekeeping = Instant::now();
777 state.inserted_since_housekeeping = 0;
778 }
779 }
780 }
781 })
782 .unwrap()
783}
784
785impl SqliteExporter {
786 pub fn new<P: AsRef<Path>>(
794 flush_interval: Duration,
795 keep_duration: Option<Duration>,
796 path: P,
797 ) -> Result<Self> {
798 let path = path.as_ref().to_path_buf();
799 let (db, _was_reset) = setup_db_or_reset(&path)?;
800 let (sender, receiver) = std::sync::mpsc::sync_channel(BACKGROUND_CHANNEL_LIMIT);
801 let thread = run_worker(db, path, receiver, flush_interval, keep_duration);
802 let exporter = SqliteExporter {
803 thread: Some(thread),
804 sender,
805 send_error_throttle: Mutex::new(LogThrottle::new(ERROR_LOG_INTERVAL)),
806 };
807 Ok(exporter)
808 }
809
810 pub fn set_periodic_housekeeping(
822 &self,
823 periodic_duration: Option<Duration>,
824 retention: Option<Duration>,
825 record_limit: Option<usize>,
826 ) {
827 if let Err(e) = self.sender.send(Event::SetHousekeeping {
828 retention_period: retention,
829 housekeeping_period: periodic_duration,
830 record_limit,
831 }) {
832 error!("Failed to set house keeping settings: {:?}", e);
833 }
834 }
835
836 fn log_send_failure(&self, context: &str, err: &dyn std::fmt::Debug) {
839 if let Ok(mut throttle) = self.send_error_throttle.lock() {
840 if let Some(suppressed) = throttle.allow() {
841 if suppressed > 0 {
842 error!(
843 "Error sending metric {} to SQLite worker: {:?} ({} similar errors suppressed in the last {}s)",
844 context,
845 err,
846 suppressed,
847 ERROR_LOG_INTERVAL.as_secs()
848 );
849 } else {
850 error!(
851 "Error sending metric {} to SQLite worker: {:?}",
852 context, err
853 );
854 }
855 }
856 }
857 }
858
859 pub fn install(self) -> Result<SqliteExporterHandle, SetRecorderError<Self>> {
861 let handle = SqliteExporterHandle {
862 sender: self.sender.clone(),
863 };
864 metrics::set_global_recorder(self)?;
865 Ok(handle)
866 }
867}
868impl Drop for SqliteExporter {
869 fn drop(&mut self) {
870 let _ = self.sender.send(Event::Stop);
871 let _ = self.thread.take().unwrap().join();
872 }
873}
874
875#[cfg(test)]
876mod tests {
877 use crate::{
878 InnerState, LogThrottle, NewMetric, QUEUE_HARD_LIMIT, SqliteExporter, setup_db_or_reset,
879 };
880 use std::time::{Duration, Instant};
881
882 fn test_state() -> (InnerState, tempfile::TempDir) {
883 let dir = tempfile::tempdir().unwrap();
884 let path = dir.path().join("metrics.db");
885 let (db, _was_reset) = setup_db_or_reset(&path).unwrap();
886 (InnerState::new(Duration::from_secs(5), db, path), dir)
887 }
888
889 #[test]
890 fn configuring_housekeeping_preserves_pending_startup_cleanup() {
891 let (mut state, _dir) = test_state();
892 state.default_retention = Some(Duration::from_secs(60));
893 state.startup_cleanup_pending = true;
894 state.maintenance = Some(crate::maintenance::Maintenance::new(
895 state.default_retention,
896 None,
897 ));
898 state.queue_metric(Duration::ZERO, "old", 1.0).unwrap();
899 state.flush().unwrap();
900 state.set_housekeeping(None, Some(Duration::from_secs(1800)), None);
901 assert!(state.maintenance.is_some());
902 while state.maintenance.is_some() {
903 state.housekeep().unwrap();
904 }
905 use diesel::prelude::*;
906 assert_eq!(
907 crate::schema::metrics::table
908 .count()
909 .get_result::<i64>(&mut state.db)
910 .unwrap(),
911 0
912 );
913 }
914
915 #[test]
916 fn disabling_periodic_cleanup_cancels_remaining_batches() {
917 let (mut state, _dir) = test_state();
918 for _ in 0..2500 {
919 state.queue_metric(Duration::ZERO, "old", 1.0).unwrap();
920 }
921 state.flush().unwrap();
922 state.set_housekeeping(
923 Some(Duration::from_secs(60)),
924 Some(Duration::from_secs(1)),
925 None,
926 );
927 state.housekeep().unwrap();
928 assert!(state.maintenance.is_some());
929 state.set_housekeeping(Some(Duration::from_secs(60)), None, None);
930 assert!(state.maintenance.is_none());
931 assert!(!state.should_housekeep());
932 use diesel::prelude::*;
933 assert_eq!(
934 crate::schema::metrics::table
935 .count()
936 .get_result::<i64>(&mut state.db)
937 .unwrap(),
938 1500
939 );
940 }
941
942 #[test]
943 fn disabling_periodic_cleanup_preserves_startup_policy() {
944 let (mut state, _dir) = test_state();
945 state.default_retention = Some(Duration::from_secs(60));
946 state.startup_cleanup_pending = true;
947 state.maintenance = Some(crate::maintenance::Maintenance::new(
948 state.default_retention,
949 None,
950 ));
951 state.queue_metric(Duration::ZERO, "old", 1.0).unwrap();
952 state
953 .queue_metric(
954 std::time::SystemTime::UNIX_EPOCH.elapsed().unwrap(),
955 "recent",
956 1.0,
957 )
958 .unwrap();
959 state.flush().unwrap();
960 state.set_housekeeping(None, None, Some(0));
962 while state.maintenance.is_some() {
963 state.housekeep().unwrap();
964 }
965 assert!(!state.startup_cleanup_pending);
966 assert!(!state.should_housekeep());
967 use diesel::prelude::*;
968 assert_eq!(
969 crate::schema::metrics::table
970 .count()
971 .get_result::<i64>(&mut state.db)
972 .unwrap(),
973 1
974 );
975 }
976
977 #[test]
978 fn maintenance_interval_starts_after_sqlite_lock_wait() {
979 use diesel::{prelude::*, sql_query};
980 let (mut state, _dir) = test_state();
981 state.queue_metric(Duration::ZERO, "old", 1.0).unwrap();
982 state.flush().unwrap();
983 state.set_housekeeping(
984 Some(Duration::from_secs(60)),
985 Some(Duration::from_secs(1)),
986 None,
987 );
988 let mut blocker = crate::setup_db(&state.db_path).unwrap();
989 sql_query("BEGIN IMMEDIATE").execute(&mut blocker).unwrap();
990 let unlocker = std::thread::spawn(move || {
991 std::thread::sleep(Duration::from_millis(100));
992 let released = Instant::now();
993 sql_query("COMMIT").execute(&mut blocker).unwrap();
994 released
995 });
996 state.housekeep().unwrap();
997 let released = unlocker.join().unwrap();
998 assert!(
999 state.last_maintenance_step >= released,
1000 "the interval must start after waiting for SQLite, not before"
1001 );
1002 }
1003
1004 #[test]
1005 fn failed_vacuum_is_throttled_and_does_not_skip_checkpoint() {
1006 use diesel::{prelude::*, sql_query};
1007 let (mut state, _dir) = test_state();
1008 sql_query("CREATE TABLE ballast (data BLOB)")
1009 .execute(&mut state.db)
1010 .unwrap();
1011 sql_query("WITH RECURSIVE n(x) AS (VALUES(1) UNION ALL SELECT x+1 FROM n WHERE x<1100) INSERT INTO ballast SELECT zeroblob(65536) FROM n")
1012 .execute(&mut state.db).unwrap();
1013 sql_query("DELETE FROM ballast")
1014 .execute(&mut state.db)
1015 .unwrap();
1016 let wal = state.db_path.with_file_name("metrics.db-wal");
1017 assert!(std::fs::metadata(&wal).unwrap().len() > 0);
1018 sql_query("PRAGMA query_only = ON")
1020 .execute(&mut state.db)
1021 .unwrap();
1022 assert!(state.housekeep().is_err());
1023 let attempt = state
1024 .last_vacuum_attempt
1025 .expect("failed VACUUM records its attempt");
1026 assert_eq!(
1027 std::fs::metadata(&wal).unwrap().len(),
1028 0,
1029 "checkpoint must run even when reclamation fails"
1030 );
1031 state.housekeep().unwrap();
1032 assert_eq!(state.last_vacuum_attempt, Some(attempt));
1033 state.last_vacuum_attempt = Some(Instant::now() - crate::maintenance::VACUUM_INTERVAL);
1034 assert!(
1035 state.housekeep().is_err(),
1036 "retry after the cooldown expires"
1037 );
1038 assert!(state.last_vacuum_attempt.unwrap() > attempt);
1039 }
1040
1041 #[test]
1042 fn housekeeping_inherits_retention_and_counts_only_successful_writes() {
1043 let (mut state, _dir) = test_state();
1044 let default = Duration::from_secs(60);
1045 state.default_retention = Some(default);
1046 state.set_housekeeping(None, Some(Duration::from_secs(1800)), Some(1000));
1047 assert_eq!(state.retention, Some(default));
1048 state.last_housekeeping = Instant::now() - Duration::from_secs(2);
1049 for _ in 0..1000 {
1050 state.queue_metric(Duration::ZERO, "test", 1.0).unwrap();
1051 }
1052 assert!(!state.should_housekeep());
1053 state.flush().unwrap();
1054 assert!(state.should_housekeep());
1055 state.housekeep().unwrap();
1056 while state.maintenance.is_some() {
1057 state.housekeep().unwrap();
1058 }
1059 use diesel::prelude::*;
1060 assert_eq!(
1061 crate::schema::metrics::table
1062 .count()
1063 .get_result::<i64>(&mut state.db)
1064 .unwrap(),
1065 0
1066 );
1067 assert!(!state.should_housekeep());
1068 state.set_housekeeping(Some(Duration::from_secs(120)), None, Some(1000));
1069 assert_eq!(state.retention, Some(Duration::from_secs(120)));
1070 state.inserted_since_housekeeping = 100_000;
1071 assert!(
1072 !state.should_housekeep(),
1073 "disabled housekeeping ignores row trigger"
1074 );
1075 }
1076
1077 #[test]
1078 fn enforce_queue_cap_drops_oldest_when_over_limit() {
1079 let (mut state, _dir) = test_state();
1080 let total = QUEUE_HARD_LIMIT + 250;
1083 for i in 0..total {
1084 state.queue.push_back(NewMetric {
1085 timestamp: 0.0,
1086 metric_key_id: 1,
1087 value: i as f64,
1088 });
1089 }
1090 state.enforce_queue_cap();
1091 assert_eq!(state.queue.len(), QUEUE_HARD_LIMIT);
1093 assert_eq!(state.queue.front().unwrap().value, 250.0);
1094 assert_eq!(state.queue.back().unwrap().value, (total - 1) as f64);
1095 state.enforce_queue_cap();
1097 assert_eq!(state.queue.len(), QUEUE_HARD_LIMIT);
1098 }
1099
1100 #[test]
1101 fn failed_flush_leaves_queue_intact() {
1102 use diesel::connection::SimpleConnection;
1103 let (mut state, _dir) = test_state();
1104 state
1108 .db
1109 .batch_execute("DROP TABLE metrics")
1110 .expect("setup: drop metrics table");
1111 for i in 0..5_000 {
1112 state.queue.push_back(NewMetric {
1113 timestamp: 0.0,
1114 metric_key_id: 1,
1115 value: i as f64,
1116 });
1117 }
1118 let before = state.queue.len();
1119 assert!(state.flush().is_err(), "flush should fail");
1120 assert_eq!(state.queue.len(), before);
1122 assert_eq!(state.queue.front().unwrap().value, 0.0);
1123 assert_eq!(state.queue.back().unwrap().value, 4_999.0);
1124 assert_eq!(state.consecutive_flush_failures, 1);
1125 assert_eq!(state.inserted_since_housekeeping, 0);
1126 }
1127
1128 #[test]
1129 fn reconnect_drops_queue_when_database_is_recreated() {
1130 use crate::setup_db;
1131 use diesel::connection::SimpleConnection;
1132 use std::io::{Seek, SeekFrom, Write};
1133 let (mut state, _dir) = test_state();
1134 for i in 0..100 {
1135 state.queue.push_back(NewMetric {
1136 timestamp: 0.0,
1137 metric_key_id: 1,
1138 value: i as f64,
1139 });
1140 }
1141 state
1144 .db
1145 .batch_execute("PRAGMA wal_checkpoint(TRUNCATE)")
1146 .expect("setup: wal checkpoint");
1147 state.db = setup_db(":memory:").expect("setup: in-memory placeholder");
1154 let mut f = std::fs::OpenOptions::new()
1159 .write(true)
1160 .open(&state.db_path)
1161 .expect("setup: open db file");
1162 f.seek(SeekFrom::Start(100))
1163 .expect("setup: seek past header");
1164 f.write_all(&[0xffu8; 16 * 1024])
1165 .expect("setup: write garbage pages");
1166 f.sync_all().expect("setup: sync garbage to disk");
1167 drop(f);
1168
1169 state.reconnect();
1170
1171 assert!(
1174 state.queue.is_empty(),
1175 "queue should be cleared after reset"
1176 );
1177 assert_eq!(state.consecutive_flush_failures, 0);
1178 assert!(state.flush().is_ok());
1180 }
1181
1182 #[test]
1183 fn reconnect_rebuilds_connection_with_backoff() {
1184 let (mut state, _dir) = test_state();
1185 state.consecutive_flush_failures = 5;
1186 state.reconnect();
1187 assert_eq!(state.consecutive_flush_failures, 0);
1190 let first_attempt = state.last_reconnect.expect("reconnect should run");
1191 assert!(state.flush().is_ok());
1193
1194 state.consecutive_flush_failures = 5;
1197 state.reconnect();
1198 assert_eq!(state.consecutive_flush_failures, 5);
1199 assert_eq!(state.last_reconnect, Some(first_attempt));
1200 }
1201
1202 #[test]
1203 fn log_throttle_suppresses_and_reports_count() {
1204 let mut throttle = LogThrottle::new(Duration::from_millis(50));
1205 assert_eq!(throttle.allow(), Some(0));
1207 for _ in 0..7 {
1209 assert_eq!(throttle.allow(), None);
1210 }
1211 std::thread::sleep(Duration::from_millis(60));
1214 assert_eq!(throttle.allow(), Some(7));
1215 std::thread::sleep(Duration::from_millis(60));
1217 assert_eq!(throttle.allow(), Some(0));
1218 }
1219
1220 #[test]
1221 fn test_threading() {
1222 use std::thread;
1223 let dir = tempfile::tempdir().unwrap();
1224 let exporter = std::sync::Arc::new(
1225 SqliteExporter::new(
1226 Duration::from_millis(500),
1227 None,
1228 dir.path().join("metrics.db"),
1229 )
1230 .unwrap(),
1231 );
1232 let joins: Vec<thread::JoinHandle<()>> = (0..5)
1233 .map(|_| {
1234 let exporter = exporter.clone();
1235 thread::spawn(move || {
1236 metrics::with_local_recorder(exporter.as_ref(), || {
1237 let start = Instant::now();
1238 loop {
1239 metrics::gauge!("rate").set(1.0);
1240 metrics::counter!("hits").increment(1);
1241 metrics::histogram!("histogram").record(5.0);
1242 if start.elapsed().as_secs() >= 5 {
1243 break;
1244 }
1245 }
1246 });
1247 })
1248 })
1249 .collect();
1250 for j in joins {
1251 j.join().unwrap();
1252 }
1253 }
1254}