Add structured logging

examples/loglevel.rs

@@ -0,0 +1,7 @@
+use std::str::FromStr;
+
+use log::LevelFilter;
+
+fn main() {
+  println!("{:?}", LevelFilter::from_str("INFO"))
+}

src/config.rs

@@ -1,5 +1,6 @@
 use std::{collections::BTreeMap, env, fs::File, net::IpAddr, path::PathBuf, str::FromStr};
 
+use log::{debug, error};
 use serde::Deserialize;
 
 #[derive(Debug, Deserialize)]
@@ -10,15 +11,38 @@ pub struct Config {
 impl Config {
     pub fn load() -> anyhow::Result<Self> {
         let config_loc = env::var("DNS_CHECK_CONFIG")
-            .map_err(anyhow::Error::new)
-            .and_then(|path| PathBuf::from_str(path.as_str()).map_err(anyhow::Error::new))
+            .map_err(|error| {
+                debug!(error:err; "couldn't get config location from environment variable");
+                anyhow::Error::new(error)
+            })
+            .and_then(|path| {
+                PathBuf::from_str(path.as_str()).map_err(|error| {
+                    error!(error:err, path; "couldn't convert environment variable value to a path");
+                    anyhow::Error::new(error)
+                })
+            })
             .or_else(|_| -> anyhow::Result<_> {
-                // .or_else::<_, impl FnOnce(_) -> anyhow::Result<_>>(|_| {
-                let cfg_loc = xdg::BaseDirectories::with_prefix("dns-check")?
-                    .place_config_file("config.yml")?;
+                let cfg_loc = xdg::BaseDirectories::with_prefix("dns-check")
+                    .map_err(|error| {
+                        error!(error:err; "xdg init error");
+                        error
+                    })?
+                    .place_config_file("config.yml")
+                    .map_err(|error| {
+                        error!(error:err; "error creating config file");
+                        error
+                    })?;
                 Ok(cfg_loc)
             })?;
-        let file = File::open(config_loc)?;
-        Ok(serde_yaml_ng::from_reader(file)?)
+
+        debug!(config_loc:?; "opening config file");
+        let file = File::open(&config_loc).map_err(|error| {
+            error!(error:err, config_loc:?; "error opening config file");
+            error
+        })?;
+        Ok(serde_yaml_ng::from_reader(file).map_err(|error| {
+            error!(error:err, config_loc:?; "error parsing config file");
+            error
+        })?)
     }
 }

src/dig_response.rs

@@ -1,9 +1,15 @@
-use std::{net::IpAddr, process::Command, vec};
+use std::{net::IpAddr, process::Command, time::Instant, vec};
 
 use anyhow::anyhow;
+use log::{debug, error};
 use serde::{Deserialize, Serialize};
 
-#[derive(Debug)]
+/**
+ * The deserialized data from Dig's Answers section of the response
+ *
+ * See https://stackoverflow.com/questions/20297531/meaning-of-the-five-fields-of-the-answer-section-in-dig-query
+ */
+#[derive(Debug, Clone)]
 pub struct DnsResponse {
     pub domain: String,
     pub ttl: i32,
@@ -48,27 +54,45 @@ impl DnsResponse {
 
 impl DigResponse {
     pub fn query(domain: impl AsRef<str>) -> anyhow::Result<Self> {
+        let domain = domain.as_ref();
+        let start = Instant::now();
         let cmd = Command::new("dig")
             .arg("+yaml")
-            .arg(domain.as_ref())
-            .output()?;
+            .arg(domain)
+            .output()
+            .map_err(|error| {
+                error!(domain:?, error:err; "error running dig command");
+                error
+            })?;
+        let cmd_time = start.elapsed().as_millis();
+        debug!(status:? = cmd.status,
+               stdout = String::from_utf8_lossy(&cmd.stdout),
+               stderr = String::from_utf8_lossy(&cmd.stderr),
+               cmd_time;
+               "dig command completed running"
+        );
         if cmd.status.success() {
             Ok(serde_yaml_ng::from_str(
-                String::from_utf8(cmd.stdout.into_iter().skip(2).collect())?.as_str(),
+                String::from_utf8(cmd.stdout.into_iter().skip(2).collect())
+                    // we skip two here --------------------------^
+                    // because the dig output starts with "-\n" which fails to parse.
+                    .map_err(|error| {
+                        error!(domain:?, error:?; "couldn't convert command output to a string");
+                        error
+                    })?
+                    .as_str(),
             )?)
         } else {
-            Err(anyhow!(
-                "dig command failed:\n\tstatus: {:?}\n\tstdout: {}\n\tstderr: {}",
-                cmd.status,
-                String::from_utf8_lossy(&cmd.stdout),
-                String::from_utf8_lossy(&cmd.stderr)
-            ))
+            error!(status:? = cmd.status,
+                   stdout = String::from_utf8_lossy(&cmd.stdout),
+                   stderr = String::from_utf8_lossy(&cmd.stderr)
+                ; "dig command failed");
+            Err(anyhow!("dig command failed"))
         }
     }
+
     pub fn answers(&self) -> anyhow::Result<Vec<DnsResponse>> {
         let mut answers = vec![];
-        // let DigResponseType::Message(ref message) = self.message;
-        // for answer in &message.response_message_data.answer_section {
         for answer in &self.message.response_message_data.answer_section {
             answers.push(DnsResponse::parse(answer)?);
         }
@@ -76,12 +100,6 @@ impl DigResponse {
     }
 }
 
-#[derive(Debug, Clone, Deserialize, Serialize)]
-#[serde(untagged)]
-pub enum DigResponseType {
-    Message(DigResponseMessage),
-}
-
 #[derive(Debug, Clone, Deserialize, Serialize)]
 pub struct DigResponseMessage {
     pub r#type: String,

src/main.rs

@@ -1,16 +1,18 @@
 mod config;
 pub mod dig_response;
 
-use std::{net::IpAddr, thread::sleep, time::Duration};
+use std::{env, net::IpAddr, str::FromStr, thread::sleep, time::Duration};
 
 use config::Config;
 use dig_response::DigResponse;
 
 use anyhow::anyhow;
+use log::{error, info, trace, warn, LevelFilter};
 
 fn main() -> anyhow::Result<()> {
+    start_log();
     let config = Config::load()?;
-    println!("starting DNS check for {} domains", config.domains.len());
+    info!(domain_count=config.domains.len(); "starting DNS check");
     for (expected_ip, domains) in config.domains.into_iter() {
         for domain in &domains {
             sleep(Duration::from_millis(250));
@@ -20,16 +22,38 @@ fn main() -> anyhow::Result<()> {
     Ok(())
 }
 
+/**
+ * Get the log level from the $DNS_CHECK_LOG_LEVEL environment variable, and
+ * fall back on `LevelFilter::Info` if the environment variable is not
+ * specified.
+ */
+fn start_log() {
+    let level = match env::var("DNS_CHECK_LOG_LEVEL")
+        .map_err(anyhow::Error::new)
+        .and_then(|lvl| LevelFilter::from_str(&lvl).map_err(anyhow::Error::new))
+    {
+        Ok(level) => level,
+        Err(err) => {
+            warn!(err:?; "log level not specified or invalid");
+            LevelFilter::Info
+        }
+    };
+    femme::with_level(level);
+}
+
 fn run_dns_check(domain: impl AsRef<str>, expected_ip: IpAddr) -> anyhow::Result<()> {
     let domain = domain.as_ref();
     let result = DigResponse::query(domain)?;
     let addresses: Vec<_> = result.answers()?.iter().map(|a| a.address).collect();
     for address in &addresses {
         if address == &expected_ip {
-            println!("found expected IP {address:?} for domain {domain}");
+            info!(ip_address:? = address, domain:?; "found expected IP for domain");
             return Ok(());
+        } else {
+            trace!(checked_ip:? = address, expected_ip:?, domain:?; "address did not match expected IP");
         }
     }
+    error!(actual_ips:?=addresses, expected_ip:?, domain:?; "expected IP not found in DNS results");
     Err(anyhow!(
         "expected IP {expected_ip:?} not found in DNS results: {addresses:?}"
     ))