micrologger/

lib.rs

/*! A Tiny Structured Logging Utility

This is a lightweight logging utility that does little more than structure messages consistently and print them to standard out.

This logging facility is a simple object that should be passed around to anything that needs to do logging. I recommend making it a part of your application context so that it is simply passed along with the rest of your application information. Begin by instantiating the object:

```text
let logger = micrologger::Logger::new(micrologger::json_stdout, "a-host", "an-app")
```

This API is fairly low-level and works best if clients wrap helper functions to build the log entries around the basic logging function.

```text
fn log_app_start(logger: micrologger::Logger) {
    logger.log("app-start", HashMap::new());
}

fn log_method_start(logger: micrologger::Logger, method_name: str) {
    let mut msg = Hashmap::new();
    msg.insert("method-name", method_name);
    logger.log("method-start", msg);
}
```
*/

#[macro_use]
extern crate serde_derive;
#[allow(unused_imports)]
#[macro_use]
extern crate serde_json;

extern crate chrono;
extern crate serde;

use chrono::prelude::*;
use serde_json::Value;
use std::collections::HashMap;

/// This defines the structured of an entry on disk. You will never create one of these directly,
/// however you can always deserialize one from a line in the log file:
/// ```text
/// let res: Result<Entry, serde_json::Error> = serde_json::from_str(&js_str);
/// ```

#[derive(Serialize, Deserialize)]
pub struct Entry {
    #[serde(rename = "timestamp")]
    time: DateTime<Utc>,
    host: String,
    app: String,
    #[serde(rename = "type")]
    msgtype: String,
    msg: HashMap<String, Value>,
}

/// This allows the definition of a custom format closure. The trait provides both immutable and
/// mutable logging methods for different scenarios. For instance, Iron middleware does not allow
/// mutability in the handlers, and so a logging middleware must be immutable. This effectively
/// means that for Iron, logging can only go to stdout.
///
/// Other systems may allow mutable logging, which allows for a Formatter that records to a file or
/// to an internal data structure.
pub trait Formatter {
    fn format(&self, _: Entry) {
        panic!("No formatter specified");
    }

    fn format_mut(&mut self, entry: Entry) {
        self.format(entry);
    }
}

/// The logger class
pub struct Logger<F>
where
    F: Formatter,
{
    formatter: F,
    app: String,
    host: String,
}

impl<F> Logger<F>
where
    F: Formatter,
{
    /// Create a logger class with the specified command, the name of the host, and the name of the
    /// application. Note that the logger takes ownership of the formatter. If you will later need
    /// to examine the internals of the formatter, it is available at `logger.formatter`.
    pub fn new(formatter: F, host: &str, app: &str) -> Logger<F> {
        Logger {
            formatter: formatter,
            app: app.to_string(),
            host: host.to_string(),
        }
    }

    /// Write a message to the log. msgtype is any arbitrary string, but it should be meaningful to
    /// the data provided in msg so that downstream parsers know how to interpret the message.
    pub fn log(&self, msgtype: &str, msg: HashMap<String, Value>) {
        let entry = Entry {
            time: Utc::now(),
            host: self.host.clone(),
            app: self.app.clone(),
            msgtype: msgtype.to_string(),
            msg,
        };
        self.formatter.format(entry);
    }

    /// A mutable version of `log`. This uses the `format_mut` method on the formatter.
    pub fn log_mut(&mut self, msgtype: &str, msg: HashMap<String, Value>) {
        let entry = Entry {
            time: Utc::now(),
            host: self.host.clone(),
            app: self.app.clone(),
            msgtype: msgtype.to_string(),
            msg,
        };
        self.formatter.format_mut(entry);
    }
}

impl<F> Formatter for F
where
    F: Fn(Entry),
{
    fn format(&self, entry: Entry) {
        (*self)(entry);
    }
}

/// Standard formatter which converts entry into a JSON object and prints it to standard out.
pub fn json_stdout(entry: Entry) {
    match serde_json::to_string(&entry) {
        Ok(s) => println!("{}", s),
        Err(err) => println!("{{ error: \"{}\" }}", err.to_string()),
    }
}

#[cfg(test)]
mod test {
    use super::*;

    #[test]
    fn it_logs_a_message() {
        let logger = Logger::new(json_stdout, "my-host", "my-app");
        let mut msg: HashMap<String, Value> = HashMap::new();
        msg.insert("field1".to_string(), json!("value1"));
        msg.insert("field2".to_string(), json!(12.5));
        logger.log("test-message", msg);
    }

    #[test]
    fn it_formats_log_messages_correctly() {
        let mut msg: HashMap<String, Value> = HashMap::new();
        msg.insert("field1".to_string(), json!("value1"));
        msg.insert("field2".to_string(), json!(12.5));

        let time = Utc::now();

        let entry = Entry {
            time,
            host: "a-host".to_string(),
            app: "an-app".to_string(),
            msgtype: "a-message".to_string(),
            msg,
        };

        let js_str = serde_json::to_string(&entry).expect("how can json encoding fail?");
        println!("[it_formats] {}", js_str);
        //let js: Result<Value, serde_json::Error> = serde_json::from_str(&js_str);
        match serde_json::from_str(&js_str) {
            Err(err) => panic!(err),
            Ok(Value::Object(obj)) => {
                // TODO: get this back at some point, but circle does nanoseconds whereas my
                // machine does microseconds and *ugh* wtf.
                //assert_eq!(obj.get("@timestamp"), Some(&json!(time.to_rfc3339_opts(SecondsFormat::Micros, true))));
                assert_eq!(obj.get("host"), Some(&json!("a-host")));
                assert_eq!(obj.get("app"), Some(&json!("an-app")));
                assert_eq!(obj.get("type"), Some(&json!("a-message")));
                assert_eq!(
                    obj.get("msg").and_then(|o| o.get("field1")),
                    Some(&json!("value1"))
                );
                assert_eq!(
                    obj.get("msg").and_then(|o| o.get("field2")),
                    Some(&json!(12.5))
                );
            }
            Ok(_) => panic!("json deserialized incorrectly"),
        }
    }

    #[test]
    fn it_can_decode_log_entries() {
        let mut msg: HashMap<String, Value> = HashMap::new();
        msg.insert("field1".to_string(), json!("value1"));
        msg.insert("field2".to_string(), json!(12.5));

        let time = Utc::now();

        let entry = Entry {
            time,
            host: "a-host".to_string(),
            app: "an-app".to_string(),
            msgtype: "a-message".to_string(),
            msg,
        };

        let js_str = serde_json::to_string(&entry).expect("how can json encoding fail?");

        let res: Result<Entry, serde_json::Error> = serde_json::from_str(&js_str);
        match res {
            Ok(entry_) => {
                assert_eq!(entry_.time, time);
                assert_eq!(entry_.host, "a-host");
                assert_eq!(entry_.app, "an-app");
                assert_eq!(entry_.msgtype, "a-message");
                assert_eq!(entry_.msg.get("field1"), Some(&json!("value1")));
                assert_eq!(entry_.msg.get("field1"), Some(&json!("value1")));
                assert_eq!(entry_.msg.get("field2"), Some(&json!(12.5)));
            }
            Err(error) => panic!(error),
        }
    }

    struct CustomFormatter {
        prefix: String,
        output: Vec<String>,
    }

    impl Formatter for CustomFormatter {
        fn format_mut(&mut self, entry: Entry) {
            self.output
                .push(format!("{}, {}", self.prefix, entry.time.to_rfc3339()));
        }
    }

    #[test]
    fn it_can_handle_a_custom_formatter() {
        let msg: HashMap<String, Value> = HashMap::new();

        let formatter = CustomFormatter {
            prefix: String::from("a-prefix"),
            output: Vec::new(),
        };
        let mut logger = Logger::new(formatter, "my-host", "my-app");
        logger.log_mut("generic", msg);
        println!("results: {:?}", logger.formatter.output);
        assert_eq!(logger.formatter.output.len(), 1);
        assert!(logger.formatter.output[0].starts_with("a-prefix,"));
    }
}