mirror of
https://relay.ngit.dev/npub15qydau2hjma6ngxkl2cyar74wzyjshvl65za5k5rl69264ar2exs5cyejr/ngit-grasp.git
synced 2026-10-05 15:08:24 +00:00
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
This commit is contained in:
@@ -9,6 +9,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
|
|||||||
|
|
||||||
### Fixed
|
### 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
|
- Back off repeatedly failed participant mailbox probes, preserving their pauses
|
||||||
across reconnects and inventory changes.
|
across reconnects and inventory changes.
|
||||||
|
|
||||||
|
|||||||
@@ -1638,6 +1638,12 @@ equivalent standard NIP-11 field, so it remains documented configuration only.
|
|||||||
|
|
||||||
### Logging Configuration
|
### 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`
|
#### `NGIT_LOG_LEVEL`
|
||||||
|
|
||||||
**Description:** Application logging level or explicit tracing filter expression
|
**Description:** Application logging level or explicit tracing filter expression
|
||||||
|
|||||||
@@ -6,6 +6,51 @@ use tracing_subscriber::layer::{Context, Filter};
|
|||||||
const LOCAL_RELAY_TARGET: &str = "nostr_sdk::local_relay::local::inner";
|
const LOCAL_RELAY_TARGET: &str = "nostr_sdk::local_relay::local::inner";
|
||||||
const UNCLEAN_RESET: &str = "WebSocket protocol error: Connection reset without closing handshake";
|
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<R: tracing_subscriber::field::RecordFields>(
|
||||||
|
&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.
|
/// Expand a bare application level into an explicit `EnvFilter` directive.
|
||||||
///
|
///
|
||||||
/// `NGIT_LOG_LEVEL` is documented as the application log level. Applying a
|
/// `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<Mutex<Vec<u8>>>);
|
||||||
|
impl std::io::Write for Capture {
|
||||||
|
fn write(&mut self, bytes: &[u8]) -> std::io::Result<usize> {
|
||||||
|
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);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|||||||
+2
-1
@@ -9,7 +9,7 @@ use tracing_subscriber::{filter::FilterExt, layer::SubscriberExt, EnvFilter, Lay
|
|||||||
use ngit_grasp::{
|
use ngit_grasp::{
|
||||||
cleanup_empty_repos,
|
cleanup_empty_repos,
|
||||||
config::Config,
|
config::Config,
|
||||||
logging::{effective_log_filter, SuppressRoutineDisconnects},
|
logging::{effective_log_filter, RelayDiagnosticFields, SuppressRoutineDisconnects},
|
||||||
nostr,
|
nostr,
|
||||||
server::RelayServer,
|
server::RelayServer,
|
||||||
};
|
};
|
||||||
@@ -122,6 +122,7 @@ async fn run_relay(config: Config) -> Result<()> {
|
|||||||
// logs corrupt journald/file output and break log-scraping consumers.
|
// logs corrupt journald/file output and break log-scraping consumers.
|
||||||
let subscriber = tracing_subscriber::registry().with(
|
let subscriber = tracing_subscriber::registry().with(
|
||||||
tracing_subscriber::fmt::layer()
|
tracing_subscriber::fmt::layer()
|
||||||
|
.fmt_fields(RelayDiagnosticFields)
|
||||||
.with_ansi(std::io::stdout().is_terminal())
|
.with_ansi(std::io::stdout().is_terminal())
|
||||||
.with_filter(filter),
|
.with_filter(filter),
|
||||||
);
|
);
|
||||||
|
|||||||
Reference in New Issue
Block a user