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`
This commit is contained in:
parent
efe080a9e7
commit
ee7a05152e
4 changed files with 102 additions and 35 deletions
|
|
@ -99,17 +99,19 @@ impl MinecraftAPI<Server> for McApi {
|
||||||
let dep_name = match self.cache.query_dep_addr(&addr, &port).await {
|
let dep_name = match self.cache.query_dep_addr(&addr, &port).await {
|
||||||
Some(x) => x,
|
Some(x) => x,
|
||||||
None => {
|
None => {
|
||||||
return Err(OpaqueError::create(&format!(
|
return Err(OpaqueError::create_with_kind(
|
||||||
"Failed to find deployment name by addr"
|
"Failed to find deployment name by addr",
|
||||||
)))
|
"DepNameLookupFailed",
|
||||||
|
))
|
||||||
}
|
}
|
||||||
};
|
};
|
||||||
let srv_name = match self.cache.query_srv_addr(&addr, &port).await {
|
let srv_name = match self.cache.query_srv_addr(&addr, &port).await {
|
||||||
Some(x) => x,
|
Some(x) => x,
|
||||||
None => {
|
None => {
|
||||||
return Err(OpaqueError::create(&format!(
|
return Err(OpaqueError::create_with_kind(
|
||||||
"Failed to find service name by addr"
|
"Failed to find service name by addr",
|
||||||
)))
|
"SrvNameLookupFailed",
|
||||||
|
))
|
||||||
}
|
}
|
||||||
};
|
};
|
||||||
|
|
||||||
|
|
|
||||||
82
src/main.rs
82
src/main.rs
|
|
@ -58,12 +58,35 @@ async fn main() {
|
||||||
"Client connected"
|
"Client connected"
|
||||||
);
|
);
|
||||||
if let Err(e) = process_connection(socket, addr, api, config).await {
|
if let Err(e) = process_connection(socket, addr, api, config).await {
|
||||||
tracing::error!(
|
match e.level {
|
||||||
// addr = format!("{}:{}", addr.ip().to_string(), addr.port().to_string()),
|
tracing::Level::ERROR => tracing::error!(
|
||||||
trace = format!("{}", e.get_span_trace()),
|
// addr = format!("{}:{}", addr.ip().to_string(), addr.port().to_string()),
|
||||||
err = format!("{}", e.context),
|
trace = format!("{}", e.get_span_trace()),
|
||||||
"Client disconnected"
|
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 {
|
} else {
|
||||||
tracing::debug!(
|
tracing::debug!(
|
||||||
addr = format!("{}:{}", addr.ip().to_string(), addr.port().to_string()),
|
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<T: MinecraftServerHandle>(
|
async fn process_connection<T: MinecraftServerHandle>(
|
||||||
mut client_stream: TcpStream,
|
mut client_stream: TcpStream,
|
||||||
addr: SocketAddr,
|
addr: SocketAddr,
|
||||||
|
|
@ -159,7 +181,6 @@ async fn handle_status<T: MinecraftServerHandle>(
|
||||||
};
|
};
|
||||||
|
|
||||||
let server_addr = handshake.get_server_address();
|
let server_addr = handshake.get_server_address();
|
||||||
let commit_hash: &'static str = env!("COMMIT_HASH");
|
|
||||||
let mut status_struct = StatusStructNew::create();
|
let mut status_struct = StatusStructNew::create();
|
||||||
status_struct.version.protocol = handshake.protocol_version.get_int();
|
status_struct.version.protocol = handshake.protocol_version.get_int();
|
||||||
|
|
||||||
|
|
@ -172,7 +193,7 @@ async fn handle_status<T: MinecraftServerHandle>(
|
||||||
{
|
{
|
||||||
Ok(x) => x,
|
Ok(x) => x,
|
||||||
Err(e) => {
|
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.max = 0;
|
||||||
status_struct.players.online = 0;
|
status_struct.players.online = 0;
|
||||||
status_struct.description.text = format!(
|
status_struct.description.text = format!(
|
||||||
|
|
@ -184,22 +205,25 @@ async fn handle_status<T: MinecraftServerHandle>(
|
||||||
.await?;
|
.await?;
|
||||||
|
|
||||||
// Recieve the ping packet, so the client does not send it again
|
// 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
|
// Send a bad ping packet back, so the client shows *searching* icon
|
||||||
let _pong = Packet::new(9, vec![0; 8])
|
let _pong = Packet::new(9, vec![0; 8])
|
||||||
.ok_or("failed to create empty pong packet?")?
|
.ok_or("failed to create empty pong packet?")?
|
||||||
.send_packet(client_stream)
|
.send_packet(client_stream)
|
||||||
.instrument(span.clone())
|
.instrument(span.clone())
|
||||||
.await
|
.await
|
||||||
.map_err(|_| "failed to send pong packet")?;
|
.map_err(|_| tracing::debug!("failed to send pong packet"));
|
||||||
let _guard = span.enter();
|
let _guard = span.enter();
|
||||||
|
|
||||||
match _ping {
|
tracing::info!(status = "unavailable", "status request");
|
||||||
Ok(_) => tracing::info!("sent status with error"),
|
|
||||||
Err(err) => {
|
|
||||||
tracing::error!(err = OpaqueError::from(err).context)
|
|
||||||
}
|
|
||||||
};
|
|
||||||
return Ok(());
|
return Ok(());
|
||||||
}
|
}
|
||||||
};
|
};
|
||||||
|
|
@ -209,7 +233,6 @@ async fn handle_status<T: MinecraftServerHandle>(
|
||||||
.get_motd()
|
.get_motd()
|
||||||
.unwrap_or("A minecraft server (proxy motd)".to_string());
|
.unwrap_or("A minecraft server (proxy motd)".to_string());
|
||||||
|
|
||||||
tracing::trace!(motd);
|
|
||||||
match status {
|
match status {
|
||||||
ServerDeploymentStatus::Connectable(mut server_stream) => {
|
ServerDeploymentStatus::Connectable(mut server_stream) => {
|
||||||
return server
|
return server
|
||||||
|
|
@ -245,7 +268,8 @@ async fn handle_login<T: MinecraftServerHandle>(
|
||||||
&handshake.get_server_address(),
|
&handshake.get_server_address(),
|
||||||
&handshake.server_port.get_value().to_string(),
|
&handshake.server_port.get_value().to_string(),
|
||||||
)
|
)
|
||||||
.await?;
|
.await
|
||||||
|
.map_err(|e| e.set_level(tracing::Level::WARN))?;
|
||||||
|
|
||||||
let status = server.query_status().await?;
|
let status = server.query_status().await?;
|
||||||
tracing::debug!(msg = "server status", status = ?status);
|
tracing::debug!(msg = "server status", status = ?status);
|
||||||
|
|
@ -281,12 +305,20 @@ async fn handle_login<T: MinecraftServerHandle>(
|
||||||
.execute(client_stream, &mut server_stream)
|
.execute(client_stream, &mut server_stream)
|
||||||
.await;
|
.await;
|
||||||
|
|
||||||
tracing::debug!("data exchanged: tx: {} rx: {}", traffic.tx, traffic.rx);
|
match traffic.error {
|
||||||
if let Some(e) = traffic.error {
|
Some(e) => {
|
||||||
return Err(OpaqueError::create(&format!(
|
tracing::info!(
|
||||||
"failed to splice; err = {}",
|
tx = traffic.tx,
|
||||||
e
|
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 => {
|
ServerDeploymentStatus::PodOk | ServerDeploymentStatus::Starting => {
|
||||||
|
|
|
||||||
|
|
@ -1,10 +1,13 @@
|
||||||
use std::{error::Error, fmt};
|
use std::{error::Error, fmt};
|
||||||
|
use tracing::Level;
|
||||||
use tracing_error::SpanTrace;
|
use tracing_error::SpanTrace;
|
||||||
|
|
||||||
#[derive(Debug)]
|
#[derive(Debug)]
|
||||||
pub struct OpaqueError {
|
pub struct OpaqueError {
|
||||||
span_trace: SpanTrace,
|
span_trace: SpanTrace,
|
||||||
pub context: String,
|
pub context: String,
|
||||||
|
pub level: Level,
|
||||||
|
kind: Option<String>,
|
||||||
}
|
}
|
||||||
|
|
||||||
impl fmt::Display for OpaqueError {
|
impl fmt::Display for OpaqueError {
|
||||||
|
|
@ -31,10 +34,20 @@ impl fmt::Display for OpaqueError {
|
||||||
}
|
}
|
||||||
impl Error for OpaqueError {}
|
impl Error for OpaqueError {}
|
||||||
impl OpaqueError {
|
impl OpaqueError {
|
||||||
pub fn create(str: &str) -> OpaqueError {
|
pub fn create(context: &str) -> OpaqueError {
|
||||||
Self {
|
Self {
|
||||||
span_trace: SpanTrace::capture(),
|
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 {
|
pub fn get_span_trace(&self) -> String {
|
||||||
|
|
@ -62,6 +75,16 @@ impl OpaqueError {
|
||||||
Err(_) => str,
|
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<String> for OpaqueError {
|
impl From<String> for OpaqueError {
|
||||||
|
|
@ -69,6 +92,8 @@ impl From<String> for OpaqueError {
|
||||||
Self {
|
Self {
|
||||||
span_trace: SpanTrace::capture(),
|
span_trace: SpanTrace::capture(),
|
||||||
context: value,
|
context: value,
|
||||||
|
level: Level::ERROR,
|
||||||
|
kind: None,
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
@ -78,6 +103,8 @@ impl From<&str> for OpaqueError {
|
||||||
Self {
|
Self {
|
||||||
span_trace: SpanTrace::capture(),
|
span_trace: SpanTrace::capture(),
|
||||||
context: value.to_string(),
|
context: value.to_string(),
|
||||||
|
level: Level::ERROR,
|
||||||
|
kind: None,
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
@ -87,6 +114,8 @@ impl From<crate::packets::ParseErrorTrace> for OpaqueError {
|
||||||
Self {
|
Self {
|
||||||
span_trace: value.context,
|
span_trace: value.context,
|
||||||
context: format!("{:?}", value.inner),
|
context: format!("{:?}", value.inner),
|
||||||
|
level: Level::ERROR,
|
||||||
|
kind: None,
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
|
||||||
|
|
@ -61,7 +61,7 @@ impl Packet {
|
||||||
pub async fn parse(stream: &mut TcpStream) -> Result<Packet, ParseErrorTrace> {
|
pub async fn parse(stream: &mut TcpStream) -> Result<Packet, ParseErrorTrace> {
|
||||||
let length = VarInt::parse(stream)
|
let length = VarInt::parse(stream)
|
||||||
.await
|
.await
|
||||||
.ok_or(ParseError::IDParseError)?;
|
.ok_or(ParseError::LengthParseError)?;
|
||||||
|
|
||||||
tracing::trace!(length = length.get_int());
|
tracing::trace!(length = length.get_int());
|
||||||
let id = match VarInt::parse(stream).await {
|
let id = match VarInt::parse(stream).await {
|
||||||
|
|
@ -150,6 +150,7 @@ impl From<ParseError> for ParseErrorTrace {
|
||||||
}
|
}
|
||||||
|
|
||||||
pub enum ParseError {
|
pub enum ParseError {
|
||||||
|
LengthParseError,
|
||||||
IDParseError,
|
IDParseError,
|
||||||
WeirdID,
|
WeirdID,
|
||||||
LengthIsTooBig(i32),
|
LengthIsTooBig(i32),
|
||||||
|
|
@ -162,7 +163,10 @@ pub enum ParseError {
|
||||||
impl fmt::Debug for ParseError {
|
impl fmt::Debug for ParseError {
|
||||||
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
|
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
|
||||||
match self {
|
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::WeirdID => write!(f, "WeirdID: weird packet id encountered: 122"),
|
||||||
Self::LengthIsTooBig(x) => {
|
Self::LengthIsTooBig(x) => {
|
||||||
write!(f, "LengthIsTooBig: packet length is too big; len={x}")
|
write!(f, "LengthIsTooBig: packet length is too big; len={x}")
|
||||||
|
|
|
||||||
Loading…
Add table
Add a link
Reference in a new issue