From da10ff09bafab8d1ca88fbd13c51c5826fb41ff5 Mon Sep 17 00:00:00 2001 From: Tim Bruijnzeels Date: Mon, 10 May 2021 15:10:49 +0200 Subject: [PATCH] Log resource diffs where applicable (#514) Also fixes an issue with requesting new certificates too often. --- Cargo.lock | 4 +- Cargo.toml | 2 +- src/commons/api/ca.rs | 77 +++++++++++++++++++++++++++++++++++ src/daemon/ca/certauth.rs | 12 ++++-- src/daemon/ca/keys.rs | 86 +++++++++++++++++++++++++-------------- src/daemon/ca/rc.rs | 58 ++++++++++++++++---------- 6 files changed, 181 insertions(+), 58 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 1f386390..e99a970e 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2091,9 +2091,9 @@ dependencies = [ [[package]] name = "rpki" -version = "0.10.0" +version = "0.10.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "75e999e1cb19aeb312c08c95bfd195f724dd05abd96ddc2cc6fa70b0cddb5927" +checksum = "4d5213cb2d9773bd7d968f9d66a50409e1891ddd1f6abf6d2573f8d841e3004b" dependencies = [ "base64 0.13.0", "bcder", diff --git a/Cargo.toml b/Cargo.toml index 3bdf50e6..08c6004b 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -40,7 +40,7 @@ regex = { version = "^1.4", optional = true, default_features = reqwest = { version = "0.10.8", features = ["json"] } reqwestblocking = { version = "0.9.24", optional = true, package = "reqwest" } rpassword = { version = "^5.0", optional = true } -rpki = "^0.10.0" +rpki = "^0.10.1" scrypt = { version = "^0.6", optional = true, default-features = false } serde = { version = "^1.0", features = ["derive"] } serde_json = "^1.0" diff --git a/src/commons/api/ca.rs b/src/commons/api/ca.rs index 6cc22976..1ab221f3 100644 --- a/src/commons/api/ca.rs +++ b/src/commons/api/ca.rs @@ -928,6 +928,21 @@ impl ResourceSet { ResourceSet { asn, v4, v6 } } + /// Returns the difference from another ResourceSet towards `self`. + pub fn difference(&self, other: &ResourceSet) -> ResourceSetDiff { + let added = ResourceSet { + asn: self.asn.difference(&other.asn), + v4: self.v4.difference(&other.v4), + v6: self.v6.difference(&other.v6), + }; + let removed = ResourceSet { + asn: other.asn.difference(&self.asn), + v4: other.v4.difference(&self.v4), + v6: other.v6.difference(&self.v6), + }; + ResourceSetDiff { added, removed } + } + pub fn contains_roa_address(&self, roa_address: &RoaIpAddress) -> bool { self.v4.contains_roa(roa_address) || self.v6.contains_roa(roa_address) } @@ -993,6 +1008,39 @@ impl fmt::Display for ResourceSet { } } +//------------ ResourceSetDiff ----------------------------------------------- + +#[derive(Clone, Debug, Deserialize, Eq, PartialEq, Serialize)] +pub struct ResourceSetDiff { + added: ResourceSet, + removed: ResourceSet +} + +impl ResourceSetDiff { + pub fn is_empty(&self) -> bool { + self.added.is_empty() && self.removed.is_empty() + } +} + +impl fmt::Display for ResourceSetDiff { + fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { + if self.is_empty() { + write!(f, "")?; + } + if !self.added.is_empty() { + write!(f, "Added: {}", self.added)?; + if !self.removed.is_empty() { + write!(f, " ")?; + } + } + if !self.removed.is_empty() { + write!(f, "Removed: {}", self.removed)?; + } + + Ok(()) + } +} + //------------ CertAuthList -------------------------------------------------- #[derive(Clone, Debug, Deserialize, Eq, PartialEq, Serialize)] @@ -2274,6 +2322,35 @@ mod test { assert_eq!(empty_set, empty_set_from_string); } + #[test] + fn resource_set_difference() { + let set1_asns = "AS65000-AS65003, AS65005"; + let set2_asns = "AS65000, AS65003, AS65005"; + let asn_added = "AS65001-AS65002"; + + let set1_ipv4s = "10.0.0.0-10.4.5.6, 192.168.0.0"; + let set2_ipv4s = "10.0.0.0/8, 192.168.0.0"; + let ipv4_removed = "10.4.5.7-10.255.255.255"; + + let set1_ipv6s = "::1, 2001:db8::/32"; + let set2_ipv6s = "::1, 2001:db8::/56"; + let ipv6_added = "2001:db8:0:100::-2001:db8:ffff:ffff:ffff:ffff:ffff:ffff"; + + let set1 = ResourceSet::from_strs(set1_asns, set1_ipv4s, set1_ipv6s).unwrap(); + let set2 = ResourceSet::from_strs(set2_asns, set2_ipv4s, set2_ipv6s).unwrap(); + + let diff = set1.difference(&set2); + + let expected_diff = ResourceSetDiff { + added: ResourceSet::from_strs(asn_added, "", ipv6_added).unwrap(), + removed: ResourceSet::from_strs("", ipv4_removed, "").unwrap(), + + }; + + assert!(!diff.is_empty()); + assert_eq!(expected_diff, diff); + } + #[test] fn serde_cert_auth_issues() { let mut issues = CertAuthIssues::default(); diff --git a/src/daemon/ca/certauth.rs b/src/daemon/ca/certauth.rs index 740670d1..7d022ef9 100644 --- a/src/daemon/ca/certauth.rs +++ b/src/daemon/ca/certauth.rs @@ -809,7 +809,11 @@ impl CertAuth { Err(Error::CaChildExtraResources(self.handle.clone(), child_handle.clone())) } else { let child = self.get_child(child_handle)?; - if &resources != child.resources() { + let diff = resources.difference(child.resources()); + + if !diff.is_empty() { + info!("Updating resources for child '{}' under CA '{}': {}", child_handle, self.handle(), diff); + Ok(vec![CaEvtDet::child_updated_resources( &self.handle, self.version, @@ -1048,7 +1052,7 @@ impl CertAuth { signer: &KrillSigner, ) -> KrillResult> { let repo = self.repository_contact()?; - rc.make_entitlement_events(entitlement, repo.repo_info(), signer) + rc.make_entitlement_events(self.handle(), entitlement, repo.repo_info(), signer) } /// Returns the open revocation requests for the given parent. @@ -1116,7 +1120,7 @@ impl CertAuth { }) { let revoke_requests = rc.revoke(signer.deref())?; - debug!("Updating Entitlements for CA: {}, Removing RC: {}", &self.handle, &rcn); + info!("Updating Entitlements for CA: {}, Removing RC: {}", &self.handle, &rcn); event_details.push(CaEvtDet::ResourceClassRemoved { resource_class_name: rcn.clone(), @@ -1192,7 +1196,7 @@ impl CertAuth { let rc = self.resources.get(&rcn).ok_or(Error::ResourceClassUnknown(rcn))?; - let evt_details = rc.update_received_cert(rcvd_cert, &self.routes, config, signer.deref())?; + let evt_details = rc.update_received_cert(self.handle(), rcvd_cert, &self.routes, config, signer.deref())?; let mut res = vec![]; let mut version = self.version; diff --git a/src/daemon/ca/keys.rs b/src/daemon/ca/keys.rs index 2a7e529e..4783265b 100644 --- a/src/daemon/ca/keys.rs +++ b/src/daemon/ca/keys.rs @@ -5,11 +5,7 @@ use serde::{Deserialize, Serialize}; use rpki::crypto::KeyIdentifier; use rpki::x509::Time; -use crate::commons::api::{ - ActiveInfo, CertifiedKeyInfo, EntitlementClass, IssuanceRequest, PendingInfo, PendingKeyInfo, RcvdCert, RepoInfo, - RequestResourceLimit, ResourceClassKeysInfo, ResourceClassName, ResourceSet, RevocationRequest, RollNewInfo, - RollOldInfo, RollPendingInfo, -}; +use crate::commons::api::{ActiveInfo, CertifiedKeyInfo, EntitlementClass, Handle, IssuanceRequest, PendingInfo, PendingKeyInfo, RcvdCert, RepoInfo, RequestResourceLimit, ResourceClassKeysInfo, ResourceClassName, ResourceSet, RevocationRequest, RollNewInfo, RollOldInfo, RollPendingInfo}; use crate::commons::crypto::KrillSigner; use crate::commons::error::Error; use crate::commons::KrillResult; @@ -74,13 +70,16 @@ impl CertifiedKey { self.old_repo = Some(repo.clone()) } - pub fn wants_update(&self, new_resources: &ResourceSet, new_not_after: Time) -> bool { + pub fn wants_update(&self, handle: &Handle, rcn: &ResourceClassName, new_resources: &ResourceSet, new_not_after: Time) -> bool { // If resources have changed, then we need to request a new certificate. - if self.incoming_cert.resources() != new_resources { - debug!( - "Resources have changed from:\n{}\nto:\n{}\n", - self.incoming_cert.resources(), - new_resources + let resources_diff = new_resources.difference(self.incoming_cert.resources()); + + if !resources_diff.is_empty() { + info!( + "Will request new certificate for CA '{}' under RC '{}'. Resources have changed:{}\n", + handle, + rcn, + resources_diff ); return true; } @@ -97,26 +96,52 @@ impl CertifiedKey { let not_after = self.incoming_cert().cert().validity().not_after(); - let not_after = not_after.timestamp_millis(); - let new_not_after = new_not_after.timestamp_millis(); + let now = Time::now().timestamp_millis(); + let until_not_after_millis = not_after.timestamp_millis() - now; + let until_new_not_after_millis = new_not_after.timestamp_millis() - now; - if not_after == new_not_after { - trace!("No change in not after time for certificate for key '{}'", self.key_id); - false - } else if not_after < new_not_after { + if until_new_not_after_millis < 0 { + // New not after time is in the past! + // + // This is rather odd. The parent should just exclude the resource class in the + // eligible entitlements instead. So, we will essentially just ignore this until + // they do. warn!( - "Parent reduced not after time for certificate for key '{}'", - self.key_id + "Will NOT request certificate for CA '{}' under RC '{}', the eligible not after time is set in the past: {}", + handle, + rcn, + new_not_after.to_rfc3339() + ); + false + } else if until_not_after_millis == until_new_not_after_millis { + debug!( + "Will not request new certificate for CA '{}' under RC '{}'. Resources and not after time are unchanged\n", + handle, + rcn, + ); + false + } else if until_new_not_after_millis < until_not_after_millis { + warn!( + "Parent of CA '{}' reduced not after time for certificate under RC '{}'", + handle, + rcn, ); true - } else if (new_not_after as f64 / not_after as f64) > 1.1_f64 { - debug!( - "Parent increased not after time >10% for certificate for key '{}'", - self.key_id + } else if until_not_after_millis <= 0 || (until_new_not_after_millis as f64 / until_not_after_millis as f64) > 1.1_f64 { + info!( + "Will request new certificate for CA '{}' under RC '{}'. Not after time increased to: {}\n", + handle, + rcn, + new_not_after.to_rfc3339() ); true } else { - debug!("New not after time less than 10% after current time for for certificate for key '{}', not requesting a new certificate.", self.key_id); + debug!( + "Will not request new certificate for CA '{}' under RC '{}'. Not after time increased by less than 10%: {}\n", + handle, + rcn, + new_not_after.to_rfc3339() + ); false } } @@ -279,6 +304,7 @@ impl KeyState { pub fn make_entitlement_events( &self, + handle: &Handle, rcn: ResourceClassName, entitlement: &EntitlementClass, base_repo: &RepoInfo, @@ -292,34 +318,34 @@ impl KeyState { keys_for_requests.push((base_repo, pending.key_id())); } KeyState::Active(current) => { - if current.wants_update(entitlement.resource_set(), entitlement.not_after()) { + if current.wants_update(handle, &rcn, entitlement.resource_set(), entitlement.not_after()) { let repo = current.old_repo.as_ref().unwrap_or(base_repo); keys_for_requests.push((repo, current.key_id())); } } KeyState::RollPending(pending, current) => { keys_for_requests.push((base_repo, pending.key_id())); - if current.wants_update(entitlement.resource_set(), entitlement.not_after()) { + if current.wants_update(handle, &rcn, entitlement.resource_set(), entitlement.not_after()) { let repo = current.old_repo.as_ref().unwrap_or(base_repo); keys_for_requests.push((repo, current.key_id())); } } KeyState::RollNew(new, current) => { - if new.wants_update(entitlement.resource_set(), entitlement.not_after()) { + if new.wants_update(handle, &rcn, entitlement.resource_set(), entitlement.not_after()) { let repo = new.old_repo.as_ref().unwrap_or(base_repo); keys_for_requests.push((repo, new.key_id())); } - if current.wants_update(entitlement.resource_set(), entitlement.not_after()) { + if current.wants_update(handle, &rcn, entitlement.resource_set(), entitlement.not_after()) { let repo = current.old_repo.as_ref().unwrap_or(base_repo); keys_for_requests.push((repo, current.key_id())); } } KeyState::RollOld(current, old) => { - if current.wants_update(entitlement.resource_set(), entitlement.not_after()) { + if current.wants_update(handle, &rcn, entitlement.resource_set(), entitlement.not_after()) { let repo = current.old_repo.as_ref().unwrap_or(base_repo); keys_for_requests.push((repo, current.key_id())); } - if old.wants_update(entitlement.resource_set(), entitlement.not_after()) { + if old.wants_update(handle, &rcn, entitlement.resource_set(), entitlement.not_after()) { let repo = old.old_repo.as_ref().unwrap_or(base_repo); keys_for_requests.push((repo, current.key_id())); } diff --git a/src/daemon/ca/rc.rs b/src/daemon/ca/rc.rs index 2eac5226..225d0c9b 100644 --- a/src/daemon/ca/rc.rs +++ b/src/daemon/ca/rc.rs @@ -5,26 +5,14 @@ use rpki::cert::Cert; use rpki::crypto::KeyIdentifier; use rpki::x509::{Time, Validity}; -use crate::{ - commons::{ - api::{ - EntitlementClass, HexEncodedHash, IssuanceRequest, IssuedCert, ParentHandle, RcvdCert, ReplacedObject, - RepoInfo, RequestResourceLimit, ResourceClassInfo, ResourceClassName, ResourceSet, Revocation, - RevocationRequest, - }, - crypto::{CsrInfo, KrillSigner, SignSupport}, - error::Error, - KrillResult, - }, - daemon::{ +use crate::{commons::{KrillResult, api::{EntitlementClass, Handle, HexEncodedHash, IssuanceRequest, IssuedCert, ParentHandle, RcvdCert, ReplacedObject, RepoInfo, RequestResourceLimit, ResourceClassInfo, ResourceClassName, ResourceSet, Revocation, RevocationRequest}, crypto::{CsrInfo, KrillSigner, SignSupport}, error::Error}, daemon::{ ca::events::{ChildCertificateUpdates, RoaUpdates}, ca::{ self, ta_handle, CaEvtDet, CertifiedKey, ChildCertificates, CurrentKey, KeyState, NewKey, OldKey, PendingKey, Roas, Routes, }, config::{Config, IssuanceTimingConfig}, - }, -}; + }}; //------------ ResourceClass ----------------------------------------------- @@ -176,6 +164,7 @@ impl ResourceClass { /// Returns event details for receiving the certificate. pub fn update_received_cert( &self, + handle: &Handle, rcvd_cert: RcvdCert, routes: &Routes, config: &Config, @@ -190,6 +179,14 @@ impl ResourceClass { if rcvd_cert_ki != pending.key_id() { Err(Error::KeyUseNoMatch(rcvd_cert_ki)) } else { + info!( + "Received certificate for CA '{}' under RC '{}', with resources: '{}' valid until: '{}'", + handle, + self.name, + rcvd_cert.resources(), + rcvd_cert.validity().not_after().to_rfc3339() + ); + let current_key = CertifiedKey::create(rcvd_cert); Ok(vec![CaEvtDet::KeyPendingToActive { resource_class_name: self.name.clone(), @@ -197,7 +194,7 @@ impl ResourceClass { }]) } } - KeyState::Active(current) => self.update_rcvd_cert_current(current, rcvd_cert, routes, config, signer), + KeyState::Active(current) => self.update_rcvd_cert_current(handle, current, rcvd_cert, routes, config, signer), KeyState::RollPending(pending, current) => { if rcvd_cert_ki == pending.key_id() { let new_key = CertifiedKey::create(rcvd_cert); @@ -206,7 +203,7 @@ impl ResourceClass { new_key, }]) } else { - self.update_rcvd_cert_current(current, rcvd_cert, routes, config, signer) + self.update_rcvd_cert_current(handle, current, rcvd_cert, routes, config, signer) } } KeyState::RollNew(new, current) => { @@ -217,18 +214,19 @@ impl ResourceClass { rcvd_cert, }]) } else { - self.update_rcvd_cert_current(current, rcvd_cert, routes, config, signer) + self.update_rcvd_cert_current(handle, current, rcvd_cert, routes, config, signer) } } KeyState::RollOld(current, _old) => { // We will never request a new certificate for an old key - self.update_rcvd_cert_current(current, rcvd_cert, routes, config, signer) + self.update_rcvd_cert_current(handle, current, rcvd_cert, routes, config, signer) } } } fn update_rcvd_cert_current( &self, + handle: &Handle, current_key: &CurrentKey, rcvd_cert: RcvdCert, routes: &Routes, @@ -248,8 +246,18 @@ impl ResourceClass { rcvd_cert: rcvd_cert.clone(), }]; - if rcvd_resources != current_key.incoming_cert().resources() { - debug!("Received a new certificate for resource class: {}, with resources: {}, will now re-issue certs and ROAs if needed.", self.name, rcvd_resources); + let rcvd_resources_diff = rcvd_resources.difference(current_key.incoming_cert().resources()); + + if !rcvd_resources_diff.is_empty() { + + info!( + "Received new certificate under CA '{}' under RC '{}' with changed resources: '{}', valid until: {}", + handle, + self.name, + rcvd_resources_diff, + rcvd_cert.validity().not_after().to_rfc3339() + ); + // Check whether child certificates should be shrunk // // NOTE: We need to pro-actively shrink child certificates to avoid invalidating them. @@ -291,6 +299,13 @@ impl ResourceClass { updates, }); } + } else { + info!( + "Received new certificate for CA '{}' under RC '{}', valid until: {}", + handle, + self.name, + rcvd_cert.validity().not_after().to_rfc3339() + ) } Ok(res) @@ -304,12 +319,13 @@ impl ResourceClass { /// ARIN - Krill is sometimes told to just drop all resources. pub fn make_entitlement_events( &self, + handle: &Handle, entitlement: &EntitlementClass, base_repo: &RepoInfo, signer: &KrillSigner, ) -> KrillResult> { self.key_state - .make_entitlement_events(self.name.clone(), entitlement, base_repo, &self.name_space, signer) + .make_entitlement_events(handle, self.name.clone(), entitlement, base_repo, &self.name_space, signer) } /// Request new certificates for all keys when the base repo changes.