From ee7a05152e054e9211362b169ac9c105081baec7 Mon Sep 17 00:00:00 2001 From: Tamipes Date: Thu, 28 May 2026 18:00:29 +0200 Subject: [PATCH] feat: cleaner logging - less clutter with unusable `span` info (on my personal preference) - less errors logged when being scanned (ex.: after status response don't log errors with ping packets, scanners usually close the connection) - implemented more detailed OpaqueError fields - `tracing::Level` - error `kind` --- src/kube_cache.rs | 14 ++++---- src/main.rs | 82 +++++++++++++++++++++++++++++++-------------- src/opaque_error.rs | 33 ++++++++++++++++-- src/packets/mod.rs | 8 +++-- 4 files changed, 102 insertions(+), 35 deletions(-) diff --git a/src/kube_cache.rs b/src/kube_cache.rs index ae54ce8..490db59 100644 --- a/src/kube_cache.rs +++ b/src/kube_cache.rs @@ -99,17 +99,19 @@ impl MinecraftAPI for McApi { let dep_name = match self.cache.query_dep_addr(&addr, &port).await { Some(x) => x, None => { - return Err(OpaqueError::create(&format!( - "Failed to find deployment name by addr" - ))) + return Err(OpaqueError::create_with_kind( + "Failed to find deployment name by addr", + "DepNameLookupFailed", + )) } }; let srv_name = match self.cache.query_srv_addr(&addr, &port).await { Some(x) => x, None => { - return Err(OpaqueError::create(&format!( - "Failed to find service name by addr" - ))) + return Err(OpaqueError::create_with_kind( + "Failed to find service name by addr", + "SrvNameLookupFailed", + )) } }; diff --git a/src/main.rs b/src/main.rs index 798ea01..fe32e77 100644 --- a/src/main.rs +++ b/src/main.rs @@ -58,12 +58,35 @@ async fn main() { "Client connected" ); if let Err(e) = process_connection(socket, addr, api, config).await { - tracing::error!( - // addr = format!("{}:{}", addr.ip().to_string(), addr.port().to_string()), - trace = format!("{}", e.get_span_trace()), - err = format!("{}", e.context), - "Client disconnected" - ); + match e.level { + tracing::Level::ERROR => tracing::error!( + // addr = format!("{}:{}", addr.ip().to_string(), addr.port().to_string()), + trace = format!("{}", e.get_span_trace()), + err = format!("{}", e.context), + "Client disconnected" + ), + tracing::Level::WARN => tracing::warn!( + // addr = format!("{}:{}", addr.ip().to_string(), addr.port().to_string()), + trace = format!("{}", e.get_span_trace()), + err = format!("{}", e.context), + "Client disconnected" + ), + tracing::Level::INFO => tracing::info!( + // addr = format!("{}:{}", addr.ip().to_string(), addr.port().to_string()), + trace = format!("{}", e.get_span_trace()), + err = format!("{}", e.context), + "Client disconnected" + ), + _ => { + tracing::error!( + // addr = format!("{}:{}", addr.ip().to_string(), addr.port().to_string()), + trace = format!("{}", e.get_span_trace()), + err = format!("{}", e.context), + actual_level = ?e.level, + "Client disconnected (bad level)" + ) + } + } } else { tracing::debug!( addr = format!("{}:{}", addr.ip().to_string(), addr.port().to_string()), @@ -74,7 +97,6 @@ async fn main() { } } -#[tracing::instrument(level = "info", skip(api, client_stream, config))] async fn process_connection( mut client_stream: TcpStream, addr: SocketAddr, @@ -159,7 +181,6 @@ async fn handle_status( }; let server_addr = handshake.get_server_address(); - let commit_hash: &'static str = env!("COMMIT_HASH"); let mut status_struct = StatusStructNew::create(); status_struct.version.protocol = handshake.protocol_version.get_int(); @@ -172,7 +193,7 @@ async fn handle_status( { Ok(x) => x, Err(e) => { - let span = tracing::span!(tracing::Level::WARN, "not_found", err = e.context); + let span = tracing::span!(tracing::Level::INFO, "unavailable", err = e.get_kind()); status_struct.players.max = 0; status_struct.players.online = 0; status_struct.description.text = format!( @@ -184,22 +205,25 @@ async fn handle_status( .await?; // Recieve the ping packet, so the client does not send it again - let _ping = Packet::parse(client_stream).instrument(span.clone()).await; + let _ping = Packet::parse(client_stream) + .instrument(span.clone()) + .await + .map_err(|err| { + tracing::debug!( + err = OpaqueError::from(err).context, + "failed to parse ping packet" + ) + }); // Send a bad ping packet back, so the client shows *searching* icon let _pong = Packet::new(9, vec![0; 8]) .ok_or("failed to create empty pong packet?")? .send_packet(client_stream) .instrument(span.clone()) .await - .map_err(|_| "failed to send pong packet")?; + .map_err(|_| tracing::debug!("failed to send pong packet")); let _guard = span.enter(); - match _ping { - Ok(_) => tracing::info!("sent status with error"), - Err(err) => { - tracing::error!(err = OpaqueError::from(err).context) - } - }; + tracing::info!(status = "unavailable", "status request"); return Ok(()); } }; @@ -209,7 +233,6 @@ async fn handle_status( .get_motd() .unwrap_or("A minecraft server (proxy motd)".to_string()); - tracing::trace!(motd); match status { ServerDeploymentStatus::Connectable(mut server_stream) => { return server @@ -245,7 +268,8 @@ async fn handle_login( &handshake.get_server_address(), &handshake.server_port.get_value().to_string(), ) - .await?; + .await + .map_err(|e| e.set_level(tracing::Level::WARN))?; let status = server.query_status().await?; tracing::debug!(msg = "server status", status = ?status); @@ -281,12 +305,20 @@ async fn handle_login( .execute(client_stream, &mut server_stream) .await; - tracing::debug!("data exchanged: tx: {} rx: {}", traffic.tx, traffic.rx); - if let Some(e) = traffic.error { - return Err(OpaqueError::create(&format!( - "failed to splice; err = {}", - e - ))); + match traffic.error { + Some(e) => { + tracing::info!( + tx = traffic.tx, + rx = traffic.rx, + err = ?e, + "connection splicing ended with error", + ) + } + None => tracing::info!( + tx = traffic.tx, + rx = traffic.rx, + "connection splicing ended", + ), } } ServerDeploymentStatus::PodOk | ServerDeploymentStatus::Starting => { diff --git a/src/opaque_error.rs b/src/opaque_error.rs index ad70182..626936f 100644 --- a/src/opaque_error.rs +++ b/src/opaque_error.rs @@ -1,10 +1,13 @@ use std::{error::Error, fmt}; +use tracing::Level; use tracing_error::SpanTrace; #[derive(Debug)] pub struct OpaqueError { span_trace: SpanTrace, pub context: String, + pub level: Level, + kind: Option, } impl fmt::Display for OpaqueError { @@ -31,10 +34,20 @@ impl fmt::Display for OpaqueError { } impl Error for OpaqueError {} impl OpaqueError { - pub fn create(str: &str) -> OpaqueError { + pub fn create(context: &str) -> OpaqueError { Self { span_trace: SpanTrace::capture(), - context: str.to_string(), + context: context.to_string(), + level: Level::ERROR, + kind: None, + } + } + pub fn create_with_kind(context: &str, kind: &str) -> OpaqueError { + Self { + span_trace: SpanTrace::capture(), + context: context.to_string(), + level: Level::ERROR, + kind: Some(kind.to_string()), } } pub fn get_span_trace(&self) -> String { @@ -62,6 +75,16 @@ impl OpaqueError { Err(_) => str, } } + pub fn set_level(mut self, lvl: Level) -> Self { + self.level = lvl; + self + } + pub fn get_kind(&self) -> &str { + match self.kind.as_ref() { + Some(x) => &x, + None => &self.context, + } + } } impl From for OpaqueError { @@ -69,6 +92,8 @@ impl From for OpaqueError { Self { span_trace: SpanTrace::capture(), context: value, + level: Level::ERROR, + kind: None, } } } @@ -78,6 +103,8 @@ impl From<&str> for OpaqueError { Self { span_trace: SpanTrace::capture(), context: value.to_string(), + level: Level::ERROR, + kind: None, } } } @@ -87,6 +114,8 @@ impl From for OpaqueError { Self { span_trace: value.context, context: format!("{:?}", value.inner), + level: Level::ERROR, + kind: None, } } } diff --git a/src/packets/mod.rs b/src/packets/mod.rs index 28c6a04..9a20335 100644 --- a/src/packets/mod.rs +++ b/src/packets/mod.rs @@ -61,7 +61,7 @@ impl Packet { pub async fn parse(stream: &mut TcpStream) -> Result { let length = VarInt::parse(stream) .await - .ok_or(ParseError::IDParseError)?; + .ok_or(ParseError::LengthParseError)?; tracing::trace!(length = length.get_int()); let id = match VarInt::parse(stream).await { @@ -150,6 +150,7 @@ impl From for ParseErrorTrace { } pub enum ParseError { + LengthParseError, IDParseError, WeirdID, LengthIsTooBig(i32), @@ -162,7 +163,10 @@ pub enum ParseError { impl fmt::Debug for ParseError { fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { match self { - Self::IDParseError => write!(f, "IDParseError: could not parse packet id"), + Self::LengthParseError => { + write!(f, "LengthParseError: could not parse packet length VarInt") + } + Self::IDParseError => write!(f, "IDParseError: could not parse packet id VarInt"), Self::WeirdID => write!(f, "WeirdID: weird packet id encountered: 122"), Self::LengthIsTooBig(x) => { write!(f, "LengthIsTooBig: packet length is too big; len={x}")