From 6524be41e19981a68de4055fd64c5ef3ba0b71ae Mon Sep 17 00:00:00 2001 From: Brandon Thomas Date: Thu, 6 Oct 2016 02:12:00 -0400 Subject: [PATCH] Configurable logging contexts; refactored logging Logging from each component (parsing, synthesis, HTTP server) now logs as its own target. Configuration options enable turning on or off each component so it's easy to isolate a component for debugging. --- config.toml | 11 ++++++++++- src/audiobank.rs | 3 ++- src/config.rs | 16 +++++++++++++++- src/handlers/audio_synth_handler.rs | 10 ++++------ src/handlers/error_filter.rs | 6 +++--- src/handlers/file_server_handler.rs | 4 ++-- src/lang/parser.rs | 2 +- src/lang/tokenizer.rs | 7 +++---- src/logger.rs | 23 ++++++++++++++++++----- src/main.rs | 6 +++--- src/synthesizer.rs | 21 ++++++++++++--------- 11 files changed, 73 insertions(+), 36 deletions(-) diff --git a/config.toml b/config.toml index 6bb8f478f6..1bbc01bb43 100644 --- a/config.toml +++ b/config.toml @@ -1,4 +1,3 @@ - # Configs for the server. [default] # Production @@ -8,7 +7,17 @@ extra_dictionary_file = "./dictionary/extra-dict" square_dictionary_file = "./dictionary/square-dict" + # Logging verbosity + log_parsing = false + log_synthesis = false + log_handler = false + [x16] # Local Development use_caching_headers = false sound_path = "/home/bt/Dropbox/jungle.horse/sounds" + # Logging verbosity + log_parsing = true + log_synthesis = false + log_handler = false + diff --git a/src/audiobank.rs b/src/audiobank.rs index fccd5cf27b..c1daa71435 100644 --- a/src/audiobank.rs +++ b/src/audiobank.rs @@ -161,7 +161,8 @@ impl Audiobank { match self.read_wave_file(&pref_path) { Some(p) => { - info!("Used {:?} for {:?}", sample_preference, n_phone); + info!(target: "synthesis", + "Used {:?} for {:?}", sample_preference, n_phone); return Some(p) }, None => {}, diff --git a/src/config.rs b/src/config.rs index 3836571c13..313c3d8f69 100644 --- a/src/config.rs +++ b/src/config.rs @@ -1,4 +1,4 @@ -// Copyright (c) 2016 Brandon Thomas +// Copyright (c) 2016 Brandon Thomas use resolve::hostname; use std::convert::From; @@ -20,6 +20,11 @@ pub struct Config { pub phoneme_dictionary_file: Option, pub extra_dictionary_file: Option, pub square_dictionary_file: Option, + + /// What events to log. + pub log_handler: Option, + pub log_parsing: Option, + pub log_synthesis: Option, } #[derive(Debug)] @@ -93,6 +98,15 @@ impl Config { square_dictionary_file: self.square_dictionary_file .clone() .or(other.square_dictionary_file.clone()), + log_handler: self.log_handler + .clone() + .or(other.log_handler.clone()), + log_parsing: self.log_parsing + .clone() + .or(other.log_parsing.clone()), + log_synthesis: self.log_synthesis + .clone() + .or(other.log_synthesis.clone()), } } } diff --git a/src/handlers/audio_synth_handler.rs b/src/handlers/audio_synth_handler.rs index 97c78aa4c6..3b46f82f7f 100644 --- a/src/handlers/audio_synth_handler.rs +++ b/src/handlers/audio_synth_handler.rs @@ -279,8 +279,6 @@ impl SpeakRequest { impl Handler for AudioSynthHandler { /// Process request. fn handle(&self, req: &mut Request) -> IronResult { - info!("GET /speak"); - let sentence_error = build_error(status::BadRequest, &format!("Missing `{}` parameter.", SENTENCE_PARAM)); @@ -300,19 +298,19 @@ impl Handler for AudioSynthHandler { }, }; - info!("Speak Request ({}): {}.", request.speaker, request.sentence); - info!("Request: {:?}", request); + info!(target: "handler", "Speak Request: {:?}", request); // FIXME: Varies with spaces, formatting, etc. let hash = self.sha_digest(&request); let entity_tag = EntityTag::new(true, hash.to_owned()); - info!("Request Header Caching Sha: {}", hash); + info!(target: "handler", "Request Header Caching Sha: {}", hash); if self.config.use_caching_headers.unwrap_or(true) { // Don't generate file if caching header is matched. if request_hash == entity_tag.to_string() { - info!("Caching headers match; responding with NotModified."); + info!(target: "handler", + "Caching headers match; responding with NotModified."); return Ok(Response::with(status::NotModified)); } } diff --git a/src/handlers/error_filter.rs b/src/handlers/error_filter.rs index 4c52a9301c..175845d8f5 100644 --- a/src/handlers/error_filter.rs +++ b/src/handlers/error_filter.rs @@ -20,7 +20,7 @@ pub fn build_error(status: Status, message: &str) -> IronResult { impl AfterMiddleware for ErrorFilter { fn catch(&self, _: &mut Request, err: IronError) -> IronResult { - error!("Error has occurred! Error: {}", err.error); + error!(target: "handler", "Error has occurred! Error: {}", err.error); // TODO: Return JSON if request was JSON, otherwise HTML. match err.response.status { @@ -39,8 +39,8 @@ impl fmt::Display for StringError { } impl Error for StringError { - fn description(&self) -> &str { - &*self.0 + fn description(&self) -> &str { + &*self.0 } } diff --git a/src/handlers/file_server_handler.rs b/src/handlers/file_server_handler.rs index 9386135141..5ad07a26b6 100644 --- a/src/handlers/file_server_handler.rs +++ b/src/handlers/file_server_handler.rs @@ -25,7 +25,7 @@ pub struct FileServerHandler { impl Handler for FileServerHandler { /// Handles routes of the form `/f/:fileame` fn handle(&self, req: &mut Request) -> IronResult { - info!("Request: {}", &req.url); + info!(target: "handler", "Request: {}", &req.url); let filename = self.get_filename(&req); @@ -101,7 +101,7 @@ impl FileServerHandler { // TODO: whitelist filetypes. // TODO: only open non-executable files. - info!("Opening file `{}`", full_filename.display()); + debug!(target: "handler", "Opening file `{}`", full_filename.display()); let mut file = match File::open(full_filename) { Err(_) => { return None }, diff --git a/src/lang/parser.rs b/src/lang/parser.rs index 78839af5bc..366dab7ffe 100644 --- a/src/lang/parser.rs +++ b/src/lang/parser.rs @@ -52,7 +52,7 @@ impl Parser { let final_sentence = sentence.join(" "); - info!("Final sentence: {}", final_sentence); + info!(target: "parsing", "Final sentence = {}", final_sentence); final_sentence } diff --git a/src/lang/tokenizer.rs b/src/lang/tokenizer.rs index 1729bbf4dc..9b0356b6c9 100644 --- a/src/lang/tokenizer.rs +++ b/src/lang/tokenizer.rs @@ -191,6 +191,8 @@ impl Tokenizer { /// Split a raw sentence into well-defined tokens. pub fn tokenize(&self, raw_sentence: &str) -> Vec { + info!(target: "parsing", "Raw Sentence = {}", raw_sentence); + // Remove any type of double quote let mut filtered = RE_ANY_DOUBLE_QUOTE.replace_all(raw_sentence, " "); @@ -229,8 +231,6 @@ impl Tokenizer { continue; } - println!("Dictionary does not contain: {}", word); - // TODO: TEST // Match URLs. if RE_URL.is_match(&word) { @@ -383,8 +383,7 @@ impl Tokenizer { tokens.push(Token::unknown(word)) } - //println!("TOKENS = {:?}", tokens); - info!("TOKENS = {:?}", tokens); + info!(target: "parsing", "Tokens = {:?}", tokens); tokens } diff --git a/src/logger.rs b/src/logger.rs index e896acc48f..443f4866f1 100644 --- a/src/logger.rs +++ b/src/logger.rs @@ -1,5 +1,6 @@ -// Copyright (c) 2015 Brandon Thomas +// Copyright (c) 2015-2016 Brandon Thomas +use config::Config; use log::LogLevel; use log::LogLevelFilter; use log::LogMetadata; @@ -9,21 +10,33 @@ use log; use time::now; /// Simple logger example taken from rust-lang.org docs. -pub struct SimpleLogger; +pub struct SimpleLogger { + config: Config, +} impl SimpleLogger { + pub fn new(config: Config) -> SimpleLogger { + SimpleLogger { config : config } + } + /// Install the logger. - pub fn init() -> Result<(), SetLoggerError> { + pub fn init(&self) -> Result<(), SetLoggerError> { log::set_logger(|max_log_level| { max_log_level.set(LogLevelFilter::Info); - Box::new(SimpleLogger) + // TODO: This is ridiculous. Figure out trait objects, vtables, etc. + Box::new(SimpleLogger::new(self.config.clone())) }) } } impl log::Log for SimpleLogger { fn enabled(&self, metadata: &LogMetadata) -> bool { - metadata.level() <= LogLevel::Info + match metadata.target() { + "handler" => self.config.log_handler.unwrap_or(false), + "parsing" => self.config.log_parsing.unwrap_or(false), + "synthesis" => self.config.log_synthesis.unwrap_or(false), + _ => metadata.level() <= LogLevel::Info, + } } fn log(&self, record: &LogRecord) { diff --git a/src/main.rs b/src/main.rs index f21caa0420..d4cd46faaf 100644 --- a/src/main.rs +++ b/src/main.rs @@ -49,7 +49,9 @@ use std::sync::RwLock; use synthesizer::Synthesizer; fn main() { - SimpleLogger::init().unwrap(); + let config = Config::read("./config.toml").unwrap(); + let logger = SimpleLogger::new(config.clone()); + logger.init().unwrap(); // Parse command line args. let matches = App::new("trumpet") @@ -63,8 +65,6 @@ fn main() { let port = get_port(&matches, 9000); - let config = Config::read("./config.toml").unwrap(); - VocabularyLibrary::read_from_directory( Path::new(&config.sound_path.clone().unwrap())).unwrap(); diff --git a/src/synthesizer.rs b/src/synthesizer.rs index 2c42a4b70e..3c7742a708 100644 --- a/src/synthesizer.rs +++ b/src/synthesizer.rs @@ -188,7 +188,8 @@ impl Synthesizer { let polyphone = match self.arpabet_dictionary.get_polyphone(word) { Some(p) => { p }, None => { - info!("Word '{}' does not exist in polyphone database.", word); + info!(target: "synthesis", + "Word '{}' does not exist in polyphone database.", word); // XXX: Adding static as a cue to denote that the given // word->polyphone mapping doesn't exist in the database. match self.audiobank.get_misc("record_static") { @@ -201,7 +202,8 @@ impl Synthesizer { }, }; - info!("Word '{}' maps to polyphone '{:?}'", word, polyphone); + info!(target: "synthesis", + "Word '{}' maps to polyphone '{:?}'", word, polyphone); // Insert space before polyphone. match self.audiobank.get_misc("pause") { @@ -228,7 +230,8 @@ impl Synthesizer { match self.audiobank.get_diphone(speaker.as_str(), first, second) { None => {}, Some(diphone_data) => { - info!("Read diphone: {}, {}", first, second); + info!(target: "synthesis", + "Read diphone: {}, {}", first, second); skip_next = true; concatenated_waveform.extend(diphone_data); continue; @@ -385,7 +388,7 @@ impl Synthesizer { } } - info!("4-fulfilled: {:?}", fulfilled); + info!(target: "synthesis", "4-fulfilled: {:?}", fulfilled); // 3-phone if polyphone.len() >= 3 { @@ -418,7 +421,7 @@ impl Synthesizer { } } - info!("3-fulfilled: {:?}", fulfilled); + info!(target: "synthesis", "3-fulfilled: {:?}", fulfilled); // 2-phone if polyphone.len() >= 2 { @@ -451,7 +454,7 @@ impl Synthesizer { } } - info!("2-fulfilled: {:?}", fulfilled); + info!(target: "synthesis", "2-fulfilled: {:?}", fulfilled); // 1-phone for i in 0..polyphone.len() { @@ -477,7 +480,7 @@ impl Synthesizer { } } - info!("1-fulfilled: {:?}", fulfilled); + info!(target: "synthesis", "1-fulfilled: {:?}", fulfilled); for x in fulfilled { if !x { @@ -489,13 +492,13 @@ impl Synthesizer { .map(|x| if x.is_some() { x.unwrap() } else { "None".to_string() }) .collect(); - info!("Comprised of: {:?}", debug_str); + info!(target: "synthesis", "Comprised of: {:?}", debug_str); let results : Vec = chunks.into_iter() .filter_map(|x| x) // Woo, already Option! .collect(); - info!("Results Length: {} of {} phones", + info!(target: "synthesis", "Results Length: {} of {} phones", results.len(), polyphone.len());