Adjust logging levels and move logging to own module

3 files changed, 64 insertions, 44 deletions

diff --git a/mullvad-daemon/src/logging.rs b/mullvad-daemon/src/logging.rs
new file mode 100644
index 0000000000..cd63757f20
--- /dev/null
+++ b/mullvad-daemon/src/logging.rs
@@ -0,0 +1,55 @@
+extern crate fern;
+
+use chrono;
+use log;
+
+use std::io;
+use std::path::PathBuf;
+
+error_chain! {
+    errors {
+        WriteFileError(path: PathBuf) {
+            description("Unable to open log file for writing")
+            display("Unable to open log file for writing: {}", path.to_string_lossy())
+        }
+    }
+    foreign_links {
+        SetLoggerError(log::SetLoggerError);
+    }
+}
+
+pub const DATE_TIME_FORMAT_STR: &str = "%Y-%m-%d %H:%M:%S%.3f";
+
+pub fn init_logger(log_level: log::LogLevelFilter, log_file: Option<&PathBuf>) -> Result<()> {
+    let silenced_crates = [
+        "jsonrpc_core",
+        "tokio_core",
+        "tokio_proto",
+        "jsonrpc_ws_server",
+        "ws",
+        "mio",
+        "hyper",
+    ];
+    let mut config = fern::Dispatch::new()
+        .format(|out, message, record| {
+            out.finish(format_args!(
+                "[{}][{}][{}] {}",
+                chrono::Local::now().format(DATE_TIME_FORMAT_STR),
+                record.target(),
+                record.level(),
+                message
+            ))
+        })
+        .level(log_level)
+        .chain(io::stdout());
+    for silenced_crate in &silenced_crates {
+        config = config.level_for(*silenced_crate, log::LogLevelFilter::Warn);
+    }
+    if let Some(ref log_file) = log_file {
+        let f = fern::log_file(log_file)
+            .chain_err(|| ErrorKind::WriteFileError(log_file.to_path_buf()))?;
+        config = config.chain(f);
+    }
+    config.apply()?;
+    Ok(())
+}
diff --git a/mullvad-daemon/src/main.rs b/mullvad-daemon/src/main.rs
index 8bd5ff9826..d6cc7755fc 100644
--- a/mullvad-daemon/src/main.rs
+++ b/mullvad-daemon/src/main.rs
@@ -13,7 +13,6 @@ extern crate chrono;
 extern crate clap;
 #[macro_use]
 extern crate error_chain;
-extern crate fern;
 extern crate futures;
 #[macro_use]
 extern crate log;
@@ -43,6 +42,7 @@ extern crate talpid_types;
 mod account_history;
 mod cli;
 mod geoip;
+mod logging;
 mod management_interface;
 mod relays;
 mod rpc_info;
@@ -119,8 +119,6 @@ static APP_INFO: AppInfo = AppInfo {
     author: "Mullvad",
 };
 
-const DATE_TIME_FORMAT_STR: &str = "%Y-%m-%d %H:%M:%S%.3f";
-
 
 /// All events that can happen in the daemon. Sent from various threads and exposed interfaces.
 pub enum DaemonEvent {
@@ -311,7 +309,7 @@ impl Daemon {
     ) {
         thread::spawn(move || {
             let result = server.wait();
-            debug!("Mullvad management interface shut down");
+            error!("Mullvad management interface shut down");
             let _ = exit_tx.send(DaemonEvent::ManagementInterfaceExited(result));
         });
     }
@@ -764,7 +762,8 @@ quick_main!(run);
 
 fn run() -> Result<()> {
     let config = cli::get_config();
-    init_logger(config.log_level, config.log_file.as_ref())?;
+    logging::init_logger(config.log_level, config.log_file.as_ref())
+        .chain_err(|| "Unable to initialize logger")?;
     log_version();
 
     let resource_dir = config.resource_dir.unwrap_or_else(|| get_resource_dir());
@@ -777,45 +776,11 @@ fn run() -> Result<()> {
 
     daemon.run()?;
 
-    debug!("Mullvad daemon is quitting");
+    info!("Mullvad daemon is quitting");
     thread::sleep(Duration::from_millis(500));
     Ok(())
 }
 
-fn init_logger(log_level: log::LogLevelFilter, log_file: Option<&PathBuf>) -> Result<()> {
-    let silenced_crates = [
-        "jsonrpc_core",
-        "tokio_core",
-        "tokio_proto",
-        "jsonrpc_ws_server",
-        "ws",
-        "mio",
-        "hyper",
-    ];
-    let mut config = fern::Dispatch::new()
-        .format(|out, message, record| {
-            out.finish(format_args!(
-                "[{}][{}][{}] {}",
-                chrono::Local::now().format(DATE_TIME_FORMAT_STR),
-                record.target(),
-                record.level(),
-                message
-            ))
-        })
-        .level(log_level)
-        .chain(std::io::stdout());
-    for silenced_crate in &silenced_crates {
-        config = config.level_for(*silenced_crate, log::LogLevelFilter::Warn);
-    }
-    if let Some(ref log_file) = log_file {
-        let f = fern::log_file(log_file).chain_err(|| "Failed to open log file for writing")?;
-        config = config.chain(f);
-    }
-    config
-        .apply()
-        .chain_err(|| "Failed to bootstrap logging system")
-}
-
 fn log_version() {
     info!(
         "Starting {} - {} {}",
diff --git a/mullvad-daemon/src/relays.rs b/mullvad-daemon/src/relays.rs
index f19feb8edb..3f1a9ab77f 100644
--- a/mullvad-daemon/src/relays.rs
+++ b/mullvad-daemon/src/relays.rs
@@ -54,10 +54,10 @@ impl RelaySelector {
     pub fn new(rpc_handle: HttpHandle, resource_dir: &Path) -> Result<Self> {
         let (last_updated, relay_list) = Self::read_cached_relays(resource_dir)?;
         let (locations, relays) = Self::process_relay_list(relay_list);
-        debug!(
+        info!(
             "Initialized with {} cached relays from {}",
             relays.len(),
-            DateTime::<Local>::from(last_updated).format(::DATE_TIME_FORMAT_STR)
+            DateTime::<Local>::from(last_updated).format(::logging::DATE_TIME_FORMAT_STR)
         );
         Ok(RelaySelector {
             locations,
@@ -243,7 +243,7 @@ impl RelaySelector {
 
     /// Downloads the latest relay list and caches it. This operation is blocking.
     pub fn update(&mut self, timeout: Duration) -> Result<()> {
-        info!("Downloading list of relays");
+        info!("Downloading list of relays...");
         let download_future = self.rpc_client
             .relay_list()
             .map_err(|e| Error::with_chain(e, ErrorKind::DownloadError));
@@ -252,7 +252,7 @@ impl RelaySelector {
             error!("Unable to save relays to cache: {}", e.display_chain());
         }
         let (locations, relays) = Self::process_relay_list(relay_list);
-        debug!("Downloaded relay inventory has {} relays", relays.len());
+        info!("Downloaded relay inventory has {} relays", relays.len());
         self.locations = locations;
         self.relays = relays;
         self.last_updated = SystemTime::now();