Improve the logging format

In order to renew different certificate at the same time, log messages
must display which certificate they are referring to.

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

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)

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(())
 }

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,

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<String, Error> {
+fn nonce_from_response(cert: &Certificate, res: &Response) -> Result<String, Error> {
     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<String, Error> {
 }
 
 fn post_jose_type(
+    cert: &Certificate,
     root_certs: &[String],
     url: &str,
     data: &[u8],
     accept_type: &str,
 ) -> Result<(Response, String), Error> {
     let uri = url.parse::<Uri>()?;
-    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<T, G>(
+    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<T, G>(
+    cert: &Certificate,
     root_certs: &[String],
     url: &str,
     data_builder: &G,
@@ -170,10 +178,18 @@ where
     T: std::str::FromStr<Err = Error>,
     G: Fn(&str) -> Result<String, Error>,
 {
-    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<T, G>(
+    cert: &Certificate,
     root_certs: &[String],
     url: &str,
     data_builder: &G,
@@ -183,7 +199,7 @@ where
     T: std::str::FromStr<Err = Error>,
     G: Fn(&str) -> Result<String, Error>,
 {
-    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<T, G>(
+    cert: &Certificate,
     root_certs: &[String],
     url: &str,
     data_builder: &G,
@@ -201,11 +218,12 @@ where
     T: std::str::FromStr<Err = Error>,
     G: Fn(&str) -> Result<String, Error>,
 {
-    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<T, G, S>(
+    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<G>(
+    cert: &Certificate,
     root_certs: &[String],
     url: &str,
     data_builder: &G,
@@ -243,11 +262,12 @@ where
     G: Fn(&str) -> Result<String, Error>,
 {
     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<G>(
+    cert: &Certificate,
     root_certs: &[String],
     url: &str,
     data_builder: &G,
@@ -257,25 +277,29 @@ where
     G: Fn(&str) -> Result<String, Error>,
 {
     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<Directory, Error> {
+pub fn get_directory(
+    cert: &Certificate,
+    root_certs: &[String],
+    url: &str,
+) -> Result<Directory, Error> {
     let uri = url.parse::<Uri>()?;
-    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<String, Error> {
+pub fn get_nonce(cert: &Certificate, root_certs: &[String], url: &str) -> Result<String, Error> {
     let uri = url.parse::<Uri>()?;
-    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)]

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<time::Tm, Error> {
-    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<String>,
     pub pk_file_group: Option<String>,
     pub env: HashMap<String, String>,
+    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::<Vec<String>>()
-            .join(", ");
-        let domains = self
-            .domains
-            .iter()
-            .map(|d| format!("{} ({})", d.dns, d.challenge))
-            .collect::<Vec<String>>()
-            .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<time::Tm, Error> {
+        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<Challenge, Error> {
         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<bool, Error> {
         let not_after = cert.not_after().to_string();
-        let not_after = parse_openssl_time_string(&not_after)?;
-        debug!("not after: {}", not_after.asctime());
+        let not_after = self.parse_openssl_time_string(&not_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::<Vec<String>>()
                 .join(", ");
-            debug!(
+            self.debug(&format!(
                 "The certificate does not include the following domains: {}",
                 domains
-            );
+            ));
         }
         has_miss
     }
 
     pub fn should_renew(&self) -> Result<bool, Error> {
         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());
         }
     }

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<T>(data: &T, hook: &Hook) -> Result<(), Error>
+fn call_single<T>(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(())
 }

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);
                     }
                 };
             }

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<PathBuf, Err
     Ok(path)
 }
 
-fn read_file(path: &PathBuf) -> Result<Vec<u8>, Error> {
-    trace!("Reading file {:?}", path);
+fn read_file(cert: &Certificate, path: &PathBuf) -> Result<Vec<u8>, 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<PKey<Private>, 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<Private>) -> Result<(
 
 pub fn get_account_pub_key(cert: &Certificate) -> Result<PKey<Public>, 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<Public>) -> Result<(),
 
 pub fn get_priv_key(cert: &Certificate) -> Result<PKey<Private>, 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<PKey<Public>, Error> {
 
 pub fn get_certificate(cert: &Certificate) -> Result<X509, Error> {
     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;
         }