From c8d4b78a3528aaf8680cd6d311590c5fb0e88241 Mon Sep 17 00:00:00 2001 From: DanConwayDev Date: Thu, 24 Sep 2026 10:52:27 +0000 Subject: [PATCH] fix(logging): omit raw relay payloads from SDK diagnostics Repeated rejection of a 5,901-tag event printed its entire 439 KB payload before the rejection reason, fragmenting journal entries and amplifying logs. Use a field formatter that replaces only the outbound SDK target's msg field without formatting the original value. Preserve URL, error, severity, and normal formatting for unrelated messages. This assumes rust-nostr continues to identify raw relay payloads as msg on nostr_sdk::relay::inner. Event validation and relay admission are unchanged; this does not suppress diagnostic events or add a global logging rate limit. Document that raw payload omission also applies under debug logging. Validation: five logging tests pass. The new captured-output regression uses a payload that panics if formatted and verifies retained URL/error fields, unrelated messages, and bounded output for the rejected payload. Assisted-by: GPT-6 --- CHANGELOG.md | 3 ++ docs/reference/configuration.md | 6 +++ src/logging.rs | 96 +++++++++++++++++++++++++++++++++ src/main.rs | 3 +- 4 files changed, 107 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 193ec1f..95ecbf3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,6 +9,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed +- Omit raw rejected relay payloads from SDK diagnostics while retaining URLs and + rejection reasons. + - Back off repeatedly failed participant mailbox probes, preserving their pauses across reconnects and inventory changes. diff --git a/docs/reference/configuration.md b/docs/reference/configuration.md index a1da46a..5fe5880 100644 --- a/docs/reference/configuration.md +++ b/docs/reference/configuration.md @@ -1638,6 +1638,12 @@ equivalent standard NIP-11 field, so it remains documented configuration only. ### Logging Configuration +The server omits the raw `msg` payload from outbound nostr-sdk relay diagnostics. +The relay URL and rejection reason remain visible at the original severity, +including when debug logging is enabled. This prevents large rejected events +from filling logs or hiding the reason across journal fragments; it does not +change event validation. + #### `NGIT_LOG_LEVEL` **Description:** Application logging level or explicit tracing filter expression diff --git a/src/logging.rs b/src/logging.rs index 1c939a3..e43c083 100644 --- a/src/logging.rs +++ b/src/logging.rs @@ -6,6 +6,51 @@ 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"; +/// Keep SDK rejection diagnostics without printing untrusted event payloads. +/// The SDK records `msg` before `error`; huge messages otherwise hide the reason +/// across journald fragments and amplify repeated invalid-event traffic. +#[derive(Debug, Default)] +pub struct RelayDiagnosticFields; + +impl<'writer> tracing_subscriber::fmt::FormatFields<'writer> for RelayDiagnosticFields { + fn format_fields( + &self, + writer: tracing_subscriber::fmt::format::Writer<'writer>, + fields: R, + ) -> std::fmt::Result { + use tracing_subscriber::field::VisitOutput; + let mut visitor = RelayDiagnosticVisitor( + tracing_subscriber::fmt::format::DefaultVisitor::new(writer, true), + ); + fields.record(&mut visitor); + visitor.0.finish() + } +} + +struct RelayDiagnosticVisitor<'a>(tracing_subscriber::fmt::format::DefaultVisitor<'a>); + +fn is_sdk_payload(field: &tracing::field::Field) -> bool { + field.name() == "msg" && field.callsite().0.metadata().target() == "nostr_sdk::relay::inner" +} + +impl Visit for RelayDiagnosticVisitor<'_> { + fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) { + if is_sdk_payload(field) { + self.0.record_str(field, "[relay payload omitted]"); + } else { + self.0.record_debug(field, value); + } + } + + fn record_str(&mut self, field: &tracing::field::Field, value: &str) { + if is_sdk_payload(field) { + self.0.record_str(field, "[relay payload omitted]"); + } else { + self.0.record_str(field, value); + } + } +} + /// Expand a bare application level into an explicit `EnvFilter` directive. /// /// `NGIT_LOG_LEVEL` is documented as the application log level. Applying a @@ -114,3 +159,54 @@ mod tests { )); } } + +#[cfg(test)] +mod diagnostic_tests { + use super::RelayDiagnosticFields; + use std::sync::{Arc, Mutex}; + + #[derive(Clone)] + struct Capture(Arc>>); + impl std::io::Write for Capture { + fn write(&mut self, bytes: &[u8]) -> std::io::Result { + self.0.lock().unwrap().extend_from_slice(bytes); + Ok(bytes.len()) + } + fn flush(&mut self) -> std::io::Result<()> { + Ok(()) + } + } + + #[test] + fn sdk_payload_is_not_formatted_but_reason_and_other_messages_survive() { + struct Unrenderable; + impl std::fmt::Display for Unrenderable { + fn fmt(&self, _: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + panic!("raw relay payload must never be formatted"); + } + } + let bytes = Arc::new(Mutex::new(Vec::new())); + let capture = Capture(bytes.clone()); + let subscriber = tracing_subscriber::fmt() + .with_ansi(false) + .without_time() + .fmt_fields(RelayDiagnosticFields) + .with_writer(move || capture.clone()) + .finish(); + tracing::subscriber::with_default(subscriber, || { + tracing::error!(target: "nostr_sdk::relay::inner", url="wss://peer.example", + msg=%Unrenderable, error="too many tags", "Impossible to handle relay message."); + tracing::error!(target: "nostr_sdk::relay::inner", msg="raw-string-payload", + error="Invalid event ID", "Impossible to handle relay message."); + tracing::warn!(target: "ngit_grasp", msg="keep this diagnostic", count=3, "Other message"); + }); + let log = String::from_utf8(bytes.lock().unwrap().clone()).unwrap(); + assert!(log.contains("wss://peer.example")); + assert!(log.contains("too many tags")); + assert!(log.contains("Invalid event ID")); + assert!(log.contains("keep this diagnostic")); + assert!(log.contains("count=3")); + assert!(!log.contains("raw-string-payload")); + assert!(log.len() < 1024); + } +} diff --git a/src/main.rs b/src/main.rs index b1fcb2a..a1c4291 100644 --- a/src/main.rs +++ b/src/main.rs @@ -9,7 +9,7 @@ use tracing_subscriber::{filter::FilterExt, layer::SubscriberExt, EnvFilter, Lay use ngit_grasp::{ cleanup_empty_repos, config::Config, - logging::{effective_log_filter, SuppressRoutineDisconnects}, + logging::{effective_log_filter, RelayDiagnosticFields, SuppressRoutineDisconnects}, nostr, server::RelayServer, }; @@ -122,6 +122,7 @@ async fn run_relay(config: Config) -> Result<()> { // logs corrupt journald/file output and break log-scraping consumers. let subscriber = tracing_subscriber::registry().with( tracing_subscriber::fmt::layer() + .fmt_fields(RelayDiagnosticFields) .with_ansi(std::io::stdout().is_terminal()) .with_filter(filter), );