[WIP] - Custom logs and debugging

Cargo.toml

@@ -16,6 +16,9 @@ clap = "2.19"
 error-chain="0.12.1"
 toml_edit="0.1.5"
 nix = "0.9.0"
+openssl = "0.10"
+openssl-sys = "0.9.58"
+chrono = "0.4"
 
 [[ bin ]]
 name = "watchdog"

install/install.sh

@@ -6,6 +6,11 @@ mkdir -p /opt/watchdog/logs
 touch /opt/watchdog/logs/sudo.logs
 touch /opt/watchdog/logs/su.logs
 touch /opt/watchdog/logs/ssh.logs
+mkdir -p /opt/watchdog/custom-logs
+touch /opt/watchdog/custom-logs/ssh.logs
+touch /opt/watchdog/custom-logs/sudo.logs
+touch /opt/watchdog/custom-logs/su.logs
+touch /opt/watchdog/custom-logs/auth.logs
 
 cp ../target/release/watchdog /opt/watchdog/bin/watchdog
 chown root /opt/watchdog/bin/watchdog

sample.config.toml

@@ -22,3 +22,7 @@ token = 'secret_token'
 # app(https://slack.com/apps/A0F7XDUAZ-incoming-webhooks)
 # and paste the hook URL here. You can customize the icon and name as you like.
 slack = 'https://hooks.slack.com/services/ABCDEFGHI/ABCDEFGHI/abcdefghijklmnopqrstuvwx'
+
+# Logging
+[logging]
+debug=true

src/auth.rs

@@ -7,28 +7,40 @@ use lib::errors::*;
 use lib::init::init;
 use lib::keyhouse::{get_name, validate_user};
 use lib::notifier;
+use lib::logger;
+use lib::utils::AUTH_LOG_PATH;
 
 pub fn handle_auth(ssh_host_username: &str, ssh_key: &str) -> Result<()> {
     let config = read_config()?;
     init(&config)?;
-
+    logger::logln(&format!("ssh_key in handle_auth: {}", ssh_key));
     match validate_user(&config, ssh_host_username.to_string(), ssh_key) {
         Ok(true) => {
+            logger::logln("User validated");
             let data = format!(
                 "ssh_host_username = '{}'\nssh_key = '{}'\n",
                 ssh_host_username, ssh_key
             );
 
             fs::write("/opt/watchdog/ssh_env", data)
                         .chain_err(|| "Cannot write temporary environment file. Please check if the watchdog `auth_keys_cmd` is run by the root user")?;
-
+            logger::logln("Temporary environment file written");
             println!("{}", ssh_key);
+            let name = get_name(&config, ssh_key)?;
+            if let Err(e) = logger::log(AUTH_LOG_PATH, "SUCCESS", &format!("User: {}", name)) {
+                println!("Failed to log: {}", e);
+            }
+            logger::logln("Logging successful");
             Ok(())
         }
 
         Ok(false) => {
+            logger::logln("User not validated");
             let name = get_name(&config, ssh_key)?;
-
+            if let Err(e) = logger::log(AUTH_LOG_PATH, "Failed", &format!("User: {}", name)) {
+                println!("Failed to log: {}", e);
+            }
+            logger::logln("Logging failed");
             match fork() {
                 Ok(ForkResult::Parent { .. }) => {}
                 Ok(ForkResult::Child) => {
@@ -38,12 +50,15 @@ pub fn handle_auth(ssh_host_username: &str, ssh_key: &str) -> Result<()> {
                         name,
                         ssh_host_username.to_string(),
                     )?;
+                    std::process::exit(0); 
                 }
                 Err(_) => println!("Fork failed"),
             }
             Ok(())
         }
-
-        Err(e) => Err(e).chain_err(|| "Error while validating user from keyhouse"),
+        Err(e) => {
+            logger::logln("Error while validating user from keyhouse");
+            Err(e).chain_err(|| "Error while validating user from keyhouse")
+        }
     }
 }

src/lib/config.rs

@@ -16,11 +16,17 @@ pub struct NotifiersConf {
     pub slack: String,
 }
 
+#[derive(Deserialize, Clone)]
+pub struct LoggingConf {
+    pub debug: bool,
+}
+
 #[derive(Deserialize, Clone)]
 pub struct Config {
     pub hostname: String,
     pub keyhouse: KeyhouseConf,
     pub notifiers: NotifiersConf,
+    pub logging: LoggingConf,
 }
 
 pub fn read_config() -> Result<Config> {
@@ -47,6 +53,9 @@ pub fn set_config_value(key: &str, val: &str) -> Result<()> {
         "notifiers.slack" => {
             doc["notifiers"]["slack"] = value(val);
         }
+        "logging.debug" => {
+            doc["logging"]["debug"] = value(val);
+        }
         _ => {
             return Err("Invalid Key passed".into());
         }
@@ -65,6 +74,7 @@ pub fn get_config_value(key: &str) -> Result<String> {
         "keyhouse.base_url" => doc["keyhouse"]["base_url"].as_str(),
         "keyhouse.token" => doc["keyhouse"]["token"].as_str(),
         "notifiers.slack" => doc["notifiers"]["slack"].as_str(),
+        "logging.debug" => doc["logging"]["debug"].as_str(),
         _ => {
             return Err("Invalid Key passed".into());
         }

src/lib/keyhouse.rs

@@ -50,7 +50,7 @@ fn get_content_from_github_json(json_text: &str) -> Result<String> {
         .as_str()
         .ok_or(Error::from(""))
         .chain_err(|| "No key 'content' found in JSON recieved from GitHub.")?;
-    let len = str::len(encoded_content);
+    let _len = str::len(encoded_content);
     let content = base64::decode(&encoded_content.trim_end())
                     .chain_err(|| "Bad Base64 Encoding. Probably GitHub is facing some issues. Check https://githubstatus.com.")?;
     Ok(String::from_utf8(content).chain_err(|| {

src/lib/lib.rs

@@ -4,7 +4,7 @@ pub mod init;
 pub mod keyhouse;
 pub mod notifier;
 pub mod utils;
-
+pub mod logger;
 #[macro_use]
 extern crate error_chain;
 

src/lib/logger.rs

@@ -0,0 +1,56 @@
+use std::fs::OpenOptions;
+use std::io::Write;
+use std::time::{SystemTime, UNIX_EPOCH};
+use std::io::Result;
+use chrono::{DateTime, Utc};
+use crate::config::{read_config, Config};
+
+pub fn log(filepath: &str, status: &str, message: &str) -> Result<()> {
+    let start = SystemTime::now();
+    let since_the_epoch = start.duration_since(UNIX_EPOCH).expect("Time went backwards");
+    let timestamp = since_the_epoch.as_secs();
+    let datetime = DateTime::<Utc>::from(SystemTime::UNIX_EPOCH + std::time::Duration::from_secs(timestamp));
+    let readable_time = datetime.format("%Y-%m-%d %H:%M:%S").to_string();
+    let log_message = format!("{} - {} - {}\n", readable_time, status, message);
+
+    let mut file = OpenOptions::new()
+        .append(true)
+        .create(true)
+        .open(filepath)?;
+
+    file.write_all(log_message.as_bytes())?;
+    Ok(())
+}
+
+pub fn logln(message: &str) {
+    let config = match read_config(){
+        Ok(config) => config,
+        Err(_) => {
+            log("/opt/watchdog/custom-logs/watchdog.logs", "FAILURE", "Failed to read config").expect("Failed to log");
+            return;
+        },
+    };
+    let debug=get_debug(&config);   
+    if debug==false {
+        log("/opt/watchdog/custom-logs/watchdog.logs", "FAILURE", "debug false in logln").expect("Failed to log");
+        return;
+    }
+    let start = SystemTime::now();
+    let since_the_epoch = start.duration_since(UNIX_EPOCH).expect("Time went backwards");
+    let timestamp = since_the_epoch.as_secs();
+    let datetime = DateTime::<Utc>::from(SystemTime::UNIX_EPOCH + std::time::Duration::from_secs(timestamp));
+    let readable_time = datetime.format("%Y-%m-%d %H:%M:%S").to_string();
+    let log_message = format!("{} - {}\n", readable_time, message);
+
+    let filepath = "/opt/watchdog/custom-logs/watchdog.logs";
+    let mut file = OpenOptions::new()
+        .append(true)
+        .create(true)
+        .open(filepath).expect("Failed to open log file");
+
+        file.write_all(log_message.as_bytes()).expect("Failed to write to log file");
+}
+
+pub fn get_debug(config: &Config) -> bool {
+    config.logging.debug
+}

src/lib/utils.rs

@@ -2,6 +2,11 @@ use std::fs;
 
 use crate::errors::*;
 
+pub const AUTH_LOG_PATH: &str = "/opt/watchdog/custom-logs/auth.logs";
+pub const SSH_LOG_PATH: &str = "/opt/watchdog/custom-logs/ssh.logs";
+pub const SUDO_LOG_PATH: &str = "/opt/watchdog/custom-logs/sudo.logs";
+pub const SU_LOG_PATH: &str = "/opt/watchdog/custom-logs/su.logs";
+
 pub fn clear_file(path: &str) -> Result<()> {
     fs::write(path, "")?;
     Ok(())

src/main.rs

@@ -11,7 +11,7 @@ use clap::{App, AppSettings, Arg, SubCommand};
 
 use lib::config::{get_config_value, set_config_value};
 use lib::errors::Error;
-
+use lib::logger;
 use auth::handle_auth;
 use ssh::{handle_ssh, handle_ssh_logs};
 use su::{handle_su, handle_su_logs};
@@ -94,6 +94,7 @@ fn main() {
             std::process::exit(1);
         }
     } else if let Some(ref _matches) = matches.subcommand_matches("ssh") {
+        logger::logln("SSH Command");
         if let Err(e) = handle_ssh() {
             println!("watchdog-ssh error: {}", e);
             print_traceback(e);
@@ -104,13 +105,16 @@ fn main() {
         let keytype = matches.value_of("keytype").unwrap();
         let user = matches.value_of("user").unwrap();
         let ssh_key = format!("{} {}", keytype, pubkey);
+        logger::logln(&format!("ssh_key: {}", ssh_key));
         if let Err(e) = handle_auth(&user, &ssh_key) {
             println!("watchdog-auth error: {}", e);
+            logger::logln(&format!("watchdog-auth error: {}", e));
             print_traceback(e);
             std::process::exit(1);
         }
     } else if let Some(ref matches) = matches.subcommand_matches("logs") {
         let filter = matches.value_of("filter").unwrap();
+        logger::logln(&format!("Filter: {}", filter));
         if filter == "all" {
             handle_all_logs();
         } else if filter == "sudo" {

src/ssh.rs

@@ -9,23 +9,28 @@ use lib::errors::*;
 use lib::init::init;
 use lib::keyhouse::get_name;
 use lib::notifier;
-use lib::utils::clear_file;
+//use lib::utils::clear_file;
+use lib::logger;
+use lib::utils::SSH_LOG_PATH;
 
 pub fn handle_ssh() -> Result<()> {
+    logger::logln("in handle_ssh SSH Command");
     let pam_type = env::var("PAM_TYPE")
                     .chain_err(|| "PAM_TYPE not set. If you are running this by `watchdog ssh`, please don't. It's an internal command, intended to be used by PAM.")?;
-
+    logger::logln(&format!("PAM_TYPE: {}", pam_type));
     if pam_type == "open_session" {
         let config = read_config()?;
         init(&config)?;
 
         let env = read_temp_env("/opt/watchdog/ssh_env")?;
+        logger::logln(&format!("env: {{ ssh_host_username: {}, ssh_key: {} }}", env.ssh_host_username, env.ssh_key));
         let name = get_name(&config, &env.ssh_key)?;
-
+        if let Err(e) = logger::log(SSH_LOG_PATH, "SUCCESS", &format!("User: {}", name)) {
+            println!("Failed to log: {}", e);
+        }
+        logger::logln("Logging successful");
         match fork() {
-            Ok(ForkResult::Parent { .. }) => {
-                clear_file("/opt/watchdog/ssh_env")?;
-            }
+            Ok(ForkResult::Parent { .. }) => {}
             Ok(ForkResult::Child) => {
                 notifier::post_ssh_summary(&config, true, name, env.ssh_host_username)?;
             }
@@ -36,6 +41,7 @@ pub fn handle_ssh() -> Result<()> {
 }
 
 pub fn handle_ssh_logs() {
+    logger::logln("in handle_ssh_logs");
     Command::new("less")
         .arg("/opt/watchdog/logs/ssh.logs")
         .status()

src/su.rs

@@ -7,6 +7,8 @@ use lib::config::read_config;
 use lib::errors::*;
 use lib::init::init;
 use lib::notifier;
+use lib::logger;
+use lib::utils::SU_LOG_PATH;
 
 pub fn handle_su() -> Result<()> {
     let pam_type = env::var("PAM_TYPE")
@@ -21,7 +23,9 @@ pub fn handle_su() -> Result<()> {
     if pam_type == "open_session" {
         let config = read_config()?;
         init(&config)?;
-
+        if let Err(e) = logger::log(SU_LOG_PATH, "SUCCESS", &format!("User: {}", pam_user)) {
+            println!("Failed to log: {}", e);
+        }
         match fork() {
             Ok(ForkResult::Parent { .. }) => {}
             Ok(ForkResult::Child) => {

src/sudo.rs

@@ -7,18 +7,24 @@ use lib::config::read_config;
 use lib::errors::*;
 use lib::init::init;
 use lib::notifier;
+use lib::logger;
+use lib::utils::SUDO_LOG_PATH;
 
 pub fn handle_sudo() -> Result<()> {
     let pam_type = env::var("PAM_TYPE")
                      .chain_err(|| "PAM_TYPE not set. If you are running this by `watchdog sudo`, please don't. It's an internal command, intended to be used by PAM.")?;
 
     let pam_ruser = env::var("PAM_RUSER")
                      .chain_err(|| "PAM_RUSER not set. If you are running this by `watchdog sudo`, please don't. It's an internal command, intended to be used by PAM.")?;
-
+    logger::logln(&format!("PAM_RUSER: {}", pam_ruser));
+    logger::logln(&format!("PAM_TYPE: {}", pam_type));
     if pam_type == "open_session" {
         let config = read_config()?;
         init(&config)?;
-
+        if let Err(e) = logger::log(SUDO_LOG_PATH, "SUCCESS", &format!("User: {}", pam_ruser)) {
+            println!("Failed to log: {}", e);
+        }
+        logger::logln("Logging successful");
         match fork() {
             Ok(ForkResult::Parent { .. }) => {}
             Ok(ForkResult::Child) => {

tests/logger_tests.rs

@@ -0,0 +1,24 @@
+#[cfg(test)]
+mod tests {
+    use std::fs;
+    use std::io::Read;
+    use lib::logger::log;
+
+    #[test]
+    fn test_log() {
+        let filepath = "test_ssh.logs";
+        let status = "INFO";
+        let message = "Test log message";
+
+        log(filepath, status, message).expect("Failed to write log");
+
+        let mut file = fs::File::open(filepath).expect("Failed to open log file");
+        let mut contents = String::new();
+        file.read_to_string(&mut contents).expect("Failed to read log file");
+
+        assert!(contents.contains("Test log message"));
+        assert!(contents.contains("INFO"));
+
+        fs::remove_file(filepath).expect("Failed to delete test log file");
+    }
+}