diff --git a/Cargo.lock b/Cargo.lock index 3b42963..8cc9d49 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -77,6 +77,7 @@ dependencies = [ "colored", "itertools", "predicates", + "regex", "serde", "serde_json", ] diff --git a/Cargo.toml b/Cargo.toml index 49a8274..c43509b 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -24,6 +24,7 @@ chrono = { version = "0.4.19", features = ["serde"] } atty = "0.2.14" colored = "2.0.0" itertools = "0.10.1" +regex = "1.5.4" [dev-dependencies] assert_cmd = "2.0.2" diff --git a/README.md b/README.md index 84ab467..723e5f9 100644 --- a/README.md +++ b/README.md @@ -23,11 +23,11 @@ > _Structured logs are the greatest thing since sliced bread._ -Are you annoyed from having to install `npm` just to get a copy of the amazing [NodeJS bunyan CLI](https://github.com/trentm/node-bunyan) to pretty-print your logs? +Are you annoyed from having to install `npm` just to get a copy of the amazing [NodeJS bunyan CLI](https://github.com/trentm/node-bunyan) to pretty-print your logs? I feel you! -That's why I wrote `bunyan-rs`, a Rust port of (a subset of) the original [NodeJS bunyan CLI](https://github.com/trentm/node-bunyan). +That's why I wrote `bunyan-rs`, a Rust port of (a subset of) the original [NodeJS bunyan CLI](https://github.com/trentm/node-bunyan).
@@ -35,6 +35,7 @@ That's why I wrote `bunyan-rs`, a Rust port of (a subset of) the original [NodeJ
# Table of Contents + 0. [How to install](#how-to-install) 1. [How to use](#how-to-use) 2. [Limitations](#limitations) @@ -45,11 +46,13 @@ That's why I wrote `bunyan-rs`, a Rust port of (a subset of) the original [NodeJ ## How to install Using `cargo`: + ```bash cargo install bunyan ``` You can verify your installation with + ```bash bunyan --help ``` @@ -61,11 +64,13 @@ Alternatively, you can download a pre-built binary for your operating system fro `bunyan-rs` only supports stdin as input source. You can pipe a log file into it: + ```bash cat tests/all/corpus/all.log | bunyan ``` Or you can pipe the output of a long-running job into it: + ```bash # Tail logs from a Docker container docker logs -f my-app | bunyan @@ -83,7 +88,7 @@ Compared to the original `bunyan` CLI, `bunyan-rs`: - Only supports `stdin` as input source (no files); - Does not support log snooping via DTrace (`-p` argument); -- Does not support the `-c/--condition` filtering mechanism; +- The `-c/--condition` filtering mechanism onlys supports a simple one-field comparison (`key==value` or `key < value`). It will find fields inside of nested JSON objects - but only compares based on the first one it finds. All standard binary comparison operators are supported. - Does not support the `--pager/--no-pager` flags; - Only supports the `long` output format; - Only supports UTC format for time. @@ -107,11 +112,14 @@ Speed has never been a burning problem while eyeballing logs from applications, To benchmark `bunyan-rs` against the original NodeJS `bunyan` follow these steps: - Build `bunyan-rs` using the `release` profile: + ```bash cargo build --release ``` + - Install `bunyan` via `npm`. You will need `npx` as well; - Benchmark! + ```bash # bunyan JS time ./benchmark_js.sh benchmark_logs.txt diff --git a/src/compare/compare_operators.rs b/src/compare/compare_operators.rs new file mode 100644 index 0000000..107ad10 --- /dev/null +++ b/src/compare/compare_operators.rs @@ -0,0 +1,85 @@ +use crate::record::{LogRecord, LogRecordTypes}; +use regex::Regex; +use std::str::FromStr; + +#[derive(Copy, Clone, Debug, PartialEq)] +pub enum Comparitors { + Equal, + NotEqual, + GreaterThan, + LessThan, + GreaterOrEqualThan, + LessOrEqualThan, +} + +impl FromStr for Comparitors { + type Err = anyhow::Error; + + fn from_str(s: &str) -> Result { + match s.trim().to_lowercase().as_str() { + "==" => Ok(Comparitors::Equal), + "!=" => Ok(Comparitors::NotEqual), + ">" => Ok(Comparitors::GreaterThan), + "<" => Ok(Comparitors::LessThan), + ">=" => Ok(Comparitors::GreaterOrEqualThan), + "<=" => Ok(Comparitors::LessOrEqualThan), + _ => Err(anyhow::anyhow!(format!("Invalid comparitor: '{}'", s))), + } + } +} + +impl Comparitors { + pub fn get_regex() -> regex::Regex { + Regex::new(r"\s?(==|!=|>=|<=|<|>)\s?").unwrap() + } + pub fn compare(&self, operand1: T, operand2: T) -> bool { + match *self { + Comparitors::Equal => operand1 == operand2, + Comparitors::NotEqual => operand1 != operand2, + Comparitors::GreaterThan => operand1 > operand2, + Comparitors::LessThan => operand1 < operand2, + Comparitors::GreaterOrEqualThan => operand1 >= operand2, + Comparitors::LessOrEqualThan => operand1 <= operand2, + } + } +} + +pub struct CompiledComparison { + pub key: String, + pub operator: Comparitors, + pub value: String, +} + +impl CompiledComparison { + pub fn new(compare: &str) -> CompiledComparison { + let re = Comparitors::get_regex(); + let mat = re + .find(compare) + .unwrap_or_else(|| panic!("Invalid comparison syntax of:{}", compare)); + let key: String = compare[0..mat.start()].to_string(); + let operator = Comparitors::from_str(compare[mat.start()..mat.end()].as_ref()).unwrap(); + let value: String = compare[mat.end()..].to_string(); + CompiledComparison { + key, + operator, + value, + } + } +} + +pub fn do_compare(r: &LogRecord, cc: &CompiledComparison) -> bool { + match r.field_by_name(&cc.key) { + Some(x) => match x { + LogRecordTypes::U8(y) => { + let u8_value: u8 = cc.value.parse().expect("getting u8 from value"); + cc.operator.compare(y, u8_value) + } + LogRecordTypes::Num(y) => { + let f64_value: f64 = cc.value.parse().expect("getting u32 from value"); + cc.operator.compare(y, f64_value) + } + LogRecordTypes::Str(y) => cc.operator.compare(&y, &cc.value), + }, + _ => false, + } +} diff --git a/src/compare/mod.rs b/src/compare/mod.rs new file mode 100644 index 0000000..9c79fcd --- /dev/null +++ b/src/compare/mod.rs @@ -0,0 +1,3 @@ +pub(crate) mod compare_operators; + +pub use compare_operators::Comparitors; diff --git a/src/lib.rs b/src/lib.rs index 812daea..84cae2c 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -1,3 +1,4 @@ +mod compare; mod level; mod record; mod sources; diff --git a/src/main.rs b/src/main.rs index 7421c3f..13413d0 100644 --- a/src/main.rs +++ b/src/main.rs @@ -13,6 +13,11 @@ struct Cli { /// numeric value. #[clap(short, long, default_value = "trace")] level: NumericalLogLevel, + /// Set a filter based on comparing a field to a provided value + /// + /// form of , ie: -c 'hostname == my.host.name' + #[clap(short, long)] + compare: Option, /// Specify an output format. /// /// - long: prettified JSON; @@ -43,5 +48,5 @@ fn main() { colored::control::set_override(true); } - process_stdin(cli.output, cli.level.0, cli.strict); + process_stdin(cli.output, cli.level.0, cli.strict, cli.compare); } diff --git a/src/record.rs b/src/record.rs index eaa5d7e..6747ba6 100644 --- a/src/record.rs +++ b/src/record.rs @@ -5,6 +5,7 @@ use itertools::Itertools; use serde::Serialize; use serde_json::ser::PrettyFormatter; use serde_json::Serializer; +use serde_json::{Map, Value}; use std::borrow::Cow; use std::convert::TryFrom; @@ -32,7 +33,15 @@ pub struct LogRecord<'a> { pub message: Cow<'a, str>, /// Any extra contextual piece of information in the log record. #[serde(flatten)] - pub extras: serde_json::Map, + pub extras: Map, +} + +//pub enum LogRecordTypes<'a> { +pub enum LogRecordTypes { + U8(u8), + Str(String), + //Using largest possible number type for flexibility - so we only have to have one type + Num(f64), } impl<'a> LogRecord<'a> { @@ -50,8 +59,59 @@ impl<'a> LogRecord<'a> { ); formatted } + pub fn field_by_name(&self, field_name: &str) -> Option { + match field_name.to_lowercase().as_str() { + "version" => Some(LogRecordTypes::U8(self.version)), + "level" => Some(LogRecordTypes::U8(self.level)), + "name" => Some(LogRecordTypes::Str(self.name.to_owned())), + "hostname" => Some(LogRecordTypes::Str(self.hostname.to_owned())), + "pid" => Some(LogRecordTypes::Num(self.process_identifier as f64)), + "time" => Some(LogRecordTypes::Str( + self.time.to_rfc3339_opts(SecondsFormat::Millis, true), + )), + "message" => Some(LogRecordTypes::Str(self.message.to_string())), + // if we can't find our field, see if it is buried inside the extras + _ => get_field_from_extras(field_name, &self.extras), + } + } +} +fn get_field_from_extras( + input_key: &str, + extra: &serde_json::value::Map, +) -> Option { + // Walking through the map instead of using extra.get() to deal with nested objects + for (key, value) in extra.iter() { + if key == input_key { + match value { + Value::Null => return None, + Value::Bool(b) => { + return Some(LogRecordTypes::Str(format!("{}", b))); + } + Value::Number(n) => { + return Some(LogRecordTypes::Num(n.as_f64().unwrap())); + } + Value::String(s) => { + return Some(LogRecordTypes::Str(s.to_string())); + } + Value::Object(_) => return None, + Value::Array(_) => return None, + }; + } else { + match value { + Value::Object(o) => { + // We have a nested object, if we can find our field inside it, return it + if let Some(nested_value) = get_field_from_extras(input_key, o) { + return Some(nested_value); + } + } + _ => { + continue; + } + } + } + } + None } - pub fn format_level(level: u8) -> String { if let Ok(level) = NamedLogLevel::try_from(level) { match level { diff --git a/src/sources/stdin.rs b/src/sources/stdin.rs index 74d16f8..4222357 100644 --- a/src/sources/stdin.rs +++ b/src/sources/stdin.rs @@ -1,15 +1,37 @@ +use crate::compare::compare_operators::do_compare; +use crate::compare::compare_operators::CompiledComparison; use crate::record::LogRecord; use crate::Format; use std::io::BufRead; -pub fn process_stdin(format: Format, level_filter: u8, strict: bool) { +pub fn process_stdin(format: Format, level_filter: u8, strict: bool, compare: Option) { let stdin = std::io::stdin(); + let compare_set; + let cc; + + match compare { + Some(c_string) => { + compare_set = true; + let compare_string = c_string; + cc = Some(CompiledComparison::new(&compare_string)); + } + None => { + compare_set = false; + cc = None; + } + } for line in stdin.lock().lines() { let line = line.unwrap(); match serde_json::from_str::(&line) { Ok(r) => { if r.level >= level_filter { - print!("{}", r.format(format)) + if compare_set { + if do_compare(&r, cc.as_ref().unwrap()) { + print!("{}", r.format(format)); + } + } else { + print!("{}", r.format(format)) + } } } Err(_) => { diff --git a/tests/all/comparisons.rs b/tests/all/comparisons.rs new file mode 100644 index 0000000..bc612f0 --- /dev/null +++ b/tests/all/comparisons.rs @@ -0,0 +1,320 @@ +use crate::helpers::{command, get_corpus_path}; +use predicates::prelude::predicate; + +#[test] +fn invalid_comparison_operators() { + let test_file = get_corpus_path().join("log1.log"); + + for invalid_operator in &["key=value", "key*value"] { + let mut cmd = command(); + + cmd.arg("-c") + .arg(invalid_operator) + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert().failure(); + } +} + +#[test] +fn valid_comparison_operators() { + let test_file = get_corpus_path().join("log1.log"); + for valid_operator in &[ + "key==value", + "key!=value", + "keyvalue", + "key <= value", + "key >= value", + ] { + let mut cmd = command(); + + cmd.arg("-c") + .arg(valid_operator) + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert().success(); + } +} + +#[test] +fn compare_version() { + let test_file = get_corpus_path().join("log1.log"); + let expected_result = "[2012-05-08T16:57:55.586Z] INFO: agent1/73267 on headnode: message +[2012-05-08T17:02:49.339Z] INFO: agent1/73267 on headnode: message +[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message +[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message +"; + let mut cmd = command(); + + cmd.arg("-c") + .arg("version == 0") + .arg("--no-color") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert() + .success() + .stdout(predicate::str::diff(expected_result)); +} + +#[test] +fn compare_version_does_not_match() { + let test_file = get_corpus_path().join("log1.log"); + + let mut cmd = command(); + + cmd.arg("-c") + .arg("version == 1") + .arg("--no-color") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert().success().stdout(predicate::str::diff("")); +} +#[test] +fn compare_pid() { + let test_file = get_corpus_path().join("log2.log"); + let expected_result = "[2012-05-08T16:58:55.586Z] INFO: agent2/73267 on headnode: message +[2012-05-08T17:01:49.339Z] INFO: agent2/73267 on headnode: message +[2012-05-08T17:02:47.404Z] INFO: agent2/73267 on headnode: message +[2012-05-08T17:02:57.404Z] INFO: agent2/73267 on headnode: message +"; + let mut cmd = command(); + + cmd.arg("-c") + .arg("pid == 73267") + .arg("--no-color") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert() + .success() + .stdout(predicate::str::diff(expected_result)); +} + +#[test] +fn compare_pid_does_not_match() { + let test_file = get_corpus_path().join("log2.log"); + + let mut cmd = command(); + + cmd.arg("-c") + .arg("pid < 50") + .arg("--no-color") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert().success().stdout(predicate::str::diff("")); +} + +#[test] +fn compare_level() { + let test_file = get_corpus_path().join("log1.log"); + let expected_result = "[2012-05-08T16:57:55.586Z] INFO: agent1/73267 on headnode: message +[2012-05-08T17:02:49.339Z] INFO: agent1/73267 on headnode: message +[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message +[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message +"; + let mut cmd = command(); + + cmd.arg("-c") + .arg("level == 30") + .arg("--no-color") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert() + .success() + .stdout(predicate::str::diff(expected_result)); +} + +#[test] +fn compare_level_does_not_match() { + let test_file = get_corpus_path().join("log1.log"); + + let mut cmd = command(); + + cmd.arg("-c") + .arg("level >= 35") + .arg("--no-color") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert().success().stdout(predicate::str::diff("")); +} +#[test] +fn compare_name() { + let test_file = get_corpus_path().join("log1.log"); + let expected_result = "[2012-05-08T16:57:55.586Z] INFO: agent1/73267 on headnode: message +[2012-05-08T17:02:49.339Z] INFO: agent1/73267 on headnode: message +[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message +[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message +"; + let mut cmd = command(); + + cmd.arg("-c") + .arg("name == agent1") + .arg("--no-color") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert() + .success() + .stdout(predicate::str::diff(expected_result)); +} + +#[test] +fn compare_name_does_not_match() { + let test_file = get_corpus_path().join("log1.log"); + + let mut cmd = command(); + + cmd.arg("-c") + .arg("name == fred") + .arg("--no-color") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert().success().stdout(predicate::str::diff("")); +} +#[test] +fn compare_hostname() { + let test_file = get_corpus_path().join("log1.log"); + let expected_result = "[2012-05-08T16:57:55.586Z] INFO: agent1/73267 on headnode: message +[2012-05-08T17:02:49.339Z] INFO: agent1/73267 on headnode: message +[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message +[2012-05-08T17:02:49.404Z] INFO: agent1/73267 on headnode: message +"; + let mut cmd = command(); + + cmd.arg("-c") + .arg("hostname == headnode") + .arg("--no-color") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert() + .success() + .stdout(predicate::str::diff(expected_result)); +} + +#[test] +fn compare_hostname_does_not_match() { + let test_file = get_corpus_path().join("log1.log"); + + let mut cmd = command(); + + cmd.arg("-c") + .arg("hostname == 3") + .arg("--no-color") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert().success().stdout(predicate::str::diff("")); +} + +#[test] +fn compare_in_extra() { + let test_file = get_corpus_path().join("all.log"); + let expected_result = + "[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: My message (one=short)\n"; + + let mut cmd = command(); + + cmd.arg("-c") + .arg("one==short") + .arg("--no-color") + .arg("--strict") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert() + .success() + .stdout(predicate::str::diff(expected_result)); +} + +#[test] +fn compare_longer_phrase_in_extra() { + let test_file = get_corpus_path().join("all.log"); + let expected_result = + "[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: My message (two=\"short with space\")\n"; + + let mut cmd = command(); + + cmd.arg("-c") + .arg("two==short with space") + .arg("--no-color") + .arg("--strict") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert() + .success() + .stdout(predicate::str::diff(expected_result)); +} + +#[test] +fn compare_embedded_object() { + let test_file = get_corpus_path().join("all.log"); + let expected_result = r#"[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: My message + five: { + "a": "json object" + } +"#; + + let mut cmd = command(); + + cmd.arg("-c") + .arg("a==json object") + // .arg("pid==123") + .arg("--no-color") + .arg("--strict") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert() + .success() + .stdout(predicate::str::diff(expected_result)); +} + +#[test] +fn compare_double_embedded_object() { + let test_file = get_corpus_path().join("all.log"); + let expected_result = r#"[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: My message + seven: { + "a": "data", + "b": { + "c": "double-nested1", + "d": 12.5 + } + } +"#; + + let mut cmd = command(); + + cmd.arg("-c") + .arg("c==double-nested1") + // .arg("pid==123") + .arg("--no-color") + .arg("--strict") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert() + .success() + .stdout(predicate::str::diff(expected_result)); +} + +#[test] +fn compare_floating_point_numbers() { + let test_file = get_corpus_path().join("all.log"); + let expected_result = r#"[2012-02-08T22:56:52.856Z] INFO: myservice/123 on example.com: My message + seven: { + "a": "data", + "b": { + "c": "double-nested1", + "d": 12.5 + } + } +"#; + + let mut cmd = command(); + + cmd.arg("-c") + .arg("d==12.5") + // .arg("pid==123") + .arg("--no-color") + .arg("--strict") + .pipe_stdin(&test_file) + .unwrap(); + cmd.assert() + .success() + .stdout(predicate::str::diff(expected_result)); +} diff --git a/tests/all/corpus/all.log b/tests/all/corpus/all.log index 5d59151..f2717ab 100644 --- a/tests/all/corpus/all.log +++ b/tests/all/corpus/all.log @@ -14,6 +14,7 @@ {"name":"myservice","pid":123,"hostname":"example.com","level":30,"four":"over 50 chars long long long long long long long long long","msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0} {"name":"myservice","pid":123,"hostname":"example.com","level":30,"five":{"a": "json object"},"msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0} {"name":"myservice","pid":123,"hostname":"example.com","level":30,"six":["a", "json", "array"],"msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0} +{"name":"myservice","pid":123,"hostname":"example.com","level":30,"seven":{"a": "data", "b": {"c": "double-nested1", "d": 12.5}},"msg":"My message","time":"2012-02-08T22:56:52.856Z","v":0} # bogus not a JSON line diff --git a/tests/all/main.rs b/tests/all/main.rs index 2476483..d1b0f56 100644 --- a/tests/all/main.rs +++ b/tests/all/main.rs @@ -1,3 +1,4 @@ +mod comparisons; mod crashers; mod formatting; pub mod helpers;