diff --git a/Cargo.toml b/Cargo.toml index f18de00..0c3a36d 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -14,6 +14,7 @@ itertools = "0.8" gstreamer = "0.13" regex = "1.1" lazy_static = "1.3" +failure = "0.1.5" [[example]] name = "dump" @@ -38,4 +39,3 @@ structopt = "0.2" structopt-derive = "0.2" colored = "1.8" gnuplot = "0.0.31" -failure = "0.1.5" diff --git a/src/lib.rs b/src/lib.rs index 8270faf..dc0de97 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -21,10 +21,48 @@ use gst::{ClockTime, DebugLevel, Structure}; #[macro_use] extern crate lazy_static; extern crate regex; +#[macro_use] +extern crate failure; + use regex::Regex; -#[derive(Debug)] -pub struct ParsingError; +#[derive(Debug, PartialEq)] +pub enum TimestampField { + Hour, + Minute, + Second, + SubSecond, +} + +#[derive(Debug, PartialEq)] +pub enum Token { + Timestamp { field: Option }, + PID, + Thread, + Level, + Category, + File, + LineNumber, + Function, + Message, + Object, +} + +#[derive(Debug, Fail, PartialEq)] +pub enum ParsingError { + #[fail(display = "invalid debug level: {}", name)] + InvalidDebugLevel { name: String }, + #[fail(display = "invalid timestamp: {} : {:?}", ts, field)] + InvalidTimestamp { ts: String, field: TimestampField }, + #[fail(display = "missing token: {:?}", t)] + MissingToken { t: Token }, + #[fail(display = "invalid PID: {}", pid)] + InvalidPID { pid: String }, + #[fail(display = "missing location")] + MissingLocation, + #[fail(display = "invalid line number: {}", line)] + InvalidLineNumber { line: String }, +} #[derive(Debug)] pub struct Entry { @@ -50,47 +88,99 @@ fn parse_debug_level(s: &str) -> Result { "LOG" => Ok(DebugLevel::Log), "TRACE" => Ok(DebugLevel::Trace), "MEMDUMP" => Ok(DebugLevel::Memdump), - _ => Err(ParsingError), + _ => Err(ParsingError::InvalidDebugLevel { + name: s.to_string(), + }), } } -fn parse_time(ts: &str) -> ClockTime { +fn parse_time(ts: &str) -> Result { let mut split = ts.splitn(3, ':'); let h: u64 = split .next() - .expect("missing hour") + .ok_or_else(|| ParsingError::MissingToken { + t: Token::Timestamp { + field: Some(TimestampField::Hour), + }, + })? .parse() - .expect("invalid hour"); + .map_err(|_e| ParsingError::InvalidTimestamp { + ts: ts.to_string(), + field: TimestampField::Hour, + })?; + let m: u64 = split .next() - .expect("missing minute") + .ok_or_else(|| ParsingError::MissingToken { + t: Token::Timestamp { + field: Some(TimestampField::Minute), + }, + })? .parse() - .expect("invalid minute"); - split = split.next().expect("missing second").splitn(2, '.'); + .map_err(|_e| ParsingError::InvalidTimestamp { + ts: ts.to_string(), + field: TimestampField::Minute, + })?; + + split = split + .next() + .ok_or_else(|| ParsingError::MissingToken { + t: Token::Timestamp { + field: Some(TimestampField::Second), + }, + })? + .splitn(2, '.'); let secs: u64 = split .next() - .expect("missing second") + .ok_or_else(|| ParsingError::MissingToken { + t: Token::Timestamp { + field: Some(TimestampField::Second), + }, + })? .parse() - .expect("invalid second"); + .map_err(|_e| ParsingError::InvalidTimestamp { + ts: ts.to_string(), + field: TimestampField::Second, + })?; + let subsecs: u64 = split .next() - .expect("missing sub second") + .ok_or_else(|| ParsingError::MissingToken { + t: Token::Timestamp { + field: Some(TimestampField::SubSecond), + }, + })? .parse() - .expect("invalid sub second"); + .map_err(|_e| ParsingError::InvalidTimestamp { + ts: ts.to_string(), + field: TimestampField::SubSecond, + })?; - ClockTime::from_seconds(h * 60 * 60 + m * 60 + secs) + ClockTime::from_nseconds(subsecs) + Ok(ClockTime::from_seconds(h * 60 * 60 + m * 60 + secs) + ClockTime::from_nseconds(subsecs)) } -fn split_location(location: &str) -> (String, u32, String, Option) { +fn split_location(location: &str) -> Result<(String, u32, String, Option), ParsingError> { let mut split = location.splitn(4, ':'); - let file = split.next().expect("missing file"); - let line = split + let file = split .next() - .expect("missing line") + .ok_or_else(|| ParsingError::MissingToken { t: Token::File })?; + let line_str = split.next().ok_or_else(|| ParsingError::MissingToken { + t: Token::LineNumber, + })?; + let line = line_str .parse() - .expect("invalid line"); - let function = split.next().expect("missing function"); - let object = split.next().expect("missing object delimiter"); + .map_err(|_e| ParsingError::InvalidLineNumber { + line: line_str.to_string(), + })?; + + let function = split + .next() + .ok_or_else(|| ParsingError::MissingToken { t: Token::Function })?; + + let object = split + .next() + .ok_or_else(|| ParsingError::MissingToken { t: Token::Object })?; + let object_name = { if !object.is_empty() { let object = object @@ -105,11 +195,11 @@ fn split_location(location: &str) -> (String, u32, String, Option) { } }; - (file.to_string(), line, function.to_string(), object_name) + Ok((file.to_string(), line, function.to_string(), object_name)) } impl Entry { - fn new(line: &str) -> Entry { + fn new(line: &str) -> Result { // Strip color codes lazy_static! { static ref RE: Regex = Regex::new("\x1b\\[[0-9;]*m").unwrap(); @@ -117,24 +207,43 @@ impl Entry { let line = RE.replace_all(&line, ""); let mut it = line.split(' '); - let ts = parse_time(it.next().expect("Missing ts")); + let ts_str = it.next().ok_or_else(|| ParsingError::MissingToken { + t: Token::Timestamp { field: None }, + })?; + let ts = parse_time(ts_str)?; + let mut it = it.skip_while(|x| x.is_empty()); - let pid = it + let pid_str = it .next() - .expect("Missing PID") - .parse() - .expect("Failed to parse PID"); + .ok_or_else(|| ParsingError::MissingToken { t: Token::PID })?; + let pid = pid_str.parse().map_err(|_e| ParsingError::InvalidPID { + pid: pid_str.to_string(), + })?; + let mut it = it.skip_while(|x| x.is_empty()); - let thread = it.next().expect("Missing thread").to_string(); + let thread = it + .next() + .ok_or_else(|| ParsingError::MissingToken { t: Token::Thread })? + .to_string(); + let mut it = it.skip_while(|x| x.is_empty()); - let level = parse_debug_level(it.next().expect("Missing level")).expect("Invalid level"); + let level_str = it + .next() + .ok_or_else(|| ParsingError::MissingToken { t: Token::Level })?; + let level = parse_debug_level(level_str)?; + let mut it = it.skip_while(|x| x.is_empty()); - let category = it.next().expect("Missing Category").to_string(); + let category = it + .next() + .ok_or_else(|| ParsingError::MissingToken { t: Token::Category })? + .to_string(); + let mut it = it.skip_while(|x| x.is_empty()); - let (file, line, function, object) = split_location(it.next().expect("Missing location")); + let location_str = it.next().ok_or_else(|| ParsingError::MissingLocation)?; + let (file, line, function, object) = split_location(location_str)?; let message: String = join(it, " "); - Entry { + Ok(Entry { ts, pid, thread, @@ -145,7 +254,7 @@ impl Entry { function, object, message, - } + }) } pub fn message_to_struct(&self) -> Option { @@ -188,7 +297,10 @@ impl Iterator for ParserIterator { fn next(&mut self) -> Option { match self.lines.next() { None => None, - Some(line) => Some(Entry::new(&line.unwrap())), + Some(line) => match Entry::new(&line.unwrap()) { + Ok(entry) => Some(entry), + Err(_err) => None, + }, } } } @@ -253,4 +365,173 @@ mod tests { assert_eq!(parsed.count(), 14); } + + #[test] + fn corrupted() { + let f = File::open("test-logs/corrupted-nocolor.log").expect("Failed to open log file"); + let mut parsed = parse(f); + + assert!(parsed.next().is_none()); + let entry = parsed.next().expect("First entry missing"); + assert_eq!(entry.ts.nanoseconds().unwrap(), 7773544); + assert_eq!(format!("{}", entry.ts), "00:00:00.007773544"); + assert_eq!(entry.pid, 8874); + assert_eq!(entry.thread, "0x558951015c00"); + assert_eq!(entry.level, DebugLevel::Info); + assert_eq!(entry.category, "GST_INIT"); + assert_eq!(entry.file, "gst.c"); + assert_eq!(entry.line, 510); + assert_eq!(entry.function, "init_pre"); + assert_eq!( + entry.message, + "Initializing GStreamer Core Library version 1.10.4" + ); + + let entry = parsed.nth(3).expect("3th entry missing"); + assert_eq!(entry.message, "0x55895101d040 ref 1->2"); + assert_eq!(entry.object, Some("allocatorsysmem0".to_string())); + } + + #[test] + fn timestamps() { + assert!(Entry::new("foo").is_err()); + + let e1 = "e:00:00.007773544 8874 0x558951015c00 INFO GST_INIT gst.c:510:init_pre: Init"; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!( + e, + ParsingError::InvalidTimestamp { + ts: "e:00:00.007773544".to_string(), + field: TimestampField::Hour, + } + ), + }; + + let e1 = ":00:00.007773544 8874 0x558951015c00 INFO GST_INIT gst.c:510:init_pre: Init"; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!( + e, + ParsingError::InvalidTimestamp { + ts: ":00:00.007773544".to_string(), + field: TimestampField::Hour, + } + ), + }; + + let e1 = "8874 0x558951015c00 INFO GST_INIT gst.c:510:init_pre: Init"; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!( + e, + ParsingError::MissingToken { + t: Token::Timestamp { + field: Some(TimestampField::Minute) + }, + } + ), + }; + } + + #[test] + fn pid() { + let e1 = "00:00:00.007773544 "; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!(e, ParsingError::MissingToken { t: Token::PID }), + }; + + let e1 = "00:00:00.007773544 8fuz874 0x558951015c00 INFO GST_INIT gst.c:510:init_pre: Init"; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!( + e, + ParsingError::InvalidPID { + pid: "8fuz874".to_string(), + } + ), + }; + } + + #[test] + fn thread() { + let e1 = "00:00:00.007773544 8874 "; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!(e, ParsingError::MissingToken { t: Token::Thread }), + }; + } + + #[test] + fn debug_level() { + let e1 = "00:00:00.007773544 8874 0x558951015c00 "; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!(e, ParsingError::MissingToken { t: Token::Level }), + }; + + let e1 = "00:00:00.007773544 8874 0x558951015c00 FUZZLEVEL GST_INIT gst.c:510:init_pre: Init"; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!( + e, + ParsingError::InvalidDebugLevel { + name: "FUZZLEVEL".to_string(), + } + ), + }; + } + + #[test] + fn category() { + let e1 = "00:00:00.007773544 8874 0x558951015c00 INFO"; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!(e, ParsingError::MissingToken { t: Token::Category }), + }; + } + + #[test] + fn location() { + let e1 = "00:00:00.007773544 8874 0x558951015c00 INFO GST_INIT"; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!(e, ParsingError::MissingLocation {}), + }; + + let e1 = "00:00:00.007773544 8874 0x558951015c00 INFO GST_INIT gst.c"; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!( + e, + ParsingError::MissingToken { + t: Token::LineNumber + } + ), + }; + + let e1 = "00:00:00.007773544 8874 0x558951015c00 INFO GST_INIT gst.c:fuzz"; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!( + e, + ParsingError::InvalidLineNumber { + line: "fuzz".to_string() + } + ), + }; + + let e1 = "00:00:00.007773544 8874 0x558951015c00 INFO GST_INIT gst.c:510"; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!(e, ParsingError::MissingToken { t: Token::Function }), + }; + + let e1 = "00:00:00.007773544 8874 0x558951015c00 INFO GST_INIT gst.c:510:"; + match Entry::new(e1) { + Ok(_) => assert!(false), + Err(e) => assert_eq!(e, ParsingError::MissingToken { t: Token::Object }), + }; + } } diff --git a/test-logs/corrupted-nocolor.log b/test-logs/corrupted-nocolor.log new file mode 100644 index 0000000..b783087 --- /dev/null +++ b/test-logs/corrupted-nocolor.log @@ -0,0 +1,7 @@ +Hello world, I am here to fuzz +0:00:00.007773544 8874 0x558951015c00 INFO GST_INIT gst.c:510:init_pre: Initializing GStreamer Core Library version 1.10.4 +0:00:01.007927372 8874 0x558951015c00 DEBUG GST_MEMORY gstallocator.c:592:_priv_gst_allocator_initialize: memory alignment: 7 +0:00:23.008032206 8874 0x558951015c00 TRACE GST_REFCOUNTING gstobject.c:220:gst_object_init: 0x55895101d040 new +0:01:10.008043265 8874 0x558951015c00 DEBUG GST_MEMORY gstallocator.c:568:gst_allocator_sysmem_init: init allocator 0x55895101d040 +0:11:20.008067915 8874 0x558951015c00 TRACE GST_REFCOUNTING gstobject.c:249:gst_object_ref: 0x55895101d040 ref 1->2 +1:30:47.008078203 8874 0x558951015c00 DEBUG GST_MEMORY gstallocator.c:210:gst_allocator_register: registering allocator 0x55895101d040 with name "SystemMemory"