diff --git a/CHANGELOG.md b/CHANGELOG.md index 1d7e494..1f3245d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -22,6 +22,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Changed - Hooks are now cleaned right after the current challenge has been validated instead of after the certificate's retrieval. - In hooks, the `stdin` field now refers to the path of the file that should be written into the hook's standard input. +- The logging format has been re-written. ### Fixed - The http-01-echo hook now correctly sets the file's access rights diff --git a/acme_common/src/error.rs b/acme_common/src/error.rs index ce12a9c..637d57e 100644 --- a/acme_common/src/error.rs +++ b/acme_common/src/error.rs @@ -5,6 +5,14 @@ pub struct Error { pub message: String, } +impl Error { + pub fn prefix(&self, prefix: &str) -> Self { + Error { + message: format!("{}: {}", prefix, &self.message), + } + } +} + impl fmt::Display for Error { fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { write!(f, "{}", self.message) diff --git a/acmed/src/acme_proto.rs b/acmed/src/acme_proto.rs index 3c9a64f..a925353 100644 --- a/acmed/src/acme_proto.rs +++ b/acmed/src/acme_proto.rs @@ -6,7 +6,6 @@ use crate::acme_proto::structs::{ use crate::certificate::Certificate; use crate::storage; use acme_common::error::Error; -use log::{info, warn}; use std::fmt; mod account; @@ -75,10 +74,10 @@ pub fn request_certificate(cert: &Certificate, root_certs: &[String]) -> Result< let mut hook_datas = vec![]; // 1. Get the directory - let directory = http::get_directory(root_certs, &cert.remote_url)?; + let directory = http::get_directory(cert, root_certs, &cert.remote_url)?; // 2. Get a first nonce - let nonce = http::get_nonce(root_certs, &directory.new_nonce)?; + let nonce = http::get_nonce(cert, root_certs, &directory.new_nonce)?; // 3. Get or create the account let (account, nonce) = AccountManager::new(cert, &directory, &nonce, root_certs)?; @@ -87,21 +86,26 @@ pub fn request_certificate(cert: &Certificate, root_certs: &[String]) -> Result< let new_order = NewOrder::new(&domains); let new_order = serde_json::to_string(&new_order)?; let data_builder = set_data_builder!(account, new_order.as_bytes(), directory.new_order); - let (order, order_url, mut nonce): (Order, String, String) = - http::get_obj_loc(root_certs, &directory.new_order, &data_builder, &nonce)?; + let (order, order_url, mut nonce): (Order, String, String) = http::get_obj_loc( + cert, + root_certs, + &directory.new_order, + &data_builder, + &nonce, + )?; if let Some(e) = order.get_error() { - warn!("Error: {}", e); + cert.warn(&e.prefix("Error").message); } // 5. Get all the required authorizations for auth_url in order.authorizations.iter() { let data_builder = set_empty_data_builder!(account, auth_url); let (auth, new_nonce): (Authorization, String) = - http::get_obj(root_certs, &auth_url, &data_builder, &nonce)?; + http::get_obj(cert, root_certs, &auth_url, &data_builder, &nonce)?; nonce = new_nonce; if let Some(e) = auth.get_error() { - warn!("Error: {}", e); + cert.warn(&e.prefix("Error").message); } if auth.status == AuthorizationStatus::Valid { continue; @@ -130,8 +134,13 @@ pub fn request_certificate(cert: &Certificate, root_certs: &[String]) -> Result< // 8. Tell the server the challenge has been completed let chall_url = challenge.get_url(); let data_builder = set_data_builder!(account, b"{}", chall_url); - let new_nonce = - http::post_challenge_response(root_certs, &chall_url, &data_builder, &nonce)?; + let new_nonce = http::post_challenge_response( + cert, + root_certs, + &chall_url, + &data_builder, + &nonce, + )?; nonce = new_nonce; } } @@ -139,8 +148,14 @@ pub fn request_certificate(cert: &Certificate, root_certs: &[String]) -> Result< // 9. Pool the authorization in order to see whether or not it is valid let data_builder = set_empty_data_builder!(account, auth_url); let break_fn = |a: &Authorization| a.status == AuthorizationStatus::Valid; - let (_, new_nonce): (Authorization, String) = - http::pool_obj(root_certs, &auth_url, &data_builder, &break_fn, &nonce)?; + let (_, new_nonce): (Authorization, String) = http::pool_obj( + cert, + root_certs, + &auth_url, + &data_builder, + &break_fn, + &nonce, + )?; nonce = new_nonce; for (data, hook_type) in hook_datas.iter() { cert.call_challenge_hooks_clean(&data, (*hook_type).to_owned())?; @@ -151,33 +166,45 @@ pub fn request_certificate(cert: &Certificate, root_certs: &[String]) -> Result< // 10. Pool the order in order to see whether or not it is ready let data_builder = set_empty_data_builder!(account, order_url); let break_fn = |o: &Order| o.status == OrderStatus::Ready; - let (order, nonce): (Order, String) = - http::pool_obj(root_certs, &order_url, &data_builder, &break_fn, &nonce)?; + let (order, nonce): (Order, String) = http::pool_obj( + cert, + root_certs, + &order_url, + &data_builder, + &break_fn, + &nonce, + )?; // 11. Finalize the order by sending the CSR let (priv_key, pub_key) = certificate::get_key_pair(cert)?; let csr = certificate::generate_csr(cert, &priv_key, &pub_key)?; let data_builder = set_data_builder!(account, csr.as_bytes(), order.finalize); let (order, nonce): (Order, String) = - http::get_obj(root_certs, &order.finalize, &data_builder, &nonce)?; + http::get_obj(cert, root_certs, &order.finalize, &data_builder, &nonce)?; if let Some(e) = order.get_error() { - warn!("Error: {}", e); + cert.warn(&e.prefix("Error").message); } // 12. Pool the order in order to see whether or not it is valid let data_builder = set_empty_data_builder!(account, order_url); let break_fn = |o: &Order| o.status == OrderStatus::Valid; - let (order, nonce): (Order, String) = - http::pool_obj(root_certs, &order_url, &data_builder, &break_fn, &nonce)?; + let (order, nonce): (Order, String) = http::pool_obj( + cert, + root_certs, + &order_url, + &data_builder, + &break_fn, + &nonce, + )?; // 13. Download the certificate let crt_url = order .certificate .ok_or_else(|| Error::from("No certificate available for download."))?; let data_builder = set_empty_data_builder!(account, crt_url); - let (crt, _) = http::get_certificate(root_certs, &crt_url, &data_builder, &nonce)?; + let (crt, _) = http::get_certificate(cert, root_certs, &crt_url, &data_builder, &nonce)?; storage::write_certificate(cert, &crt.as_bytes())?; - info!("Certificate renewed for {}", domains.join(", ")); + cert.info("Certificate renewed"); Ok(()) } diff --git a/acmed/src/acme_proto/account.rs b/acmed/src/acme_proto/account.rs index 8ea5449..d280975 100644 --- a/acmed/src/acme_proto/account.rs +++ b/acmed/src/acme_proto/account.rs @@ -42,8 +42,13 @@ impl AccountManager { let account = serde_json::to_string(&account)?; let data_builder = |n: &str| encode_jwk(&priv_key, account.as_bytes(), &directory.new_account, n); - let (acc_rep, account_url, nonce): (AccountResponse, String, String) = - http::get_obj_loc(root_certs, &directory.new_account, &data_builder, &nonce)?; + let (acc_rep, account_url, nonce): (AccountResponse, String, String) = http::get_obj_loc( + cert, + root_certs, + &directory.new_account, + &data_builder, + &nonce, + )?; let ac = AccountManager { priv_key, pub_key, diff --git a/acmed/src/acme_proto/http.rs b/acmed/src/acme_proto/http.rs index 7ac36a1..ab6c737 100644 --- a/acmed/src/acme_proto/http.rs +++ b/acmed/src/acme_proto/http.rs @@ -1,9 +1,9 @@ use crate::acme_proto::structs::{AcmeError, ApiError, Directory, HttpApiError}; +use crate::certificate::Certificate; use acme_common::error::Error; use http_req::request::{Method, Request}; use http_req::response::Response; use http_req::uri::Uri; -use log::{debug, trace, warn}; use std::path::Path; use std::str::FromStr; use std::{thread, time}; @@ -25,8 +25,13 @@ impl FromStr for DummyString { } } -fn new_request<'a>(root_certs: &'a [String], uri: &'a Uri, method: Method) -> Request<'a> { - debug!("{}: {}", method, uri); +fn new_request<'a>( + cert: &Certificate, + root_certs: &'a [String], + uri: &'a Uri, + method: Method, +) -> Request<'a> { + cert.debug(&format!("{}: {}", method, uri)); let useragent = format!( "{}/{} ({}) {}", crate::APP_NAME, @@ -52,7 +57,7 @@ fn send_request(request: &Request) -> Result<(Response, String), Error> { Ok((res, res_str)) } -fn send_request_retry(request: &Request) -> Result<(Response, String), Error> { +fn send_request_retry(cert: &Certificate, request: &Request) -> Result<(Response, String), Error> { for _ in 0..crate::DEFAULT_HTTP_FAIL_NB_RETRY { let (res, res_body) = send_request(request)?; match check_response(&res, &res_body) { @@ -64,7 +69,7 @@ fn send_request_retry(request: &Request) -> Result<(Response, String), Error> { let msg = format!("HTTP error: {}: {}", res.status_code(), res.reason()); return Err(msg.into()); } - warn!("{}", e); + cert.warn(&format!("{}", e)); } }; thread::sleep(time::Duration::from_secs(crate::DEFAULT_HTTP_FAIL_WAIT_SEC)); @@ -86,10 +91,10 @@ fn is_nonce(data: &str) -> bool { .all(|c| c.is_ascii_alphanumeric() || c == b'-' || c == b'_') } -fn nonce_from_response(res: &Response) -> Result { +fn nonce_from_response(cert: &Certificate, res: &Response) -> Result { let nonce = get_header(res, "Replay-Nonce")?; if is_nonce(&nonce) { - trace!("New nonce: {}", nonce); + cert.trace(&format!("New nonce: {}", nonce)); Ok(nonce.to_string()) } else { let msg = format!("{}: invalid nonce.", nonce); @@ -98,21 +103,22 @@ fn nonce_from_response(res: &Response) -> Result { } fn post_jose_type( + cert: &Certificate, root_certs: &[String], url: &str, data: &[u8], accept_type: &str, ) -> Result<(Response, String), Error> { let uri = url.parse::()?; - let mut request = new_request(root_certs, &uri, Method::POST); + let mut request = new_request(cert, root_certs, &uri, Method::POST); request.header("Content-Type", CONTENT_TYPE_JOSE); request.header("Content-Length", &data.len().to_string()); request.header("Accept", accept_type); request.body(data); let rstr = String::from_utf8_lossy(data); - trace!("request body: {}", rstr); + cert.trace(&format!("request body: {}", rstr)); let (res, res_body) = send_request(&request)?; - trace!("response body: {}", res_body); + cert.trace(&format!("response body: {}", res_body)); Ok((res, res_body)) } @@ -125,6 +131,7 @@ fn check_response(res: &Response, body: &str) -> Result<(), AcmeError> { } fn fetch_obj_type( + cert: &Certificate, root_certs: &[String], url: &str, data_builder: &G, @@ -138,8 +145,8 @@ where let mut nonce = nonce.to_string(); for _ in 0..crate::DEFAULT_HTTP_FAIL_NB_RETRY { let data = data_builder(&nonce)?; - let (res, res_body) = post_jose_type(root_certs, url, data.as_bytes(), accept_type)?; - nonce = nonce_from_response(&res)?; + let (res, res_body) = post_jose_type(cert, root_certs, url, data.as_bytes(), accept_type)?; + nonce = nonce_from_response(cert, &res)?; match check_response(&res, &res_body) { Ok(()) => { @@ -152,7 +159,7 @@ where let msg = format!("HTTP error: {}: {}", res.status_code(), res.reason()); return Err(msg.into()); } - warn!("{}", e); + cert.warn(&format!("{}", e)); } }; thread::sleep(time::Duration::from_secs(crate::DEFAULT_HTTP_FAIL_WAIT_SEC)); @@ -161,6 +168,7 @@ where } fn fetch_obj( + cert: &Certificate, root_certs: &[String], url: &str, data_builder: &G, @@ -170,10 +178,18 @@ where T: std::str::FromStr, G: Fn(&str) -> Result, { - fetch_obj_type(root_certs, url, data_builder, nonce, CONTENT_TYPE_JSON) + fetch_obj_type( + cert, + root_certs, + url, + data_builder, + nonce, + CONTENT_TYPE_JSON, + ) } pub fn get_obj_loc( + cert: &Certificate, root_certs: &[String], url: &str, data_builder: &G, @@ -183,7 +199,7 @@ where T: std::str::FromStr, G: Fn(&str) -> Result, { - let (obj, location, nonce) = fetch_obj(root_certs, url, data_builder, nonce)?; + let (obj, location, nonce) = fetch_obj(cert, root_certs, url, data_builder, nonce)?; if location.is_empty() { Err("Location header not found.".into()) } else { @@ -192,6 +208,7 @@ where } pub fn get_obj( + cert: &Certificate, root_certs: &[String], url: &str, data_builder: &G, @@ -201,11 +218,12 @@ where T: std::str::FromStr, G: Fn(&str) -> Result, { - let (obj, _, nonce) = fetch_obj(root_certs, url, data_builder, nonce)?; + let (obj, _, nonce) = fetch_obj(cert, root_certs, url, data_builder, nonce)?; Ok((obj, nonce)) } pub fn pool_obj( + cert: &Certificate, root_certs: &[String], url: &str, data_builder: &G, @@ -220,12 +238,12 @@ where let mut nonce: String = nonce.to_string(); for _ in 0..crate::DEFAULT_POOL_NB_TRIES { thread::sleep(time::Duration::from_secs(crate::DEFAULT_POOL_WAIT_SEC)); - let (obj, _, new_nonce) = fetch_obj(root_certs, url, data_builder, &nonce)?; + let (obj, _, new_nonce) = fetch_obj(cert, root_certs, url, data_builder, &nonce)?; if break_fn(&obj) { return Ok((obj, new_nonce)); } if let Some(e) = obj.get_error() { - warn!("Error: {}", e); + cert.warn(&e.prefix("Error").message); } nonce = new_nonce; } @@ -234,6 +252,7 @@ where } pub fn post_challenge_response( + cert: &Certificate, root_certs: &[String], url: &str, data_builder: &G, @@ -243,11 +262,12 @@ where G: Fn(&str) -> Result, { let (_, _, nonce): (DummyString, String, String) = - fetch_obj(root_certs, url, data_builder, nonce)?; + fetch_obj(cert, root_certs, url, data_builder, nonce)?; Ok(nonce) } pub fn get_certificate( + cert: &Certificate, root_certs: &[String], url: &str, data_builder: &G, @@ -257,25 +277,29 @@ where G: Fn(&str) -> Result, { let (res_body, _, nonce): (DummyString, String, String) = - fetch_obj(root_certs, url, data_builder, nonce)?; + fetch_obj(cert, root_certs, url, data_builder, nonce)?; Ok((res_body.content, nonce)) } -pub fn get_directory(root_certs: &[String], url: &str) -> Result { +pub fn get_directory( + cert: &Certificate, + root_certs: &[String], + url: &str, +) -> Result { let uri = url.parse::()?; - let mut request = new_request(root_certs, &uri, Method::GET); + let mut request = new_request(cert, root_certs, &uri, Method::GET); request.header("Accept", CONTENT_TYPE_JSON); - let (r, s) = send_request_retry(&request)?; + let (r, s) = send_request_retry(cert, &request)?; check_response(&r, &s)?; Directory::from_str(&s) } -pub fn get_nonce(root_certs: &[String], url: &str) -> Result { +pub fn get_nonce(cert: &Certificate, root_certs: &[String], url: &str) -> Result { let uri = url.parse::()?; - let request = new_request(root_certs, &uri, Method::HEAD); - let (res, res_body) = send_request_retry(&request)?; + let request = new_request(cert, root_certs, &uri, Method::HEAD); + let (res, res_body) = send_request_retry(cert, &request)?; check_response(&res, &res_body)?; - nonce_from_response(&res) + nonce_from_response(cert, &res) } #[cfg(test)] diff --git a/acmed/src/certificate.rs b/acmed/src/certificate.rs index 7074bd9..58bc2fc 100644 --- a/acmed/src/certificate.rs +++ b/acmed/src/certificate.rs @@ -3,40 +3,12 @@ use crate::config::{Account, Domain, HookType}; use crate::hooks::{self, ChallengeHookData, Hook, HookEnvData, PostOperationHookData}; use crate::storage::{certificate_files_exists, get_certificate}; use acme_common::error::Error; -use log::{debug, trace}; +use log::{debug, info, trace, warn}; use openssl::x509::X509; use std::collections::{HashMap, HashSet}; use std::fmt; use time::{strptime, Duration}; -// OpenSSL ASN1_TIME_print madness -// The real fix would be to add Asn1TimeRef access in the openssl crate. -// -// https://github.com/sfackler/rust-openssl/issues/687 -// https://github.com/sfackler/rust-openssl/pull/673 -fn parse_openssl_time_string(time: &str) -> Result { - debug!("Parsing OpenSSL time: \"{}\"", time); - let formats = [ - "%b %d %T %Y %Z", - "%b %d %T %Y %Z", - "%b %d %T %Y", - "%b %d %T %Y", - "%b %d %T.%f %Y %Z", - "%b %d %T.%f %Y %Z", - "%b %d %T.%f %Y", - "%b %d %T.%f %Y", - ]; - for fmt in formats.iter() { - if let Ok(t) = strptime(time, fmt) { - trace!("Format \"{}\" matches", fmt); - return Ok(t); - } - trace!("Format \"{}\" does not match", fmt); - } - let msg = format!("invalid time string: {}", time); - Err(msg.into()) -} - #[derive(Clone, Debug)] pub enum Algorithm { Rsa2048, @@ -89,40 +61,60 @@ pub struct Certificate { pub pk_file_owner: Option, pub pk_file_group: Option, pub env: HashMap, + pub id: usize, } impl fmt::Display for Certificate { fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { - let hooks = self - .hooks - .iter() - .map(std::string::ToString::to_string) - .collect::>() - .join(", "); - let domains = self - .domains - .iter() - .map(|d| format!("{} ({})", d.dns, d.challenge)) - .collect::>() - .join(", "); - write!( - f, - "Certificate information: -Domains: {domains} -Algorithm: {algo} -Account: {account} -Private key reuse: {kp_reuse} -Hooks: {hooks}", - domains = domains, - algo = self.algo, - account = self.account.name, - kp_reuse = self.kp_reuse, - hooks = hooks, - ) + // TODO: set a more "funky" id + write!(f, "crt-{:x}", self.id) } } impl Certificate { + pub fn warn(&self, msg: &str) { + warn!("{}: {}", &self, msg); + } + + pub fn info(&self, msg: &str) { + info!("{}: {}", &self, msg); + } + + pub fn debug(&self, msg: &str) { + debug!("{}: {}", &self, msg); + } + + pub fn trace(&self, msg: &str) { + trace!("{}: {}", &self, msg); + } + + // OpenSSL ASN1_TIME_print madness + // The real fix would be to add Asn1TimeRef access in the openssl crate. + // + // https://github.com/sfackler/rust-openssl/issues/687 + // https://github.com/sfackler/rust-openssl/pull/673 + fn parse_openssl_time_string(&self, time: &str) -> Result { + self.debug(&format!("Parsing OpenSSL time: \"{}\"", time)); + let formats = [ + "%b %d %T %Y %Z", + "%b %d %T %Y %Z", + "%b %d %T %Y", + "%b %d %T %Y", + "%b %d %T.%f %Y %Z", + "%b %d %T.%f %Y %Z", + "%b %d %T.%f %Y", + "%b %d %T.%f %Y", + ]; + for fmt in formats.iter() { + if let Ok(t) = strptime(time, fmt) { + self.trace(&format!("Format \"{}\" matches", fmt)); + return Ok(t); + } + self.trace(&format!("Format \"{}\" does not match", fmt)); + } + Err(format!("invalid time string: {}", time).into()) + } + pub fn get_domain_challenge(&self, domain_name: &str) -> Result { let domain_name = domain_name.to_string(); for d in self.domains.iter() { @@ -131,17 +123,16 @@ impl Certificate { return Ok(c); } } - let msg = format!("{}: domain name not found", domain_name); - Err(msg.into()) + Err(format!("{}: domain name not found", domain_name).into()) } fn is_expiring(&self, cert: &X509) -> Result { let not_after = cert.not_after().to_string(); - let not_after = parse_openssl_time_string(¬_after)?; - debug!("not after: {}", not_after.asctime()); + let not_after = self.parse_openssl_time_string(¬_after)?; + self.debug(&format!("not after: {}", not_after.asctime())); // TODO: allow a custom duration (using time-parse ?) let renewal_time = not_after - Duration::weeks(3); - debug!("renew on: {}", renewal_time.asctime()); + self.debug(&format!("renew on: {}", renewal_time.asctime())); Ok(time::now_utc() > renewal_time) } @@ -166,17 +157,17 @@ impl Certificate { .map(std::borrow::ToOwned::to_owned) .collect::>() .join(", "); - debug!( + self.debug(&format!( "The certificate does not include the following domains: {}", domains - ); + )); } has_miss } pub fn should_renew(&self) -> Result { if !certificate_files_exists(&self) { - debug!("certificate does not exist: requesting one"); + self.debug("certificate does not exist: requesting one"); return Ok(true); } let cert = get_certificate(&self)?; @@ -185,9 +176,9 @@ impl Certificate { let renew = renew || self.is_expiring(&cert)?; if renew { - debug!("The certificate will be renewed now."); + self.debug("The certificate will be renewed now."); } else { - debug!("The certificate will not be renewed now."); + self.debug("The certificate will not be renewed now."); } Ok(renew) } @@ -252,7 +243,35 @@ impl Certificate { #[cfg(test)] mod tests { - use super::parse_openssl_time_string; + use super::{Algorithm, Certificate}; + use std::collections::HashMap; + + fn get_dummy_certificate() -> Certificate { + Certificate { + account: crate::config::Account { + name: String::new(), + email: String::new(), + }, + domains: Vec::new(), + algo: Algorithm::Rsa2048, + kp_reuse: false, + remote_url: String::new(), + tos_agreed: false, + hooks: Vec::new(), + account_directory: String::new(), + crt_directory: String::new(), + crt_name: String::new(), + crt_name_format: String::new(), + cert_file_mode: 0, + cert_file_owner: None, + cert_file_group: None, + pk_file_mode: 0, + pk_file_owner: None, + pk_file_group: None, + env: HashMap::new(), + id: 0, + } + } #[test] fn test_parse_openssl_time() { @@ -266,8 +285,9 @@ mod tests { "May 17 18:34:07.922661874 2024", "May 17 18:34:07.922661874 2024 GMT", ]; + let crt = get_dummy_certificate(); for time_str in time_str_lst.iter() { - let time_res = parse_openssl_time_string(time_str); + let time_res = crt.parse_openssl_time_string(time_str); assert!(time_res.is_ok()); } } diff --git a/acmed/src/hooks.rs b/acmed/src/hooks.rs index 4b260cf..e5ca0aa 100644 --- a/acmed/src/hooks.rs +++ b/acmed/src/hooks.rs @@ -2,7 +2,6 @@ use crate::certificate::Certificate; use crate::config::HookType; use acme_common::error::Error; use handlebars::Handlebars; -use log::debug; use serde::Serialize; use std::collections::hash_map::Iter; use std::collections::HashMap; @@ -102,11 +101,12 @@ impl fmt::Display for Hook { } macro_rules! get_hook_output { - ($out: expr, $reg: ident, $data: expr) => {{ + ($cert: expr, $out: expr, $reg: ident, $data: expr, $hook_name: expr, $out_name: expr) => {{ match $out { Some(path) => { let path = $reg.render_template(path, $data)?; - let file = File::create(path)?; + $cert.trace(&format!("Hook {}: {}: {}", $hook_name, $out_name, &path)); + let file = File::create(&path)?; Stdio::from(file) } None => Stdio::null(), @@ -114,11 +114,11 @@ macro_rules! get_hook_output { }}; } -fn call_single(data: &T, hook: &Hook) -> Result<(), Error> +fn call_single(cert: &Certificate, data: &T, hook: &Hook) -> Result<(), Error> where T: Clone + HookEnvData + Serialize, { - debug!("Calling hook: {}", hook.name); + cert.debug(&format!("Calling hook: {}", hook.name)); let reg = Handlebars::new(); let mut v = vec![]; let args = match &hook.args { @@ -131,13 +131,27 @@ where } None => &[], }; - debug!("Hook {}: cmd: {}", hook.name, hook.cmd); - debug!("Hook {}: args: {:?}", hook.name, args); + cert.trace(&format!("Hook {}: cmd: {}", hook.name, hook.cmd)); + cert.trace(&format!("Hook {}: args: {:?}", hook.name, args)); let mut cmd = Command::new(&hook.cmd) .envs(data.get_env()) .args(args) - .stdout(get_hook_output!(&hook.stdout, reg, &data)) - .stderr(get_hook_output!(&hook.stderr, reg, &data)) + .stdout(get_hook_output!( + cert, + &hook.stdout, + reg, + &data, + &hook.name, + "stdout" + )) + .stderr(get_hook_output!( + cert, + &hook.stderr, + reg, + &data, + &hook.name, + "stderr" + )) .stdin(match &hook.stdin { HookStdin::Str(_) | HookStdin::File(_) => Stdio::piped(), HookStdin::None => Stdio::null(), @@ -146,13 +160,13 @@ where match &hook.stdin { HookStdin::Str(s) => { let data_in = reg.render_template(&s, &data)?; - debug!("Hook {}: string stdin: {}", hook.name, &data_in); + cert.trace(&format!("Hook {}: string stdin: {}", hook.name, &data_in)); let stdin = cmd.stdin.as_mut().ok_or("stdin not found")?; stdin.write_all(data_in.as_bytes())?; } HookStdin::File(f) => { let file_name = reg.render_template(&f, &data)?; - debug!("Hook {}: file stdin: {}", hook.name, &file_name); + cert.trace(&format!("Hook {}: file stdin: {}", hook.name, &file_name)); let stdin = cmd.stdin.as_mut().ok_or("stdin not found")?; let file = File::open(&file_name)?; let buf_reader = BufReader::new(file); @@ -167,14 +181,14 @@ where let status = cmd.wait()?; if !status.success() && !hook.allow_failure { let msg = match status.code() { - Some(code) => format!("Hook {}: unrecoverable failure: code {}", hook.name, code), - None => format!("Hook {}: unrecoverable failure", hook.name), + Some(code) => format!("Unrecoverable failure: code {}", code).into(), + None => "Unrecoverable failure".into(), }; - return Err(msg.into()); + return Err(msg); } match status.code() { - Some(code) => debug!("Hook {}: exited: code {}", hook.name, code), - None => debug!("Hook {}: exited", hook.name), + Some(code) => cert.debug(&format!("Hook {}: exited: code {}", hook.name, code)), + None => cert.debug(&format!("Hook {}: exited", hook.name)), }; Ok(()) } @@ -188,7 +202,7 @@ where .iter() .filter(|h| h.hook_type.contains(&hook_type)) { - call_single(data, &hook)?; + call_single(cert, data, &hook).map_err(|e| e.prefix(&hook.name))?; } Ok(()) } diff --git a/acmed/src/main_event_loop.rs b/acmed/src/main_event_loop.rs index f362256..db89efd 100644 --- a/acmed/src/main_event_loop.rs +++ b/acmed/src/main_event_loop.rs @@ -2,7 +2,6 @@ use crate::acme_proto::request_certificate; use crate::certificate::Certificate; use crate::config; use acme_common::error::Error; -use log::{debug, warn}; use std::thread; use std::time::Duration; @@ -16,7 +15,7 @@ impl MainEventLoop { let cnf = config::from_file(config_file)?; let mut certs = Vec::new(); - for crt in cnf.certificate.iter() { + for (i, crt) in cnf.certificate.iter().enumerate() { let cert = Certificate { account: crt.get_account(&cnf)?, domains: crt.domains.to_owned(), @@ -36,6 +35,7 @@ impl MainEventLoop { pk_file_owner: cnf.get_pk_file_user(), pk_file_group: cnf.get_pk_file_group(), env: crt.env.to_owned(), + id: i + 1, }; certs.push(cert); } @@ -49,7 +49,6 @@ impl MainEventLoop { pub fn run(&mut self) { loop { for crt in self.certs.iter_mut() { - debug!("{}", crt); match crt.should_renew() { Ok(sr) => { if sr { @@ -57,32 +56,22 @@ impl MainEventLoop { match request_certificate(crt, &self.root_certs) { Ok(_) => ("Success.".to_string(), true), Err(e) => { - let msg = format!( - "Unable to renew the {} certificate for {}: {}", - crt.algo, - &crt.domains.first().unwrap().dns, - e - ); - warn!("{}", msg); - (format!("Failed: {}", msg), false) + let e = e.prefix("Unable to renew the certificate"); + crt.warn(&e.message); + (e.message, false) } }; match crt.call_post_operation_hooks(&status, is_success) { Ok(_) => {} Err(e) => { - let msg = format!( - "{} certificate for {}: post-operation hook error: {}", - crt.algo, - &crt.domains.first().unwrap().dns, - e - ); - warn!("{}", msg); + let e = e.prefix("Post-operation hook error"); + crt.warn(&e.message); } }; } } Err(e) => { - warn!("{}", e); + crt.warn(&e.message); } }; } diff --git a/acmed/src/storage.rs b/acmed/src/storage.rs index daa910b..966161a 100644 --- a/acmed/src/storage.rs +++ b/acmed/src/storage.rs @@ -3,7 +3,6 @@ use crate::config::HookType; use crate::hooks::{self, FileStorageHookData, HookEnvData}; use acme_common::b64_encode; use acme_common::error::Error; -use log::trace; use openssl::pkey::{PKey, Private, Public}; use openssl::x509::X509; use std::collections::HashMap; @@ -72,8 +71,8 @@ fn get_file_path(cert: &Certificate, file_type: FileType) -> Result Result, Error> { - trace!("Reading file {:?}", path); +fn read_file(cert: &Certificate, path: &PathBuf) -> Result, Error> { + cert.trace(&format!("Reading file {:?}", path)); let mut file = File::open(path)?; let mut contents = vec![]; file.read_to_end(&mut contents)?; @@ -120,12 +119,12 @@ fn set_owner(cert: &Certificate, path: &PathBuf, file_type: FileType) -> Result< None => None, }; match uid { - Some(u) => trace!("Setting the uid to {}", u.as_raw()), - None => trace!("Uid unchanged"), + Some(u) => cert.trace(&format!("{:?}: setting the uid to {}", path, u.as_raw())), + None => cert.trace(&format!("{:?}: uid unchanged", path)), }; match gid { - Some(g) => trace!("Setting the gid to {}", g.as_raw()), - None => trace!("Gid unchanged"), + Some(g) => cert.trace(&format!("{:?}: setting the gid to {}", path, g.as_raw())), + None => cert.trace(&format!("{:?}: gid unchanged", path)), }; match nix::unistd::chown(path, uid, gid) { Ok(_) => Ok(()), @@ -150,7 +149,7 @@ fn write_file(cert: &Certificate, file_type: FileType, data: &[u8]) -> Result<() hooks::call(cert, &hook_data, HookType::FilePreEdit)?; } - trace!("Writing file {:?}", path); + cert.trace(&format!("Writing file {:?}", path)); let mut file = if cfg!(unix) { let mut options = OpenOptions::new(); options.mode(match &file_type { @@ -178,7 +177,7 @@ fn write_file(cert: &Certificate, file_type: FileType, data: &[u8]) -> Result<() pub fn get_account_priv_key(cert: &Certificate) -> Result, Error> { let path = get_file_path(cert, FileType::AccountPrivateKey)?; - let raw_key = read_file(&path)?; + let raw_key = read_file(cert, &path)?; let key = PKey::private_key_from_pem(&raw_key)?; Ok(key) } @@ -190,7 +189,7 @@ pub fn set_account_priv_key(cert: &Certificate, key: &PKey) -> Result<( pub fn get_account_pub_key(cert: &Certificate) -> Result, Error> { let path = get_file_path(cert, FileType::AccountPublicKey)?; - let raw_key = read_file(&path)?; + let raw_key = read_file(cert, &path)?; let key = PKey::public_key_from_pem(&raw_key)?; Ok(key) } @@ -202,7 +201,7 @@ pub fn set_account_pub_key(cert: &Certificate, key: &PKey) -> Result<(), pub fn get_priv_key(cert: &Certificate) -> Result, Error> { let path = get_file_path(cert, FileType::PrivateKey)?; - let raw_key = read_file(&path)?; + let raw_key = read_file(cert, &path)?; let key = PKey::private_key_from_pem(&raw_key)?; Ok(key) } @@ -219,7 +218,7 @@ pub fn get_pub_key(cert: &Certificate) -> Result, Error> { pub fn get_certificate(cert: &Certificate) -> Result { let path = get_file_path(cert, FileType::Certificate)?; - let raw_crt = read_file(&path)?; + let raw_crt = read_file(cert, &path)?; let crt = X509::from_pem(&raw_crt)?; Ok(crt) } @@ -236,7 +235,7 @@ fn check_files(cert: &Certificate, file_types: &[FileType]) -> bool { return false; } }; - trace!("Testing file path: {}", path.to_str().unwrap()); + cert.trace(&format!("Testing file path: {}", path.to_str().unwrap())); if !path.is_file() { return false; }