From 88cda1c6ad2e5dfd0fe400f4183f896e32ec320d Mon Sep 17 00:00:00 2001 From: Thomas Eizinger Date: Sat, 7 Jun 2025 15:05:30 +0200 Subject: [PATCH] fix(telemetry): negate filters for spammy events (#9469) Boolean logic is hard. Instead of filtering _out_ these spammy events on a certain level, we accidentally configured the `SentryLayer` such that only events on level ERROR would be sent to Sentry. To fix this, we rewrite the filter such that it is phrased in an affirmative manner, i.e. it only allows an event if it matches all of the given criteria. This filter this then applied in a **negated** way, i.e. we don't want to see events that match these criteria. Resolves: #9400 --- .../src/event_message_contains_filter.rs | 62 ++++++++++++------- rust/logging/src/lib.rs | 18 +++--- 2 files changed, 52 insertions(+), 28 deletions(-) diff --git a/rust/logging/src/event_message_contains_filter.rs b/rust/logging/src/event_message_contains_filter.rs index 36b0c6687..5856fdb92 100644 --- a/rust/logging/src/event_message_contains_filter.rs +++ b/rust/logging/src/event_message_contains_filter.rs @@ -1,7 +1,7 @@ use tracing::Level; use tracing_subscriber::layer::Filter; -/// Filters out all events whose message contains all of the given snippets. +/// Filters all events whose message does not contain all of the given snippets. pub struct EventMessageContains { level: Level, snippets: Vec<&'static str>, @@ -25,11 +25,7 @@ where metadata: &tracing::Metadata<'_>, _: &tracing_subscriber::layer::Context<'_, S>, ) -> bool { - if metadata.level() != &self.level { - return false; - } - - true + metadata.level() == &self.level } fn event_enabled( @@ -41,18 +37,12 @@ where event.record(&mut visitor); let Some(message) = visitor.message else { - return true; + return false; }; - if self - .snippets + self.snippets .iter() .all(|snippet| message.contains(snippet)) - { - return false; - } - - true } } @@ -78,7 +68,9 @@ impl tracing::field::Visit for MessageVisitor { mod tests { use super::*; use crate::capturing_writer::CapturingWriter; - use tracing_subscriber::{Layer, layer::SubscriberExt, util::SubscriberInitExt}; + use tracing_subscriber::{ + Layer, filter::FilterExt, layer::SubscriberExt, util::SubscriberInitExt, + }; #[test] fn matches_on_all_strings() { @@ -88,10 +80,10 @@ mod tests { .with( tracing_subscriber::fmt::layer() .with_writer(capture.clone()) - .with_filter(EventMessageContains::all( - Level::DEBUG, - &["foo", r#"bar ("xyz")"#, "baz"], - )), + .with_filter( + EventMessageContains::all(Level::DEBUG, &["foo", r#"bar ("xyz")"#, "baz"]) + .not(), + ), ) .set_default(); @@ -113,11 +105,39 @@ mod tests { .with_level(false) .without_time() .with_target(false) - .with_filter(EventMessageContains::all(Level::DEBUG, &["foo"])), + .with_filter(EventMessageContains::all(Level::DEBUG, &["foo"]).not()), ) .set_default(); - tracing::debug!("This is a message"); + tracing::warn!("This is a message"); + + assert_eq!( + *capture.lines().lines().collect::>(), + vec!["This is a message".to_owned()] + ); + } + + #[test] + fn multiple_filters() { + let capture = CapturingWriter::default(); + + let _guard = tracing_subscriber::registry() + .with( + tracing_subscriber::fmt::layer() + .with_writer(capture.clone()) + .with_level(false) + .without_time() + .with_target(false) + .with_filter(EventMessageContains::all(Level::DEBUG, &["foo"]).not()) + .with_filter(EventMessageContains::all(Level::DEBUG, &["bar"]).not()) + .with_filter(EventMessageContains::all(Level::DEBUG, &["baz"]).not()), + ) + .set_default(); + + tracing::debug!("foo"); + tracing::debug!("This is a message baz"); + tracing::debug!("bar"); + tracing::warn!("This is a message"); assert_eq!( *capture.lines().lines().collect::>(), diff --git a/rust/logging/src/lib.rs b/rust/logging/src/lib.rs index e7a8d7fb7..88a7f75dc 100644 --- a/rust/logging/src/lib.rs +++ b/rust/logging/src/lib.rs @@ -17,8 +17,13 @@ use sentry_tracing::EventFilter; use tracing::{Subscriber, subscriber::DefaultGuard}; use tracing_log::LogTracer; use tracing_subscriber::{ - EnvFilter, Layer, Registry, filter::ParseError, fmt, layer::SubscriberExt as _, - registry::LookupSpan, reload, util::SubscriberInitExt, + EnvFilter, Layer, Registry, + filter::{FilterExt, ParseError}, + fmt, + layer::SubscriberExt as _, + registry::LookupSpan, + reload, + util::SubscriberInitExt, }; pub use ansi::stdout_supports_ansi; @@ -224,29 +229,28 @@ where r#"RemoveInstance "SWD\WINTUN\{E9245BC1-B8C1-44CA-AB1D-C6AAD4F13B9C}""#, "(Code 0x00000003)", ], - )) + ).not()) .with_filter(EventMessageContains::all( Level::ERROR, &[ r#"WinTun: Error executing worker process: "SWD\WINTUN\{E9245BC1-B8C1-44CA-AB1D-C6AAD4F13B9C}""#, "(Code 0x00000003)", ], - )) + ).not()) .with_filter(EventMessageContains::all( Level::ERROR, &[ "WinTun: Failed to remove adapter when closing", "(Code 0x00000003)", ], - )) + ).not()) .with_filter(EventMessageContains::all( Level::ERROR, &[ r#"WinTun: Failed to remove orphaned adapter "Firezone""#, "(Code 0x00000003)", ], - )) - // Filter out noisy crates but pass all events otherwise. + ).not()) } #[doc(hidden)]