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
This commit is contained in:
behzad nouri 2021-10-13 13:58:02 +00:00 committed by GitHub
parent aec9d8bf2f
commit cd87525f54
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 38 additions and 29 deletions

View File

@ -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);
}

View File

@ -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![],
}
}

View File

@ -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