From c562bfbad03c32907e6e7f9c628deaaf26ef8920 Mon Sep 17 00:00:00 2001 From: Matthew Jackson <1085847+MattJackson@users.noreply.github.com> Date: Wed, 7 Oct 2026 03:31:30 -0700 Subject: [PATCH] online: log the connection-slot wait and DNS lookup time Address count only, never the address. Separates local waits from the key-service POST when a lookup is slow. --- CHANGELOG.md | 6 ++++++ src/online.rs | 17 ++++++++++++++++- 2 files changed, 22 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 15efce7..eee8a58 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,11 @@ # Changelog +## [Unreleased] + +### Added + +- The online source logs the connection-slot wait and the DNS lookup time (address count only, never the address) before each key-service POST. + ## [1.8.1] — 2026-10-07 ### Changed diff --git a/src/online.rs b/src/online.rs index d180d78..beabdae 100644 --- a/src/online.rs +++ b/src/online.rs @@ -517,7 +517,9 @@ fn run_on_worker( halt: &Halt, work: impl FnOnce() -> WorkerOutcome + Send + 'static, ) -> Result, Error> { + let waited = std::time::Instant::now(); let slot = acquire_query_slot(host, halt)?; + tracing::info!(target: "freemkv::keysource", phase = "keyserver_slot", waited_ms = waited.elapsed().as_millis() as u64, "key-service connection slot acquired"); let (tx, rx) = mpsc::channel(); let spawned = std::thread::Builder::new() .name("keysource-online".into()) @@ -788,7 +790,20 @@ impl PostJob { None => resolve_and_guard(&self.url), }; #[cfg(not(test))] - let guarded = resolve_and_guard(&self.url); + let guarded = { + let t0 = std::time::Instant::now(); + let g = resolve_and_guard(&self.url); + // Count only: the addresses themselves are never logged. + tracing::info!( + target: "freemkv::keysource", + phase = "keyserver_dns", + ok = g.is_ok(), + addrs = g.as_ref().map(|a| a.len()).unwrap_or(0), + elapsed_ms = t0.elapsed().as_millis() as u64, + "key-service host resolved" + ); + g + }; // Resolve + SSRF-guard the host just before the POST and pin the validated addresses, // so a DNS rebind after config time can't redirect the request to an internal host. let pinned = match guarded {