From 11b01490b441794d78a0383879d3b48cff7fdf75 Mon Sep 17 00:00:00 2001 From: David Emett Date: Fri, 1 Sep 2023 14:49:04 +0100 Subject: [PATCH] Adjust log levels --- src/core/fragment.rs | 8 ++++---- src/core/mod.rs | 28 ++++++++++++++-------------- src/core/surb_keystore.rs | 4 ++-- src/reply_manager.rs | 12 ++++++------ 4 files changed, 26 insertions(+), 26 deletions(-) diff --git a/src/core/fragment.rs b/src/core/fragment.rs index 63f325f..dd056bc 100644 --- a/src/core/fragment.rs +++ b/src/core/fragment.rs @@ -26,7 +26,7 @@ use super::{ }; use arrayref::{array_mut_ref, array_refs, mut_array_refs}; use hashlink::{linked_hash_map::Entry, LinkedHashMap}; -use log::{error, log, warn, Level}; +use log::{debug, log, Level}; use std::cmp::{max, min}; /// Size in bytes of a [`MessageId`]. @@ -255,7 +255,7 @@ impl FragmentAssembler { /// each fragment insertion. fn maybe_evict(&mut self, log_target: &str) { if self.need_eviction() { - warn!(target: log_target, "Too many incomplete messages; evicting LRU"); + debug!(target: log_target, "Too many incomplete messages; evicting LRU"); let incomplete_message = self .incomplete_messages .pop_front() @@ -276,7 +276,7 @@ impl FragmentAssembler { /// returned. pub fn insert(&mut self, fragment: &Fragment, log_target: &str) -> Option { if let Err(err) = check_fragment(fragment) { - error!(target: log_target, "Received bad fragment: {err}"); + debug!(target: log_target, "Received bad fragment: {err}"); return None } let num_fragments = num_fragments(fragment); @@ -292,7 +292,7 @@ impl FragmentAssembler { if let Err(err) = incomplete_message.insert(fragment) { let level = match err { IncompleteMessageInsertErr::AlreadyHave => Level::Trace, - _ => Level::Error, + _ => Level::Debug, }; log!(target: log_target, level, "Fragment insert failed: {err}"); return None diff --git a/src/core/mod.rs b/src/core/mod.rs index b9dc7ce..5ea1456 100644 --- a/src/core/mod.rs +++ b/src/core/mod.rs @@ -69,7 +69,7 @@ use arrayref::{array_mut_ref, array_ref}; use arrayvec::ArrayVec; use bitflags::bitflags; use either::Either; -use log::{debug, error, info, warn}; +use log::{debug, info, trace}; use multiaddr::Multiaddr; use rand::Rng; use std::{ @@ -360,7 +360,7 @@ impl Mixnet { }, _ => if !self.sessions.is_empty() || !next_session.is_empty() { - warn!( + debug!( target: self.config.log_target, "Unexpected session index {}; previous session index was {}", session_status.current_index, @@ -426,7 +426,7 @@ impl Mixnet { }; let max_mixnodes = (MAX_MIXNODE_INDEX + 1) as usize; if mixnodes.len() > max_mixnodes { - warn!( + debug!( target: self.config.log_target, "Session {session_index}: Too many mixnodes ({}, max {max_mixnodes}); ignoring excess", mixnodes.len() @@ -518,14 +518,14 @@ impl Mixnet { // This will usually get hit quite a bit on session changeover after we discard the // keys for the previous session. It may get hit just before a new session if other // nodes switch sooner. - debug!( + trace!( target: self.config.log_target, "Failed to peel packet; either bad MAC or unknown secret" ); return None }, Some(Err(err)) => { - error!(target: self.config.log_target, "Failed to peel packet: {err}"); + debug!(target: self.config.log_target, "Failed to peel packet: {err}"); return None }, Some(Ok(x)) => x, @@ -534,13 +534,13 @@ impl Mixnet { match action { Action::ForwardTo { target, delay } => { if !session.topology.is_mixnode() { - error!(target: self.config.log_target, + debug!(target: self.config.log_target, "Received packet to forward despite not being a mixnode in the session; discarding"); return None } if !self.forward_packet_queue.has_space() { - warn!(target: self.config.log_target, "Dropped forward packet; forward queue full"); + debug!(target: self.config.log_target, "Dropped forward packet; forward queue full"); return None } @@ -557,7 +557,7 @@ impl Mixnet { self.events |= Events::NEXT_FORWARD_PACKET_DEADLINE_CHANGED; } }, - Err(err) => error!( + Err(err) => debug!( target: self.config.log_target, "Failed to map target {target:?} to peer ID: {err}" ), @@ -569,7 +569,7 @@ impl Mixnet { let payload_data = array_ref![out, 0, PAYLOAD_DATA_SIZE]; if !session.topology.is_mixnode() { - error!(target: self.config.log_target, + debug!(target: self.config.log_target, "Received request packet despite not being a mixnode in the session; discarding"); return None } @@ -602,7 +602,7 @@ impl Mixnet { // ID is stored alongside the keys; it is simply returned with any completed // message to provide context. let Some(entry) = self.surb_keystore.entry(&surb_id) else { - warn!(target: self.config.log_target, + debug!(target: self.config.log_target, "Received reply with unrecognised SURB ID {surb_id:x?}; discarding"); return None }; @@ -610,7 +610,7 @@ impl Mixnet { let res = decrypt_reply_payload(payload, entry.keys()); entry.remove(); if let Err(err) = res { - error!(target: self.config.log_target, "Failed to decrypt reply payload: {err}"); + debug!(target: self.config.log_target, "Failed to decrypt reply payload: {err}"); return None } let payload_data = array_ref![payload, 0, PAYLOAD_DATA_SIZE]; @@ -619,7 +619,7 @@ impl Mixnet { self.fragment_assembler.insert(payload_data, self.config.log_target).map( |message| { if !message.surbs.is_empty() { - error!(target: self.config.log_target, + debug!(target: self.config.log_target, "Reply message included SURBs; discarding them"); } Message::Reply(ReplyMessage { request_id, data: message.data }) @@ -747,9 +747,9 @@ impl Mixnet { matches!(err, TopologyErr::NoConnectedGatewayMixnodes) { // Possibly still connecting to mixnodes - debug!(target: self.config.log_target, "Failed to generate cover packet: {err}"); + trace!(target: self.config.log_target, "Failed to generate cover packet: {err}"); } else { - warn!(target: self.config.log_target, "Failed to generate cover packet: {err}"); + debug!(target: self.config.log_target, "Failed to generate cover packet: {err}"); } None }, diff --git a/src/core/surb_keystore.rs b/src/core/surb_keystore.rs index 6da4da7..ad2f1e3 100644 --- a/src/core/surb_keystore.rs +++ b/src/core/surb_keystore.rs @@ -25,7 +25,7 @@ use super::{ sphinx::{SurbId, SurbPayloadEncryptionKeys, SURB_ID_SIZE}, }; use hashlink::{linked_hash_map, LinkedHashMap}; -use log::warn; +use log::debug; use rand::{CryptoRng, Rng}; struct Value { @@ -73,7 +73,7 @@ impl SurbKeystore { // Discard the oldest SURB if we're already at capacity debug_assert!(self.surbs.len() <= self.capacity); if self.surbs.len() == self.capacity { - warn!(target: log_target, "Too many entries in SURB keystore; evicting oldest"); + debug!(target: log_target, "Too many entries in SURB keystore; evicting oldest"); self.surbs.pop_front(); } diff --git a/src/reply_manager.rs b/src/reply_manager.rs index df2415c..5342368 100644 --- a/src/reply_manager.rs +++ b/src/reply_manager.rs @@ -24,7 +24,7 @@ use super::core::{MessageId, Mixnet, RequestMessage, SessionIndex, Surb, MESSAGE_ID_SIZE}; use hashlink::{linked_hash_map::Entry, LinkedHashMap}; -use log::{debug, warn}; +use log::{debug, trace}; use rand::RngCore; use std::time::{Duration, Instant}; @@ -93,7 +93,7 @@ impl ReplyContext { &reply.message_id, reply.data.as_slice().into(), ) { - warn!(target: config.log_target, + debug!(target: config.log_target, "Failed to post reply to request with message ID {:x?}: {err}", self.message_id); break @@ -154,13 +154,13 @@ impl ReplyManager { match self.states.entry(message.id) { Entry::Occupied(mut entry) => { match entry.get_mut() { - ReplyState::Pending => debug!(target: self.config.log_target, + ReplyState::Pending => trace!(target: self.config.log_target, "Ignoring repeat request with message ID {:x?}; currently handling", message.id), ReplyState::Complete { reply, last_post } => { let now = Instant::now(); let since_last = now.saturating_duration_since(*last_post); if since_last < self.config.cooldown { - debug!(target: self.config.log_target, + trace!(target: self.config.log_target, "Ignoring repeat request with message ID {:x?}; posted a reply {:.1}s ago", message.id, since_last.as_secs_f32()); } else { @@ -188,7 +188,7 @@ impl ReplyManager { ReplyState::Pending => { entry.remove(); }, - ReplyState::Complete { .. } => warn!( + ReplyState::Complete { .. } => debug!( target: self.config.log_target, "Ignoring abandon of request with message ID {:x?}; already completed", reply_context.message_id @@ -208,7 +208,7 @@ impl ReplyManager { Entry::Occupied(entry) => match entry.into_mut() { state @ ReplyState::Pending => state, ReplyState::Complete { .. } => { - warn!(target: self.config.log_target, + debug!(target: self.config.log_target, "Request with message ID {:x?} completed twice", reply_context.message_id); return