1
  2
  3
  4
  5
  6
  7
  8
  9
 10
 11
 12
 13
 14
 15
 16
 17
 18
 19
 20
 21
 22
 23
 24
 25
 26
 27
 28
 29
 30
 31
 32
 33
 34
 35
 36
 37
 38
 39
 40
 41
 42
 43
 44
 45
 46
 47
 48
 49
 50
 51
 52
 53
 54
 55
 56
 57
 58
 59
 60
 61
 62
 63
 64
 65
 66
 67
 68
 69
 70
 71
 72
 73
 74
 75
 76
 77
 78
 79
 80
 81
 82
 83
 84
 85
 86
 87
 88
 89
 90
 91
 92
 93
 94
 95
 96
 97
 98
 99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
use crate::{Metric, MetricPublisher};
use chrono::prelude::*;
use holochain_tracing_macros::newrelic_autotrace;
use regex::Regex;
use std::{
    convert::{TryFrom, TryInto},
    io::{BufRead, BufReader},
    path::PathBuf,
};

/// A metric publisher that just logs to the debug level logger
/// a key value pair formatted according to the Into<String> trait of LogLine.
#[derive(Debug, Clone)]
pub struct LoggerMetricPublisher;

impl LoggerMetricPublisher {
    pub fn new() -> Self {
        Self
    }
}

impl MetricPublisher for LoggerMetricPublisher {
    fn publish(&mut self, metric: &Metric) {
        let log_line: LogLine = metric.into();
        debug!("{}", log_line);
    }
}

impl Default for LoggerMetricPublisher {
    fn default() -> Self {
        Self::new()
    }
}

pub const METRIC_TAG: &str = "METRIC";

lazy_static! {
    pub static ref LOG_HEADER_REGEX: Regex = Regex::new("[\\w]+ ([\\d\\-]+ [\\d:]+)").unwrap();
    pub static ref PARSE_METRIC_REGEX: Regex =
        Regex::new((METRIC_TAG.to_string() + " ([\\w\\d~\\-\\._]+) ([\\d\\.]+)").as_str()).unwrap();
}

#[derive(Debug, Clone)]
pub struct ParseError(pub String);

impl ParseError {
    pub fn new<S: Into<String>>(s: S) -> Self {
        Self(s.into())
    }
}

impl From<std::num::ParseFloatError> for ParseError {
    fn from(f: std::num::ParseFloatError) -> Self {
        ParseError(format!("Couldn't convert metric value to f64: {:?}", f))
    }
}

/// A metric as represented by a log line. Used to convert
/// from a metric to log line and back.
#[derive(Debug, Clone, Shrinkwrap)]
pub struct LogLine(pub String);

const RUST_LOG_DATE_FORMAT: &str = "%Y-%m-%d %H:%M:%S";

impl From<Metric> for LogLine {
    fn from(metric: Metric) -> Self {
        LogLine(format!(
            "{} {} {} {} {}",
            metric
                .timestamp
                .map(|t| t.format(RUST_LOG_DATE_FORMAT).to_string())
                .unwrap_or_else(String::new),
            metric.stream_id.unwrap_or_else(String::new),
            METRIC_TAG,
            metric.name,
            metric.value
        ))
    }
}

impl From<&Metric> for LogLine {
    fn from(metric: &Metric) -> Self {
        metric.clone().into()
    }
}

impl Into<String> for LogLine {
    fn into(self) -> String {
        self.0
    }
}

impl std::fmt::Display for LogLine {
    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
        write!(f, "{}", self.0)
    }
}

impl TryFrom<LogLine> for Metric {
    type Error = ParseError;
    fn try_from(source: LogLine) -> Result<Metric, ParseError> {
        let stripped = strip_ansi_escapes::strip(source.0).unwrap();
        let stripped = std::str::from_utf8(stripped.as_slice()).unwrap();
        let cap = PARSE_METRIC_REGEX
            .captures_iter(stripped)
            .next()
            .map(Ok)
            .unwrap_or_else(|| {
                Err(ParseError(format!(
                    "expected at least one capture group for a metric value: {:?}",
                    stripped
                )))
            })?;
        let timestamp = LOG_HEADER_REGEX
            .captures_iter(stripped)
            .next()
            .and_then(|s| {
                let to_parse = &s[1];
                NaiveDateTime::parse_from_str(to_parse, RUST_LOG_DATE_FORMAT)
                    .map_err(|e| warn!("Invalid date string {:?} from log: {:?}", to_parse, e))
                    .ok()
            })
            .map(|t: NaiveDateTime| {
                let dt: DateTime<_> = DateTime::from_utc(t, Utc);
                dt
            });
        let metric_name: String = cap[1].to_string();
        let value_str = cap[2].to_string();
        let metric_value: f64 = value_str.as_str().parse()?;
        let metric = Metric::new(&metric_name, None, timestamp, metric_value);
        Ok(metric)
    }
}

/// Produces an iterator of metric data given a log file name.
#[newrelic_autotrace(HOLOCHAIN_METRICS)]
pub fn metrics_from_file(log_file: PathBuf) -> std::io::Result<Box<dyn Iterator<Item = Metric>>> {
    let file = std::fs::File::open(log_file.clone())?;
    let reader = BufReader::new(file);
    let log_file: String = log_file.to_str().unwrap_or_else(|| "unknown").to_string();
    let stream_id = Some(log_file);

    let metrics = reader.lines().filter_map(move |line| {
        let result: Result<Metric, _> = line
            .map_err(|e| ParseError(format!("{}", e)))
            .and_then(move |line| LogLine(line).try_into());
        result
            .map(|mut metric| {
                metric.stream_id = stream_id.clone();
                Some(metric)
            })
            .unwrap_or_else(|e| {
                warn!("Unparsable log line: {:?}", e);
                None
            })
    });
    Ok(Box::new(metrics))
}

#[cfg(test)]
mod tests {

    use super::*;
    use std::convert::TryInto;
    #[test]
    fn can_convert_log_line_to_metric() {
        let line = format!(
            "DEBUG 2019-10-30 10:34:44 #[holochain_metrics::metrics] net_worker_thread/puid-4-2e crates/metrics/src/logger.rs:33 {} sim2h_worker.tick.latency 123", METRIC_TAG);
        let log_line = LogLine(line.to_string());
        let metric: Result<Metric, _> = log_line.try_into();

        assert!(metric.is_ok());

        let metric = metric.unwrap();
        assert_eq!("sim2h_worker.tick.latency", metric.name);
        assert_eq!(123.0, metric.value);
        assert_eq!(
            "2019-10-30 10:34:44",
            metric
                .timestamp
                .map(|x| x.format(RUST_LOG_DATE_FORMAT).to_string())
                .unwrap_or_else(|| "None".into())
        );
    }

    #[test]
    fn can_convert_cloudwatch_log_line_to_metric() {
        let line = format!("{} sim2h_worker.tick.latency 123", METRIC_TAG);
        let log_line = LogLine(line.to_string());
        let metric: Metric = log_line.try_into().unwrap();
        assert_eq!("sim2h_worker.tick.latency", metric.name);
        assert_eq!(123.0, metric.value);
    }
}