log timing

config.toml

@@ -9,16 +9,17 @@
   abbreviation_file = "./dictionary/abbreviations.dict"
 
   # Logging verbosity
+  log_handler = false
   log_parsing = false
   log_synthesis = false
-  log_handler = false
+  log_timing  = true
 
 [x16] # Local Development
   use_caching_headers = false
   sound_path = "/home/bt/Dropbox/jungle.horse/sounds"
 
   # Logging verbosity
+  log_handler = false
   log_parsing = true
   log_synthesis = false
-  log_handler = false
 

src/config.rs

@@ -28,6 +28,7 @@ pub struct Config {
   pub log_handler: Option<bool>,
   pub log_parsing: Option<bool>,
   pub log_synthesis: Option<bool>,
+  pub log_timing: Option<bool>,
 }
 
 #[derive(Debug)]
@@ -113,6 +114,9 @@ impl Config {
       log_synthesis: self.log_synthesis
           .clone()
           .or(other.log_synthesis.clone()),
+      log_timing: self.log_timing
+          .clone()
+          .or(other.log_timing.clone()),
     }
   }
 }

src/handlers/audio_synth_handler.rs

@@ -23,6 +23,7 @@ use std::sync::Arc;
 use std::sync::RwLock;
 use super::error_filter::build_error;
 use synthesizer::Synthesizer;
+use time::PreciseTime;
 use urlencoded::UrlEncodedQuery;
 
 const SENTENCE_PARAM : &'static str = "s";
@@ -315,8 +316,12 @@ impl Handler for AudioSynthHandler {
       }
     }
 
+    let start = PreciseTime::now();
     let result = self.create_audio(request);
 
+    info!(target: "timing",
+          "Total parsing and synthesis took: {}", start.to(PreciseTime::now()));
+
     let mime_type = "audio/wav".parse::<Mime>().unwrap();
 
     let mut response = Response::with((mime_type, status::Ok, result));
@@ -357,7 +362,7 @@ impl AudioSynthHandler {
                                        request.word_padding_end);
         match generated {
           Err(e) => {
-            println!("Error synthesizing: {:?}", e);
+            warn!("Error synthesizing: {:?}", e);
             Vec::new() // TODO FIXME
           },
           Ok(wav) => wav,
@@ -391,8 +396,6 @@ impl AudioSynthHandler {
     if request.use_words { use_byte |= 1 << 3; }
     if request.use_ends { use_byte |= 1 << 4; }
 
-    println!("Use byte: {}", use_byte);
-
     hasher.input(&[use_byte]);
 
     hasher.result_str().to_string()

src/logger.rs

@@ -35,6 +35,7 @@ impl log::Log for SimpleLogger {
       "handler" => self.config.log_handler.unwrap_or(false),
       "parsing" => self.config.log_parsing.unwrap_or(false),
       "synthesis" => self.config.log_synthesis.unwrap_or(false),
+      "timing" => self.config.log_timing.unwrap_or(false),
       _ => metadata.level() <= LogLevel::Info,
     }
   }