use std::{
thread,
time::{Duration, Instant},
};
use lazy_static::lazy_static;
use tempfile::{tempdir, TempDir};
const K: u64 = 1024;
const M: u64 = K * K;
const FILE_SIZE: u64 = 100 * M;
const FILE_COUNT: u32 = 10;
lazy_static! {
static ref LOGDIR: TempDir = tempdir().unwrap();
static ref HANDLE: log4rs::Handle =
log4rs::init_config(mk_config(FILE_SIZE, FILE_COUNT)).unwrap();
static ref MSG: String = "0".repeat(M as usize);
}
fn main() {
bench_find_anomalies();
}
fn bench_find_anomalies() {
lazy_static::initialize(&HANDLE);
let iters = 1000;
let mut measurements = vec![];
for _ in 1..iters {
thread::sleep(Duration::from_millis(5));
let now = Instant::now();
a::write_log();
let dur = now.elapsed();
measurements.push(dur);
}
let stats = Stats::new(&mut measurements);
let anomalies = stats.anomalies(&measurements);
println!("{:#?}", stats);
if !anomalies.is_empty() {
println!("anomalies: {:?}", anomalies);
}
assert!(
anomalies.is_empty(),
"There should be no log anomalies: {:?}",
anomalies
);
}
mod a {
pub fn write_log() {
log::info!("{}", *super::MSG);
}
}
fn mk_config(file_size: u64, file_count: u32) -> log4rs::config::Config {
let log_path = LOGDIR.path();
let log_pattern = log_path.join("log.log");
#[cfg(feature = "gzip")]
let roll_pattern = format!("{}/{}", log_path.to_string_lossy(), "log.{}.gz");
#[cfg(not(feature = "gzip"))]
let roll_pattern = format!("{}/{}", log_path.to_string_lossy(), "log.{}");
use log::LevelFilter;
use log4rs::{
append::rolling_file::{policy, RollingFileAppender},
config::{Appender, Config, Logger, Root},
encode::pattern::PatternEncoder,
};
let trigger = policy::compound::trigger::size::SizeTrigger::new(file_size);
let roller = policy::compound::roll::fixed_window::FixedWindowRoller::builder()
.build(&roll_pattern, file_count)
.unwrap();
let policy = policy::compound::CompoundPolicy::new(Box::new(trigger), Box::new(roller));
let file = RollingFileAppender::builder()
.encoder(Box::new(PatternEncoder::new(
"{d(%Y-%m-%d %H:%M:%S.%3f %Z)} {l} [{t} - {T}] {m}{n}",
)))
.build(&log_pattern, Box::new(policy))
.unwrap();
Config::builder()
.appender(Appender::builder().build("file", Box::new(file)))
.logger(
Logger::builder()
.appender("file")
.additive(false)
.build("log4rs_benchmark::a", LevelFilter::Info),
)
.build(Root::builder().appender("file").build(LevelFilter::Info))
.unwrap()
}
#[derive(Debug)]
struct Stats {
min: Duration,
max: Duration,
median: Duration,
mean_nanos: u128,
variance_nanos: f64,
stddev_nanos: f64,
}
impl Stats {
fn new(measurements: &mut [Duration]) -> Self {
measurements.sort();
let (mean_nanos, variance_nanos) =
measurements
.iter()
.fold((0, 0_f64), |(old_mean, old_variance), x| {
let nanos = x.as_nanos();
let size = measurements.len();
let mean = old_mean + (nanos - old_mean) / (size as u128);
let prevq = old_variance * (size as f64);
let variance = (prevq + ((nanos - old_mean) as f64) * (nanos - mean) as f64)
/ (size as f64);
(mean, variance)
});
Self {
min: measurements.first().unwrap().to_owned(),
max: measurements.last().unwrap().to_owned(),
median: measurements[measurements.len() / 2],
mean_nanos,
variance_nanos,
stddev_nanos: variance_nanos.sqrt(),
}
}
fn anomalies(&self, measurements: &[Duration]) -> Vec<Duration> {
let mut anomalies = vec![];
let thresh = self.mean_nanos + ((self.stddev_nanos * 50.0).round() as u128);
for dur in measurements {
if dur.as_nanos() as u128 > thresh {
anomalies.push(dur.clone());
}
}
anomalies
}
}