From cf7d4fd28d77b4a3334bbdd7f5b170da4cba4f28 Mon Sep 17 00:00:00 2001 From: Tim Bruijnzeels Date: Mon, 30 Sep 2019 14:44:27 +0200 Subject: [PATCH] Sanitise debug and trace logging. Closes: #89 --- src/commons/api/admin.rs | 15 +++++++++++++++ src/commons/api/rrdp.rs | 4 +++- src/commons/eventsourcing/agg_store.rs | 7 ++++--- src/commons/eventsourcing/store.rs | 8 ++++---- src/commons/remote/proxy.rs | 2 +- src/commons/util/file.rs | 2 +- src/daemon/auth.rs | 2 +- src/daemon/ca/certauth.rs | 5 +++++ src/daemon/ca/server.rs | 26 ++++++++++++++++++-------- src/daemon/config.rs | 2 +- src/daemon/endpoints.rs | 4 ++-- src/daemon/krillserver.rs | 7 ++++--- src/daemon/mq.rs | 2 +- src/daemon/scheduler.rs | 9 ++++----- 14 files changed, 64 insertions(+), 31 deletions(-) diff --git a/src/commons/api/admin.rs b/src/commons/api/admin.rs index 7125bc7f..a09f4662 100644 --- a/src/commons/api/admin.rs +++ b/src/commons/api/admin.rs @@ -553,6 +553,21 @@ impl UpdateChildRequest { } } +impl fmt::Display for UpdateChildRequest { + fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { + if self.id_cert.is_some() { + write!(f, "new id cert ")?; + } + if let Some(resources) = &self.resources { + write!(f, "new resources: {} ", resources)?; + } + if self.force { + write!(f, "")?; + } + Ok(()) + } +} + //------------ Tests --------------------------------------------------------- #[cfg(test)] diff --git a/src/commons/api/rrdp.rs b/src/commons/api/rrdp.rs index 15709ba7..2bf0cde0 100644 --- a/src/commons/api/rrdp.rs +++ b/src/commons/api/rrdp.rs @@ -222,7 +222,7 @@ impl Notification { } pub fn write_xml(&self, path: &PathBuf) -> Result<(), io::Error> { - debug!("Writing notification file: {}", path.to_string_lossy()); + trace!("Writing notification file: {}", path.to_string_lossy()); let mut file = file::create_file_with_path(&path)?; XmlWriter::encode_to_file(&mut file, |w| { @@ -490,6 +490,7 @@ impl Snapshot { } pub fn write_xml(&self, path: &PathBuf) -> Result { + trace!("Writing snapshot file: {}", path.to_string_lossy()); let vec = XmlWriter::encode_vec(|w| { let a = [ ("xmlns", NS), @@ -626,6 +627,7 @@ impl Delta { } pub fn write_xml(&self, path: &PathBuf) -> Result { + trace!("Writing delta file: {}", path.to_string_lossy()); let vec = XmlWriter::encode_vec(|w| { let a = [ ("xmlns", NS), diff --git a/src/commons/eventsourcing/agg_store.rs b/src/commons/eventsourcing/agg_store.rs index 36b14a5c..9935ee42 100644 --- a/src/commons/eventsourcing/agg_store.rs +++ b/src/commons/eventsourcing/agg_store.rs @@ -113,7 +113,7 @@ impl DiskAggregateStore { } fn get_latest_no_lock(&self, handle: &Handle) -> StoreResult> { - debug!("Trying to load aggregate id: {}", handle); + trace!("Trying to load aggregate id: {}", handle); match self.cache_get(handle) { None => match self.store.get_aggregate(handle)? { None => { @@ -123,7 +123,7 @@ impl DiskAggregateStore { Some(agg) => { let arc: Arc = Arc::new(agg); self.cache_update(handle, arc.clone()); - debug!("Loaded aggregate id: {} from disk", handle); + trace!("Loaded aggregate id: {} from disk", handle); Ok(arc) } }, @@ -132,7 +132,7 @@ impl DiskAggregateStore { let agg = Arc::make_mut(&mut arc); self.store.update_aggregate(handle, agg)?; } - debug!("Loaded aggregate id: {} from memory", handle); + trace!("Loaded aggregate id: {} from memory", handle); Ok(arc) } } @@ -169,6 +169,7 @@ impl AggregateStore for DiskAggregateStore { { // Verify whether there is a concurrency issue if prev.version() != latest.version() { + // TODO: Print history (last X events) and conflict to log. return Err(AggregateStoreError::ConcurrentModification(handle.clone())); } diff --git a/src/commons/eventsourcing/store.rs b/src/commons/eventsourcing/store.rs index e7312575..3a6565db 100644 --- a/src/commons/eventsourcing/store.rs +++ b/src/commons/eventsourcing/store.rs @@ -173,12 +173,12 @@ impl KeyStore for DiskKeyStore { Err(KeyStoreError::JsonError(e)) } Ok(v) => { - debug!("Deserialized json at: {}", path_str); + trace!("Deserialized json at: {}", path_str); Ok(Some(v)) } } } else { - debug!("Could not find file at: {}", path_str); + trace!("Could not find file at: {}", path_str); Ok(None) } } @@ -196,12 +196,12 @@ impl KeyStore for DiskKeyStore { Err(KeyStoreError::JsonError(e)) } Ok(v) => { - debug!("Deserialized event at: {}", path_str); + trace!("Deserialized event at: {}", path_str); Ok(Some(v)) } } } else { - debug!("No more events at: {}", path_str); + trace!("No more events at: {}", path_str); Ok(None) } } diff --git a/src/commons/remote/proxy.rs b/src/commons/remote/proxy.rs index ac121d93..0bbb3ca3 100644 --- a/src/commons/remote/proxy.rs +++ b/src/commons/remote/proxy.rs @@ -194,7 +194,7 @@ impl ProxyServer { /// Retrieves the QueryMessage contained in the SignedMessage and /// converts into the (json) equivalent request for the API. fn convert_to_json_request(&self, msg: &SignedMessage) -> Result { - debug!("Convert contained message to Json equivalent"); + trace!("Convert contained message to Json equivalent"); let msg = rfc8181::Message::from_signed_message(&msg)?; let msg = msg.into_query()?; Ok(msg.into_publish_request()) diff --git a/src/commons/util/file.rs b/src/commons/util/file.rs index d306f210..d9303f63 100644 --- a/src/commons/util/file.rs +++ b/src/commons/util/file.rs @@ -123,7 +123,7 @@ pub fn clean_file_and_path(path: &PathBuf) -> Result<(), io::Error> { while parent_opt.is_some() { let parent = parent_opt.unwrap(); if parent.read_dir()?.count() == 0 { - debug!("Will delete {}", parent.to_string_lossy().to_string()); + trace!("Will delete {}", parent.to_string_lossy().to_string()); fs::remove_dir(parent)?; } diff --git a/src/daemon/auth.rs b/src/daemon/auth.rs index 5b38fffe..82f08189 100644 --- a/src/daemon/auth.rs +++ b/src/daemon/auth.rs @@ -112,7 +112,7 @@ impl FromRequest for Auth { fn from_request(req: &HttpRequest, payload: &mut Payload) -> Self::Future { if let Some(identity) = Identity::from_request(req, payload)?.identity() { - debug!("Found user: {}", &identity); + trace!("Found user: {}", &identity); Ok(Auth::User(identity)) } else if let Some(header) = req.headers().get("Authorization") { let token = diff --git a/src/daemon/ca/certauth.rs b/src/daemon/ca/certauth.rs index 6a3cb012..bd38fbbf 100644 --- a/src/daemon/ca/certauth.rs +++ b/src/daemon/ca/certauth.rs @@ -827,10 +827,12 @@ impl CertAuth { rc: &ResourceClass, signer: &S, ) -> Result> { + let parent_class_name = entitlement.class_name().clone(); let req_details_list = rc.make_request_events(entitlement, &self.base_repo, signer)?; let mut res = vec![]; for details in req_details_list.into_iter() { + debug!("Updating Entitlements for CA: {}, Request for RC: {}", &self.handle, &parent_class_name); res.push(StoredEvent::new(&self.handle, *version, details)); *version += 1; } @@ -908,6 +910,8 @@ impl CertAuth { let delta = rc.withdraw(&self.base_repo); let revocations = rc.revoke(signer.deref())?; + debug!("Updating Entitlements for CA: {}, Removing RC: {}", &self.handle, &name); + res.push(EvtDet::resource_class_removed( &self.handle, version, @@ -960,6 +964,7 @@ impl CertAuth { ); let rc_add_version = version; version += 1; + debug!("Updating Entitlements for CA: {}, adding RC: {}", &self.handle, &rcn); let signer = signer.read().unwrap(); let mut request_events = diff --git a/src/daemon/ca/server.rs b/src/daemon/ca/server.rs index 425138ee..c9fc111b 100644 --- a/src/daemon/ca/server.rs +++ b/src/daemon/ca/server.rs @@ -165,7 +165,7 @@ impl CaServer { parent: &ParentHandle, child: &ChildHandle, ) -> ServerResult, S> { - debug!("Finding details for CA: {} under parent: {}", child, parent); + trace!("Finding details for CA: {} under parent: {}", child, parent); let ca = self.get_ca(parent)?; let child_opt = match ca.get_child(child) { @@ -184,8 +184,8 @@ impl CaServer { req: UpdateChildRequest, ) -> ServerResult<(), S> { debug!( - "Updating details for CA: {} under parent: {}", - child, parent + "Updating details for CA: {} under parent: {} to: {}", + child, parent, req ); let mut ca = self.get_ca(parent)?; @@ -216,20 +216,27 @@ impl CaServer { /// # CA support /// impl CaServer { + /// Gets a CA by the given handle, returns an `Err(ServerError::UnknownCA)` if it + /// does not exist. pub fn get_ca(&self, handle: &Handle) -> ServerResult>, S> { self.ca_store .get_latest(handle) .map_err(|_| ServerError::UnknownCa(handle.to_string())) } + /// Checks whether a CA by the given handle exists. + pub fn has_ca(&self, handle: &Handle) -> bool { + self.ca_store.has(handle) + } + /// Verifies an RFC6492 message and returns the child handle, token, /// and content of the request, so that the simple 'list' and 'issue' /// functions can be called. pub fn rfc6492(&self, ca_handle: &Handle, msg: SignedMessage) -> ServerResult { - debug!("RFC6492 Request: will check"); + trace!("RFC6492 Request: will check"); let ca = self.ca_store.get_latest(ca_handle)?; let content = ca.verify_rfc6492(msg)?; - debug!("RFC6492 Request: verified"); + trace!("RFC6492 Request: verified"); let (child, recipient, content) = content.unwrap(); @@ -258,7 +265,7 @@ impl CaServer { handle: &Handle, msg: rfc6492::Message, ) -> ServerResult { - debug!("RFC6492 Response wrapping for {}", handle); + trace!("RFC6492 Response wrapping for {}", handle); self.get_ca(handle)? .sign_rfc6492_response(msg, self.signer.read().unwrap().deref()) .map_err(ServerError::::CertAuth) @@ -763,7 +770,7 @@ impl CaServer { // send to the server let uri = parent_res.service_uri().to_string(); debug!( - "Sending to parent: {}\n{}", + "Sending RFC6492 message to parent: {}\n{}", &uri, base64::encode(&signed.as_bytes()) ); @@ -773,7 +780,10 @@ impl CaServer { // unpack and validate response let msg = match SignedMessage::decode(res.as_ref(), false).map_err(ServerError::custom) { - Ok(msg) => msg, + Ok(msg) => { + debug!("Received syntactically correct RFC6492 response."); + msg + }, Err(e) => { error!("Could not parse response: {}", base64::encode(res.as_ref())); return Err(e); diff --git a/src/daemon/config.rs b/src/daemon/config.rs index ecdf0fca..4559dd6e 100644 --- a/src/daemon/config.rs +++ b/src/daemon/config.rs @@ -167,7 +167,7 @@ impl Config { let data_dir = data_dir.clone(); let rsync_base = ConfigDefaults::rsync_base(); let service_uri = ConfigDefaults::service_uri(); - let log_level = LevelFilter::Info; + let log_level = LevelFilter::Debug; let log_type = LogType::Stderr; let mut log_file = data_dir.clone(); log_file.push("krill.log"); diff --git a/src/daemon/endpoints.rs b/src/daemon/endpoints.rs index 26e062d9..63c0d36f 100644 --- a/src/daemon/endpoints.rs +++ b/src/daemon/endpoints.rs @@ -187,7 +187,7 @@ pub fn handle_delta( ) -> HttpResponse { let handle = handle.into_inner(); let delta = delta.into_inner(); - debug!("Received delta request for {}", &handle); + trace!("Received delta request for {}", &handle); if_publication_allowed(&server, &handle, &auth, || { render_empty_res(server.read().handle_delta(delta, &handle)) }) @@ -197,7 +197,7 @@ pub fn handle_delta( #[allow(clippy::needless_pass_by_value)] pub fn handle_list(server: web::Data, auth: Auth, handle: Path) -> HttpResponse { let handle = handle.into_inner(); - debug!("Received list request for {}", &handle); + trace!("Received list request for {}", &handle); if_publication_allowed(&server, &handle, &auth, || { match server.read().handle_list(&handle) { Ok(list) => render_json(list), diff --git a/src/daemon/krillserver.rs b/src/daemon/krillserver.rs index 68a70b34..482846b6 100644 --- a/src/daemon/krillserver.rs +++ b/src/daemon/krillserver.rs @@ -99,7 +99,9 @@ impl KrillServer { if config.use_ta() { let ta_handle = ta_handle(); - if caserver.get_ca(&ta_handle).is_err() { + if !caserver.has_ca(&ta_handle) { + info!("Creating embedded Trust Anchor"); + let repo_info = pubserver.repo_info_for(&ta_handle)?; let ta_uri = config.ta_cert_uri(); @@ -125,7 +127,6 @@ impl KrillServer { // Force initial publication caserver.republish(&ta_handle)?; - info!("Created embedded Trust Anchor"); } } @@ -179,7 +180,7 @@ impl KrillServer { }; if allowed { - debug!("Access to publication api allowed") + trace!("Access to publication api allowed") } else { warn!( "Access to publication api disallowed for handle: {}, and auth: {}", diff --git a/src/daemon/mq.rs b/src/daemon/mq.rs index 9219f9f4..84ec286a 100644 --- a/src/daemon/mq.rs +++ b/src/daemon/mq.rs @@ -63,7 +63,7 @@ impl eventsourcing::EventListener> for EventQueueListener use crate::commons::eventsourcing::Event; let json = serde_json::to_string_pretty(&event).unwrap(); - debug!("Seen CertAuth event: {}", json); + trace!("Seen CertAuth event: {}", json); let handle = event.handle(); match event.details() { diff --git a/src/daemon/scheduler.rs b/src/daemon/scheduler.rs index fc45d441..218b955d 100644 --- a/src/daemon/scheduler.rs +++ b/src/daemon/scheduler.rs @@ -65,7 +65,7 @@ fn make_event_sh( .send_revoke_requests(&handle, &parent, revocations) .is_err() { - info!("Could not revoke key for removed resource class. This is not \ + debug!("Could not revoke key for removed resource class. This is not \ an issue, because typically the parent will revoke our keys pro-actively, \ just before removing the resource class entitlements."); } @@ -101,10 +101,9 @@ fn make_republish_sh(caserver: Arc>) -> ScheduleHandle { } fn publish(handle: &Handle, delta: PublishDelta, pubserver: &PubServer) { - debug!("Triggered publishing for CA: {}", handle); - match pubserver.publish(handle, delta) { - Ok(()) => debug!("Published for CA: {}", handle), - Err(e) => error!("Failed to publish for CA: {}, error: {}", handle, e), + trace!("Asking CA: {} if it wants to publish", handle); + if let Err(e) = pubserver.publish(handle, delta) { + error!("Failed to publish for CA: {}, error: {}", handle, e); } }