From e88387a87a15eb4b5f21ef2f80e1923e5aad8850 Mon Sep 17 00:00:00 2001 From: behzad nouri Date: Wed, 13 Oct 2021 13:58:02 +0000 Subject: [PATCH] uses nanos precision for timestamp when submitting metrics to influxdb (#20623) Current datapoint_info! is apparently overwriting itself when run inside a loop. For example in https://github.com/solana-labs/solana/blob/005d6863f/core/src/window_service.rs#L101-L107 only one of the slots will show up in influxdb. This is apparently because of metrics code using milliseconds as the timestamp, as mentioned here: https://github.com/solana-labs/solana/issues/19789#issuecomment-922482013 (cherry picked from commit cd87525f54abdc9c394d55647f2924e7776c7a6f) --- metrics/src/counter.rs | 21 +++++++++++++-------- metrics/src/datapoint.rs | 6 +++--- metrics/src/metrics.rs | 40 ++++++++++++++++++++++------------------ 3 files changed, 38 insertions(+), 29 deletions(-) diff --git a/metrics/src/counter.rs b/metrics/src/counter.rs index 29b7ecc526d2e9..265cb636f93d62 100644 --- a/metrics/src/counter.rs +++ b/metrics/src/counter.rs @@ -1,8 +1,13 @@ -use crate::metrics::submit_counter; -use log::*; -use solana_sdk::timing; -use std::env; -use std::sync::atomic::{AtomicU64, AtomicUsize, Ordering}; +use { + crate::metrics::submit_counter, + log::*, + solana_sdk::timing, + std::{ + env, + sync::atomic::{AtomicU64, AtomicUsize, Ordering}, + time::SystemTime, + }, +}; const DEFAULT_LOG_RATE: usize = 1000; // Submit a datapoint every second by default @@ -23,7 +28,7 @@ pub struct Counter { pub struct CounterPoint { pub name: &'static str, pub count: i64, - pub timestamp: u64, + pub timestamp: SystemTime, } impl CounterPoint { @@ -32,7 +37,7 @@ impl CounterPoint { CounterPoint { name, count: 0, - timestamp: 0, + timestamp: std::time::UNIX_EPOCH, } } } @@ -198,7 +203,7 @@ impl Counter { let counter = CounterPoint { name: self.name, count: counts as i64 - lastlog as i64, - timestamp: now, + timestamp: SystemTime::now(), }; submit_counter(counter, level, bucket); } diff --git a/metrics/src/datapoint.rs b/metrics/src/datapoint.rs index d5e2d5a9a32bd2..c25f3a5e707400 100644 --- a/metrics/src/datapoint.rs +++ b/metrics/src/datapoint.rs @@ -1,9 +1,9 @@ -use std::fmt; +use std::{fmt, time::SystemTime}; #[derive(Clone, Debug)] pub struct DataPoint { pub name: &'static str, - pub timestamp: u64, + pub timestamp: SystemTime, pub fields: Vec<(&'static str, String)>, } @@ -11,7 +11,7 @@ impl DataPoint { pub fn new(name: &'static str) -> Self { DataPoint { name, - timestamp: solana_sdk::timing::timestamp(), + timestamp: SystemTime::now(), fields: vec![], } } diff --git a/metrics/src/metrics.rs b/metrics/src/metrics.rs index 6d55b89e7e7a66..db9bea65e3e3ed 100644 --- a/metrics/src/metrics.rs +++ b/metrics/src/metrics.rs @@ -1,20 +1,23 @@ //! The `metrics` module enables sending measurements to an `InfluxDB` instance -use crate::{counter::CounterPoint, datapoint::DataPoint}; -use gethostname::gethostname; -use lazy_static::lazy_static; -use log::*; -use solana_sdk::hash::hash; -use std::{ - collections::HashMap, - convert::Into, - sync::{ - mpsc::{channel, Receiver, RecvTimeoutError, Sender}, - Arc, Barrier, Mutex, Once, RwLock, +use { + crate::{counter::CounterPoint, datapoint::DataPoint}, + gethostname::gethostname, + lazy_static::lazy_static, + log::*, + solana_sdk::hash::hash, + std::{ + cmp, + collections::HashMap, + convert::Into, + env, + sync::{ + mpsc::{channel, Receiver, RecvTimeoutError, Sender}, + Arc, Barrier, Mutex, Once, RwLock, + }, + thread, + time::{Duration, Instant, UNIX_EPOCH}, }, - thread, - time::{Duration, Instant}, - {cmp, env}, }; type CounterMap = HashMap<(&'static str, u64), CounterPoint>; @@ -68,7 +71,7 @@ impl InfluxDbMetricsWriter { ); let write_url = format!( - "{}/write?db={}&u={}&p={}&precision=ms", + "{}/write?db={}&u={}&p={}&precision=n", &config.host, &config.db, &config.username, &config.password ); @@ -97,8 +100,9 @@ impl MetricsWriter for InfluxDbMetricsWriter { )); first = false; } - - line.push_str(&format!(" {}\n", &point.timestamp)); + let timestamp = point.timestamp.duration_since(UNIX_EPOCH); + let nanos = timestamp.unwrap().as_nanos(); + line.push_str(&format!(" {}\n", nanos)); } let client = reqwest::blocking::Client::builder() @@ -537,7 +541,7 @@ mod test { CounterPoint { name: "counter", count: 10, - timestamp: 0, + timestamp: UNIX_EPOCH, }, Level::Info, 0, // use the same bucket