fix(logging): demote routine unclean disconnects

Public WebSocket clients commonly reset TCP connections without completing the close handshake. rust-nostr reports that transport outcome as an ERROR, causing production error logs to be dominated by expected client churn and obscuring actionable relay failures.

Add a per-event tracing filter that suppresses only the exact rust-nostr local-relay target and reset-without-close message. Other WebSocket protocol errors, client-send failures, and database failures from the same module retain their configured severity.

The match deliberately remains narrow instead of changing the whole dependency target log level. Reclassifying other disconnect variants or changing rust-nostr upstream is excluded.

Validated with focused classification unit tests and cargo check --bin ngit-grasp in nix develop.
This commit is contained in:
DanConwayDev
2026-08-07 11:50:15 +00:00
parent 87d7732910
commit 662491c99c
4 changed files with 89 additions and 5 deletions
+3
View File
@@ -59,6 +59,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
### Fixed
- Stopped routine client connection resets without a WebSocket close handshake
from being reported as server errors, while retaining other embedded-relay
failures at their original severity.
- Adapted historic pagination to each relay's observed page size and guarded
NIP-11 `default_limit` hint, so omitted-limit filters continue past relays
that return small pages without trusting unrelated maximum-limit metadata.
+1
View File
@@ -4,6 +4,7 @@ pub mod config;
pub mod git;
pub mod grasp06;
pub mod http;
pub mod logging;
pub mod metrics;
pub mod nostr;
pub mod outbound;
+77
View File
@@ -0,0 +1,77 @@
//! Application-specific tracing filters.
use tracing::{field::Visit, Event, Subscriber};
use tracing_subscriber::layer::{Context, Filter};
const LOCAL_RELAY_TARGET: &str = "nostr_sdk::local_relay::local::inner";
const UNCLEAN_RESET: &str = "WebSocket protocol error: Connection reset without closing handshake";
/// Suppresses the routine unclean-disconnect event emitted by the embedded relay.
///
/// Internet clients commonly disappear without completing the WebSocket close
/// handshake. That is useful at debug level but is not a server failure. Match
/// the exact target and error text so database and outbound-send failures from
/// the same rust-nostr module remain visible at their original severity.
#[derive(Debug, Clone, Copy, Default)]
pub struct SuppressRoutineDisconnects;
impl<S> Filter<S> for SuppressRoutineDisconnects
where
S: Subscriber,
{
fn enabled(&self, _meta: &tracing::Metadata<'_>, _cx: &Context<'_, S>) -> bool {
true
}
fn event_enabled(&self, event: &Event<'_>, _cx: &Context<'_, S>) -> bool {
if event.metadata().target() != LOCAL_RELAY_TARGET {
return true;
}
let mut visitor = MessageVisitor::default();
event.record(&mut visitor);
!visitor
.message
.as_deref()
.is_some_and(is_routine_disconnect_message)
}
}
#[derive(Default)]
struct MessageVisitor {
message: Option<String>,
}
impl Visit for MessageVisitor {
fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) {
if field.name() == "message" {
self.message = Some(format!("{value:?}"));
}
}
}
fn is_routine_disconnect_message(message: &str) -> bool {
message.contains("Can't handle websocket msg:") && message.contains(UNCLEAN_RESET)
}
#[cfg(test)]
mod tests {
use super::is_routine_disconnect_message;
#[test]
fn identifies_reset_without_close_handshake() {
assert!(is_routine_disconnect_message(
"Can't handle websocket msg: WebSocket protocol error: Connection reset without closing handshake"
));
}
#[test]
fn retains_other_websocket_and_relay_errors() {
assert!(!is_routine_disconnect_message(
"Can't handle websocket msg: WebSocket protocol error: invalid opcode"
));
assert!(!is_routine_disconnect_message(
"Can't save event into database: disk I/O error"
));
}
}
+8 -5
View File
@@ -2,9 +2,12 @@ use anyhow::Result;
use clap::Parser;
use tokio::signal;
use tracing::info;
use tracing_subscriber::{EnvFilter, FmtSubscriber};
use tracing_subscriber::{filter::FilterExt, layer::SubscriberExt, EnvFilter, Layer};
use ngit_grasp::{cleanup_empty_repos, config::Config, nostr, server::RelayServer};
use ngit_grasp::{
cleanup_empty_repos, config::Config, logging::SuppressRoutineDisconnects, nostr,
server::RelayServer,
};
/// Top-level CLI dispatcher.
///
@@ -66,9 +69,9 @@ async fn main() -> Result<()> {
/// the global tracing subscriber and signal handling.
async fn run_relay(config: Config) -> Result<()> {
// Initialize tracing with configured log level
let subscriber = FmtSubscriber::builder()
.with_env_filter(EnvFilter::new(&config.log_level))
.finish();
let filter = EnvFilter::new(&config.log_level).and(SuppressRoutineDisconnects);
let subscriber =
tracing_subscriber::registry().with(tracing_subscriber::fmt::layer().with_filter(filter));
tracing::subscriber::set_global_default(subscriber)?;
info!("Starting ngit-grasp with log level: {}", config.log_level);