From 01b47fb010a38ea535ebb6fbda82a2153502ad58 Mon Sep 17 00:00:00 2001 From: Brian Picciano Date: Tue, 13 Jun 2023 21:33:43 +0200 Subject: [PATCH] Add real logging --- Cargo.lock | 37 +++++++++++++++++++++++++----- Cargo.toml | 2 ++ TODO | 1 - src/domain/acme/manager.rs | 22 +++++++++--------- src/domain/acme/store.rs | 4 ++-- src/main.rs | 46 +++++++++++++++++++++++++++----------- 6 files changed, 80 insertions(+), 32 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index fe0c74a..5a33bd8 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -449,12 +449,14 @@ version = "0.1.0" dependencies = [ "acme2", "clap", + "env_logger", "futures", "gix", "handlebars", "hex", "http", "hyper", + "log", "mime_guess", "mockall", "openssl", @@ -522,6 +524,19 @@ dependencies = [ "syn 1.0.109", ] +[[package]] +name = "env_logger" +version = "0.10.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "85cdab6a89accf66733ad5a1693a4dcced6aeff64602b634530dd73c1f3ee9f0" +dependencies = [ + "humantime", + "is-terminal", + "log", + "regex", + "termcolor", +] + [[package]] name = "errno" version = "0.3.1" @@ -1468,6 +1483,12 @@ version = "1.0.3" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "86cce260d758a9aa3d7c4b99d55c815a540f8a37514ba6046ab6be402a157cb0" +[[package]] +name = "humantime" +version = "2.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9a3a5bfb195931eeb336b2a7b4d761daec841b97f947d34394601737a7bba5e4" + [[package]] name = "hyper" version = "0.14.26" @@ -1715,12 +1736,9 @@ dependencies = [ [[package]] name = "log" -version = "0.4.17" +version = "0.4.19" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "abb12e687cfb44aa40f41fc3978ef76448f9b6038cad6aef4259d3c095a2382e" -dependencies = [ - "cfg-if", -] +checksum = "b06a4cde4c0f271a446782e3eff8de789548ce57dbc8eca9292c27f4a42004b4" [[package]] name = "lru-cache" @@ -2689,6 +2707,15 @@ dependencies = [ "windows-sys 0.45.0", ] +[[package]] +name = "termcolor" +version = "1.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "be55cf8942feac5c765c2c993422806843c9a9a45d4d5c407ad6dd2ea95eb9b6" +dependencies = [ + "winapi-util", +] + [[package]] name = "termtree" version = "0.4.1" diff --git a/Cargo.toml b/Cargo.toml index 6c5c1c0..e954671 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -39,3 +39,5 @@ pem = "2.0.1" serde_with = "3.0.0" tls-listener = { version = "0.7.0", features = [ "rustls", "hyper-h1" ]} tokio-rustls = "0.24.0" +log = "0.4.19" +env_logger = "0.10.0" diff --git a/TODO b/TODO index 035c319..afbad36 100644 --- a/TODO +++ b/TODO @@ -1,4 +1,3 @@ -- logging - expect statements (pretend it's "expected", not "expect") - map_unexpected annotation string - clean up main a lot diff --git a/src/domain/acme/manager.rs b/src/domain/acme/manager.rs index 9a52d9d..d0bd4ee 100644 --- a/src/domain/acme/manager.rs +++ b/src/domain/acme/manager.rs @@ -104,7 +104,7 @@ where } } - println!("fetching a new certificate for domain {}", domain.as_str()); + log::info!("Fetching a new certificate for domain {}", domain.as_str()); let mut builder = acme2::OrderBuilder::new(self.account.clone()); builder.add_dns_identifier(domain.as_str().to_string()); let order = builder.build().await.map_unexpected()?; @@ -137,8 +137,8 @@ where // `validate()` call below will instigate the acme server to make this check, and // block until it succeeds. - println!( - "waiting for ACME challenge to be validated for domain {}", + log::info!( + "Waiting for ACME challenge to be validated for domain {}", domain.as_str(), ); let challenge = challenge.validate().await.map_unexpected()?; @@ -166,8 +166,8 @@ where // Poll the authorization every 5 seconds until it is in either the // `valid` or `invalid` state. - println!( - "waiting for ACME authorization to be validated for domain {}", + log::info!( + "Waiting for ACME authorization to be validated for domain {}", domain.as_str(), ); @@ -189,8 +189,8 @@ where // Poll the order every 5 seconds until it is in either the `ready` or `invalid` state. // Ready means that it is now ready for finalization (certificate creation). - println!( - "waiting for ACME order to be made ready for domain {}", + log::info!( + "Waiting for ACME order to be made ready for domain {}", domain.as_str(), ); @@ -224,8 +224,8 @@ where // Poll the order every 5 seconds until it is in either the // `valid` or `invalid` state. Valid means that the certificate // has been provisioned, and is now ready for download. - println!( - "waiting for ACME order to be validated for domain {}", + log::info!( + "Waiting for ACME order to be validated for domain {}", domain.as_str(), ); let order = order @@ -244,7 +244,7 @@ where } // Download the certificate, and panic if it doesn't exist. - println!("fetching certificate for domain {}", domain.as_str()); + log::info!("Fetching certificate for domain {}", domain.as_str()); let cert = order .certificate() .await @@ -267,7 +267,7 @@ where )); } - println!("certificate for {} successfully retrieved", domain.as_str()); + log::info!("Certificate for {} successfully retrieved", domain.as_str()); self.store .set_certificate(domain.as_str(), pkey, cert) .map_unexpected()?; diff --git a/src/domain/acme/store.rs b/src/domain/acme/store.rs index b975347..d712ecd 100644 --- a/src/domain/acme/store.rs +++ b/src/domain/acme/store.rs @@ -198,7 +198,7 @@ impl rustls::server::ResolvesServerCert for BoxedFSStore { match self.get_certificate(domain) { Err(GetCertificateError::NotFound) => { - println!("No cert found for domain {domain}"); + log::warn!("No cert found for domain {domain}"); Ok(None) } Err(GetCertificateError::Unexpected(err)) => Err(err), @@ -215,7 +215,7 @@ impl rustls::server::ResolvesServerCert for BoxedFSStore { } } .unwrap_or_else(|err| { - println!("Unexpected error getting cert for domain {domain}: {err}"); + log::error!("Unexpected error getting cert for domain {domain}: {err}"); None }) } diff --git a/src/main.rs b/src/main.rs index 58a5bef..ea242ed 100644 --- a/src/main.rs +++ b/src/main.rs @@ -19,6 +19,17 @@ use domiply::domain::manager::Manager; #[command(version)] #[command(about = "A domiply to another dimension")] struct Cli { + #[arg( + long, + help = "OFF, ERROR, WARN, INFO, DEBUG, or TRACE", + default_value_t = log::LevelFilter::Info, + env = "DOMIPLY_LOG_LEVEL" + )] + log_level: log::LevelFilter, + + #[arg(long, default_value_t = false, env = "DOMIPLY_LOG_TIMESTAMP")] + log_timestamp: bool, + #[arg(long, required = true, env = "DOMIPLY_HTTP_DOMAIN")] http_domain: domiply::domain::Name, @@ -71,6 +82,15 @@ where async fn main() { let config = Cli::parse(); + env_logger::Builder::new() + .filter_level(config.log_level) + .format_timestamp( + config + .log_timestamp + .then_some(env_logger::TimestampPrecision::Micros), + ) + .init(); + let mut wait_group = FuturesUnordered::new(); let canceller = tokio_util::sync::CancellationToken::new(); @@ -82,12 +102,12 @@ async fn main() { Signals::new(signal_hook::consts::TERM_SIGNALS).expect("initialized signals"); if (signals.next().await).is_some() { - println!("Gracefully shutting down..."); + log::info!("Gracefully shutting down..."); canceller.cancel(); } if (signals.next().await).is_some() { - println!("Forcefully shutting down"); + log::warn!("Forcefully shutting down"); std::process::exit(1); }; }); @@ -157,7 +177,7 @@ async fn main() { let errors_iter = domain_manager.sync_all_origins(); if let Err(err) = errors_iter { - println!("Got error calling sync_all_origins: {err}"); + log::error!("Got error calling sync_all_origins: {err}"); continue; } @@ -165,8 +185,8 @@ async fn main() { .unwrap() .into_iter() .for_each(|(descr, err)| match descr { - None => println!("error while syncing unknown descr: {err}"), - Some(descr) => println!("failed to sync {descr:?}: {err}"), + None => log::error!("Error while syncing unknown descr: {err}"), + Some(descr) => log::error!("Failed to sync {descr:?}: {err}"), }); } }) @@ -201,7 +221,7 @@ async fn main() { tokio::spawn(async move { let addr = config.http_listen_addr; - println!( + log::info!( "Listening on http://{}:{}", http_domain.as_str(), addr.port() @@ -240,7 +260,7 @@ async fn main() { .sync_domain(http_domain.clone()) .await .inspect_err(|err| { - println!( + log::error!( "Error while getting cert for {}: {err}", http_domain.as_str() ) @@ -249,7 +269,7 @@ async fn main() { let domains_iter = domain_manager.all_domains(); if let Err(err) = domains_iter { - println!("Got error calling all_domains: {err}"); + log::error!("Got error calling all_domains: {err}"); continue; } @@ -261,13 +281,13 @@ async fn main() { .sync_domain(domain.clone()) .await .inspect_err(|err| { - println!( + log::error!( "Error while getting cert for {}: {err}", domain.as_str(), ) }); } - Err(err) => println!("Error iterating through domains: {err}"), + Err(err) => log::error!("Error iterating through domains: {err}"), }; } } @@ -310,7 +330,7 @@ async fn main() { let incoming = tls_listener::TlsListener::new(server_config, addr_incoming).filter(|conn| { if let Err(err) = conn { - println!("Error accepting TLS connection: {:?}", err); + log::error!("Error accepting TLS connection: {:?}", err); future::ready(false) } else { future::ready(true) @@ -319,7 +339,7 @@ async fn main() { let incoming = hyper::server::accept::from_stream(incoming); - println!( + log::info!( "Listening on https://{}:{}", http_domain.as_str(), addr.port() @@ -340,5 +360,5 @@ async fn main() { while wait_group.next().await.is_some() {} - println!("Graceful shutdown complete"); + log::info!("Graceful shutdown complete"); }