From 4461d1ea3f494778f07041164f6b8a252bd26ea2 Mon Sep 17 00:00:00 2001 From: notgne2 Date: Sun, 27 Dec 2020 10:48:18 -0700 Subject: Replace logger, add more logging options including files --- src/utils/deploy.rs | 20 +++++++++-- src/utils/mod.rs | 95 +++++++++++++++++++++++++++++++++++++++++++++++++++-- 2 files changed, 110 insertions(+), 5 deletions(-) (limited to 'src/utils') diff --git a/src/utils/deploy.rs b/src/utils/deploy.rs index 14a44a0..3aced6c 100644 --- a/src/utils/deploy.rs +++ b/src/utils/deploy.rs @@ -16,6 +16,8 @@ fn build_activate_command( temp_path: &Cow, confirm_timeout: u16, magic_rollback: bool, + debug_logs: bool, + log_dir: Option<&str>, ) -> String { let mut self_activate_command = format!( "{}/activate-rs '{}' '{}' --temp-path {} --confirm-timeout {}", @@ -30,6 +32,14 @@ fn build_activate_command( self_activate_command = format!("{} --auto-rollback", self_activate_command); } + if debug_logs { + self_activate_command = format!("{} --debug-logs", self_activate_command); + } + + if let Some(log_dir) = log_dir { + self_activate_command = format!("{} --log-file {}", self_activate_command, log_dir); + } + if let Some(sudo_cmd) = &sudo { self_activate_command = format!("{} {}", sudo_cmd, self_activate_command); } @@ -47,6 +57,8 @@ fn test_activation_command_builder() { let temp_path = &"/tmp".into(); let confirm_timeout = 30; let magic_rollback = true; + let debug_logs = true; + let log_dir = Some("/tmp/something.txt"); assert_eq!( build_activate_command( @@ -56,9 +68,11 @@ fn test_activation_command_builder() { auto_rollback, temp_path, confirm_timeout, - magic_rollback + magic_rollback, + debug_logs, + log_dir ), - "sudo -u test /nix/store/blah/etc/activate-rs '/blah/profiles/test' '/nix/store/blah/etc' --temp-path /tmp --confirm-timeout 30 --magic-rollback --auto-rollback" + "sudo -u test /nix/store/blah/etc/activate-rs '/blah/profiles/test' '/nix/store/blah/etc' --temp-path /tmp --confirm-timeout 30 --magic-rollback --auto-rollback --debug-logs --log-file /tmp/something.txt" .to_string(), ); } @@ -107,6 +121,8 @@ pub async fn deploy_profile( &temp_path, confirm_timeout, magic_rollback, + deploy_data.debug_logs, + deploy_data.log_dir, ); debug!("Constructed activation command: {}", self_activate_command); diff --git a/src/utils/mod.rs b/src/utils/mod.rs index 5770f98..42c81f7 100644 --- a/src/utils/mod.rs +++ b/src/utils/mod.rs @@ -3,14 +3,14 @@ // // SPDX-License-Identifier: MPL-2.0 -use rnix::{types::*, NodeOrToken, SyntaxKind::*, SyntaxNode}; - -use std::path::PathBuf; +use rnix::{types::*, SyntaxKind::*}; use merge::Merge; use thiserror::Error; +use flexi_logger::*; + #[macro_export] macro_rules! good_panic { ($($tts:tt)*) => {{ @@ -19,6 +19,87 @@ macro_rules! good_panic { }} } +pub fn logger_formatter_activate( + w: &mut dyn std::io::Write, + _now: &mut DeferredNow, + record: &Record, +) -> Result<(), std::io::Error> { + let level = record.level(); + + write!( + w, + "⭐ REMOTE ⭐ {0} {1} {0} {2}", + match level { + log::Level::Error => "❌", + log::Level::Warn => "⚠️", + log::Level::Info => "ℹ️", + log::Level::Debug => "❓", + log::Level::Trace => "🖊️", + }, + style(level, level.to_string()), + record.args() + ) +} + +pub fn logger_formatter_deploy( + w: &mut dyn std::io::Write, + _now: &mut DeferredNow, + record: &Record, +) -> Result<(), std::io::Error> { + let level = record.level(); + + write!( + w, + "🚀 {0} {1} {0} {2}", + match level { + log::Level::Error => "❌", + log::Level::Warn => "⚠️", + log::Level::Info => "ℹ️", + log::Level::Debug => "❓", + log::Level::Trace => "🖊️", + }, + style(level, level.to_string()), + record.args() + ) +} + +pub fn init_logger( + debug_logs: bool, + log_dir: Option<&str>, + activate: bool, +) -> Result<(), FlexiLoggerError> { + let logger_formatter = match activate { + true => logger_formatter_activate, + false => logger_formatter_deploy, + }; + + if let Some(log_dir) = log_dir { + Logger::with_env_or_str("debug") + .log_to_file() + .format_for_stderr(logger_formatter) + .set_palette("196;208;51;7;8".to_string()) + .directory(log_dir) + .discriminant(if activate { "activate" } else { "deploy" }) + .duplicate_to_stderr(match debug_logs { + true => Duplicate::Debug, + false => Duplicate::Info, + }) + .print_message() + .start()?; + } else { + Logger::with_env_or_str(match debug_logs { + true => "debug", + false => "info", + }) + .log_target(LogTarget::StdErr) + .format(logger_formatter_deploy) + .set_palette("196;208;51;7;8".to_string()) + .start()?; + } + + Ok(()) +} + pub mod data; pub mod deploy; pub mod push; @@ -191,6 +272,9 @@ pub struct DeployData<'a> { pub cmd_overrides: &'a CmdOverrides, pub merged_settings: data::GenericSettings, + + pub debug_logs: bool, + pub log_dir: Option<&'a str>, } #[derive(Debug)] @@ -259,6 +343,8 @@ pub fn make_deploy_data<'a, 's>( profile: &'a data::Profile, profile_name: &'a str, cmd_overrides: &'a CmdOverrides, + debug_logs: bool, + log_dir: Option<&'a str>, ) -> DeployData<'a> { let mut merged_settings = top_settings.clone(); merged_settings.merge(node.generic_settings.clone()); @@ -292,6 +378,9 @@ pub fn make_deploy_data<'a, 's>( cmd_overrides, merged_settings, + + debug_logs, + log_dir, } } -- cgit v1.2.3 From 72b04b0ae84f68a3314de32da87381097a54fbe5 Mon Sep 17 00:00:00 2001 From: notgne2 Date: Sun, 27 Dec 2020 10:59:32 -0700 Subject: Fix log dir/file mismatch --- src/utils/deploy.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'src/utils') diff --git a/src/utils/deploy.rs b/src/utils/deploy.rs index 3aced6c..93cebee 100644 --- a/src/utils/deploy.rs +++ b/src/utils/deploy.rs @@ -37,7 +37,7 @@ fn build_activate_command( } if let Some(log_dir) = log_dir { - self_activate_command = format!("{} --log-file {}", self_activate_command, log_dir); + self_activate_command = format!("{} --log-dir {}", self_activate_command, log_dir); } if let Some(sudo_cmd) = &sudo { @@ -72,7 +72,7 @@ fn test_activation_command_builder() { debug_logs, log_dir ), - "sudo -u test /nix/store/blah/etc/activate-rs '/blah/profiles/test' '/nix/store/blah/etc' --temp-path /tmp --confirm-timeout 30 --magic-rollback --auto-rollback --debug-logs --log-file /tmp/something.txt" + "sudo -u test /nix/store/blah/etc/activate-rs '/blah/profiles/test' '/nix/store/blah/etc' --temp-path /tmp --confirm-timeout 30 --magic-rollback --auto-rollback --debug-logs --log-dir /tmp/something.txt" .to_string(), ); } -- cgit v1.2.3 From 01ea759cf653750694201522a1b7e0d86f89a177 Mon Sep 17 00:00:00 2001 From: notgne2 Date: Sun, 27 Dec 2020 11:05:37 -0700 Subject: Deduplicate level to emoji pattern into make_emoji() --- src/utils/mod.rs | 26 ++++++++++++-------------- 1 file changed, 12 insertions(+), 14 deletions(-) (limited to 'src/utils') diff --git a/src/utils/mod.rs b/src/utils/mod.rs index 42c81f7..00277c8 100644 --- a/src/utils/mod.rs +++ b/src/utils/mod.rs @@ -19,6 +19,16 @@ macro_rules! good_panic { }} } +fn make_emoji(level: log::Level) -> &'static str { + match level { + log::Level::Error => "❌", + log::Level::Warn => "⚠️", + log::Level::Info => "ℹ️", + log::Level::Debug => "❓", + log::Level::Trace => "🖊️", + } +} + pub fn logger_formatter_activate( w: &mut dyn std::io::Write, _now: &mut DeferredNow, @@ -29,13 +39,7 @@ pub fn logger_formatter_activate( write!( w, "⭐ REMOTE ⭐ {0} {1} {0} {2}", - match level { - log::Level::Error => "❌", - log::Level::Warn => "⚠️", - log::Level::Info => "ℹ️", - log::Level::Debug => "❓", - log::Level::Trace => "🖊️", - }, + make_emoji(level), style(level, level.to_string()), record.args() ) @@ -51,13 +55,7 @@ pub fn logger_formatter_deploy( write!( w, "🚀 {0} {1} {0} {2}", - match level { - log::Level::Error => "❌", - log::Level::Warn => "⚠️", - log::Level::Info => "ℹ️", - log::Level::Debug => "❓", - log::Level::Trace => "🖊️", - }, + make_emoji(level), style(level, level.to_string()), record.args() ) -- cgit v1.2.3 From 48548d1b1564861a63603814d62bb008e4e3edae Mon Sep 17 00:00:00 2001 From: notgne2 Date: Sun, 27 Dec 2020 11:33:55 -0700 Subject: Remove discriminant (they are already differenciated by binary name) --- src/utils/mod.rs | 1 - 1 file changed, 1 deletion(-) (limited to 'src/utils') diff --git a/src/utils/mod.rs b/src/utils/mod.rs index 00277c8..9557aab 100644 --- a/src/utils/mod.rs +++ b/src/utils/mod.rs @@ -77,7 +77,6 @@ pub fn init_logger( .format_for_stderr(logger_formatter) .set_palette("196;208;51;7;8".to_string()) .directory(log_dir) - .discriminant(if activate { "activate" } else { "deploy" }) .duplicate_to_stderr(match debug_logs { true => Duplicate::Debug, false => Duplicate::Info, -- cgit v1.2.3 From b6a6abe104d348ba696054c930a3dafe0edf8d00 Mon Sep 17 00:00:00 2001 From: notgne2 Date: Wed, 30 Dec 2020 20:25:59 -0700 Subject: Modify activation logic to keep SSH connection alive for magic-rollback and avoid forking or disconnecting std{out,err} --- src/utils/deploy.rs | 167 +++++++++++++++++++++++++++++++++++++++++----------- src/utils/mod.rs | 54 ++++++++++++++--- 2 files changed, 179 insertions(+), 42 deletions(-) (limited to 'src/utils') diff --git a/src/utils/deploy.rs b/src/utils/deploy.rs index 93cebee..3371160 100644 --- a/src/utils/deploy.rs +++ b/src/utils/deploy.rs @@ -19,9 +19,24 @@ fn build_activate_command( debug_logs: bool, log_dir: Option<&str>, ) -> String { - let mut self_activate_command = format!( - "{}/activate-rs '{}' '{}' --temp-path {} --confirm-timeout {}", - closure, profile_path, closure, temp_path, confirm_timeout + let mut self_activate_command = format!("{}/activate-rs", closure); + + if debug_logs { + self_activate_command = format!("{} --debug-logs", self_activate_command); + } + + if let Some(log_dir) = log_dir { + self_activate_command = format!("{} --log-dir {}", self_activate_command, log_dir); + } + + self_activate_command = format!( + "{} --temp-path '{}' activate '{}' '{}'", + self_activate_command, temp_path, closure, profile_path + ); + + self_activate_command = format!( + "{} --confirm-timeout {}", + self_activate_command, confirm_timeout ); if magic_rollback { @@ -32,14 +47,6 @@ fn build_activate_command( self_activate_command = format!("{} --auto-rollback", self_activate_command); } - if debug_logs { - self_activate_command = format!("{} --debug-logs", self_activate_command); - } - - if let Some(log_dir) = log_dir { - self_activate_command = format!("{} --log-dir {}", self_activate_command, log_dir); - } - if let Some(sudo_cmd) = &sudo { self_activate_command = format!("{} {}", sudo_cmd, self_activate_command); } @@ -49,7 +56,6 @@ fn build_activate_command( #[test] fn test_activation_command_builder() { - let activate_path_str = "/blah/bin/activate".to_string(); let sudo = Some("sudo -u test".to_string()); let profile_path = "/blah/profiles/test"; let closure = "/nix/store/blah/etc"; @@ -72,7 +78,57 @@ fn test_activation_command_builder() { debug_logs, log_dir ), - "sudo -u test /nix/store/blah/etc/activate-rs '/blah/profiles/test' '/nix/store/blah/etc' --temp-path /tmp --confirm-timeout 30 --magic-rollback --auto-rollback --debug-logs --log-dir /tmp/something.txt" + "sudo -u test /nix/store/blah/etc/activate-rs --debug-logs --log-dir /tmp/something.txt --temp-path '/tmp' activate '/nix/store/blah/etc' '/blah/profiles/test' --confirm-timeout 30 --magic-rollback --auto-rollback" + .to_string(), + ); +} + +fn build_wait_command( + sudo: &Option, + closure: &str, + temp_path: &Cow, + debug_logs: bool, + log_dir: Option<&str>, +) -> String { + let mut self_activate_command = format!("{}/activate-rs", closure); + + if debug_logs { + self_activate_command = format!("{} --debug-logs", self_activate_command); + } + + if let Some(log_dir) = log_dir { + self_activate_command = format!("{} --log-dir {}", self_activate_command, log_dir); + } + + self_activate_command = format!( + "{} --temp-path '{}' wait '{}'", + self_activate_command, temp_path, closure + ); + + if let Some(sudo_cmd) = &sudo { + self_activate_command = format!("{} {}", sudo_cmd, self_activate_command); + } + + self_activate_command +} + +#[test] +fn test_wait_command_builder() { + let sudo = Some("sudo -u test".to_string()); + let closure = "/nix/store/blah/etc"; + let temp_path = &"/tmp".into(); + let debug_logs = true; + let log_dir = Some("/tmp/something.txt"); + + assert_eq!( + build_wait_command( + &sudo, + closure, + temp_path, + debug_logs, + log_dir + ), + "sudo -u test /nix/store/blah/etc/activate-rs --debug-logs --log-dir /tmp/something.txt --temp-path '/tmp' wait '/nix/store/blah/etc'" .to_string(), ); } @@ -81,10 +137,20 @@ fn test_activation_command_builder() { pub enum DeployProfileError { #[error("Failed to calculate activate bin path from deploy bin path: {0}")] DeployPathToActivatePathError(#[from] super::DeployPathToActivatePathError), + + #[error("Failed to spawn activation command over SSH: {0}")] + SSHSpawnActivateError(std::io::Error), + #[error("Failed to run activation command over SSH: {0}")] SSHActivateError(std::io::Error), - #[error("Activation over SSH resulted in a bad exit code: {0:?}")] + #[error("Activating over SSH resulted in a bad exit code: {0:?}")] SSHActivateExitError(Option), + + #[error("Failed to run wait command over SSH: {0}")] + SSHWaitError(std::io::Error), + #[error("Waiting over SSH resulted in a bad exit code: {0:?}")] + SSHWaitExitError(Option), + #[error("Failed to run confirmation command over SSH (the server should roll back): {0}")] SSHConfirmError(std::io::Error), #[error( @@ -127,35 +193,70 @@ pub async fn deploy_profile( debug!("Constructed activation command: {}", self_activate_command); + let self_wait_command = build_wait_command( + &deploy_defs.sudo, + &deploy_data.profile.profile_settings.path, + &temp_path, + deploy_data.debug_logs, + deploy_data.log_dir, + ); + + debug!("Constructed wait command: {}", self_wait_command); + let hostname = match deploy_data.cmd_overrides.hostname { Some(ref x) => x, None => &deploy_data.node.node_settings.hostname, }; - let mut c = Command::new("ssh"); - let mut ssh_command = c - .arg("-t") - .arg(format!("ssh://{}@{}", deploy_defs.ssh_user, hostname)); + let ssh_addr = format!("ssh://{}@{}", deploy_defs.ssh_user, hostname); + + let mut ssh_activate_command_ = Command::new("ssh"); + let ssh_activate_command = ssh_activate_command_.arg(&ssh_addr); for ssh_opt in &deploy_data.merged_settings.ssh_opts { - ssh_command = ssh_command.arg(ssh_opt); + ssh_activate_command.arg(&ssh_opt); } - let ssh_exit_status = ssh_command - .arg(self_activate_command) - .status() - .await - .map_err(DeployProfileError::SSHActivateError)?; + if !magic_rollback { + let ssh_activate_exit_status = ssh_activate_command + .arg(self_activate_command) + .status() + .await + .map_err(DeployProfileError::SSHActivateError)?; - match ssh_exit_status.code() { - Some(0) => (), - a => return Err(DeployProfileError::SSHActivateExitError(a)), - }; + match ssh_activate_exit_status.code() { + Some(0) => (), + a => return Err(DeployProfileError::SSHActivateExitError(a)), + }; - info!("Success activating!"); + info!("Success activating, done!"); + } else { + let ssh_activate = ssh_activate_command + .arg(self_activate_command) + .spawn() + .map_err(DeployProfileError::SSHSpawnActivateError)?; - if magic_rollback { - info!("Attempting to confirm activation"); + info!("Creating activation waiter"); + + let mut ssh_wait_command_ = Command::new("ssh"); + let ssh_wait_command = ssh_wait_command_.arg(&ssh_addr); + + for ssh_opt in &deploy_data.merged_settings.ssh_opts { + ssh_wait_command.arg(ssh_opt); + } + + let ssh_wait_exit_status = ssh_wait_command + .arg(self_wait_command) + .status() + .await + .map_err(DeployProfileError::SSHWaitError)?; + + match ssh_wait_exit_status.code() { + Some(0) => (), + a => return Err(DeployProfileError::SSHWaitExitError(a)), + }; + + info!("Success activating, attempting to confirm activation"); let mut c = Command::new("ssh"); let mut ssh_confirm_command = c.arg(format!("ssh://{}@{}", deploy_defs.ssh_user, hostname)); @@ -164,8 +265,8 @@ pub async fn deploy_profile( ssh_confirm_command = ssh_confirm_command.arg(ssh_opt); } - let lock_hash = &deploy_data.profile.profile_settings.path["/nix/store/".len()..]; - let lock_path = format!("{}/deploy-rs-canary-{}", temp_path, lock_hash); + let lock_path = + super::make_lock_path(&temp_path, &deploy_data.profile.profile_settings.path); let mut confirm_command = format!("rm {}", lock_path); if let Some(sudo_cmd) = &deploy_defs.sudo { diff --git a/src/utils/mod.rs b/src/utils/mod.rs index 9557aab..b1aa3e6 100644 --- a/src/utils/mod.rs +++ b/src/utils/mod.rs @@ -19,6 +19,12 @@ macro_rules! good_panic { }} } +pub fn make_lock_path(temp_path: &str, closure: &str) -> String { + let lock_hash = + &closure["/nix/store/".len()..closure.find("-").unwrap_or_else(|| closure.len())]; + format!("{}/deploy-rs-canary-{}", temp_path, lock_hash) +} + fn make_emoji(level: log::Level) -> &'static str { match level { log::Level::Error => "❌", @@ -38,7 +44,23 @@ pub fn logger_formatter_activate( write!( w, - "⭐ REMOTE ⭐ {0} {1} {0} {2}", + "⭐ {0} {1} {0} {2}", + make_emoji(level), + style(level, level.to_string()), + record.args() + ) +} + +pub fn logger_formatter_wait( + w: &mut dyn std::io::Write, + _now: &mut DeferredNow, + record: &Record, +) -> Result<(), std::io::Error> { + let level = record.level(); + + write!( + w, + "👀 {0} {1} {0} {2}", make_emoji(level), style(level, level.to_string()), record.args() @@ -61,18 +83,25 @@ pub fn logger_formatter_deploy( ) } +pub enum LoggerType { + Deploy, + Activate, + Wait, +} + pub fn init_logger( debug_logs: bool, log_dir: Option<&str>, - activate: bool, + logger_type: LoggerType, ) -> Result<(), FlexiLoggerError> { - let logger_formatter = match activate { - true => logger_formatter_activate, - false => logger_formatter_deploy, + let logger_formatter = match logger_type { + LoggerType::Deploy => logger_formatter_deploy, + LoggerType::Activate => logger_formatter_activate, + LoggerType::Wait => logger_formatter_wait, }; if let Some(log_dir) = log_dir { - Logger::with_env_or_str("debug") + let mut logger = Logger::with_env_or_str("debug") .log_to_file() .format_for_stderr(logger_formatter) .set_palette("196;208;51;7;8".to_string()) @@ -81,15 +110,22 @@ pub fn init_logger( true => Duplicate::Debug, false => Duplicate::Info, }) - .print_message() - .start()?; + .print_message(); + + match logger_type { + LoggerType::Activate => logger = logger.discriminant("activate"), + LoggerType::Wait => logger = logger.discriminant("wait"), + LoggerType::Deploy => (), + } + + logger.start()?; } else { Logger::with_env_or_str(match debug_logs { true => "debug", false => "info", }) .log_target(LogTarget::StdErr) - .format(logger_formatter_deploy) + .format(logger_formatter) .set_palette("196;208;51;7;8".to_string()) .start()?; } -- cgit v1.2.3 From 12fee773d5a3a142a8cb9b57e57ff2be98346584 Mon Sep 17 00:00:00 2001 From: notgne2 Date: Fri, 1 Jan 2021 19:30:33 -0700 Subject: Format logs differently --- src/utils/mod.rs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'src/utils') diff --git a/src/utils/mod.rs b/src/utils/mod.rs index b1aa3e6..89b124f 100644 --- a/src/utils/mod.rs +++ b/src/utils/mod.rs @@ -44,7 +44,7 @@ pub fn logger_formatter_activate( write!( w, - "⭐ {0} {1} {0} {2}", + "⭐ {} [activate] [{}] {}", make_emoji(level), style(level, level.to_string()), record.args() @@ -60,7 +60,7 @@ pub fn logger_formatter_wait( write!( w, - "👀 {0} {1} {0} {2}", + "👀 {} [wait] [{}] {}", make_emoji(level), style(level, level.to_string()), record.args() @@ -76,7 +76,7 @@ pub fn logger_formatter_deploy( write!( w, - "🚀 {0} {1} {0} {2}", + "🚀 {} [deploy] [{}] {}", make_emoji(level), style(level, level.to_string()), record.args() -- cgit v1.2.3