fix(normalization): Light normalize logentry [ISSUE-1574] #1442
Conversation
Error message filters look at the `formatted` and `message` entries of an event, in that order. If `formatted` is not provided in the payload, relay builds it from `message` and `params`, [see docs](https://develop.sentry.dev/sdk/event-payloads/types/#typedef-LogEntry). That build, aka logentry normalization, doesn't happen before filters are applied. As a result, events with a `formatted` string that should be filtered out are not, due to the string not being built yet.
Please enter the commit message for your changes. Lines starting
| ({"logentry": {"message": "filter:"}}, False), | ||
| ({"logentry": {"message": "filter:yes"}}, True), | ||
| ({"logentry": {"message": "filter:%s", "params": ["no"]}}, False), | ||
| ({"logentry": {"message": "filter:%s", "params": ["yes"]}}, True), |
There was a problem hiding this comment.
I have not added tests with formatted because I don't think they are valuable at this point. I'm open to adding them and it's not much additional work, so let me know if you think they provide enough value.
| @@ -574,6 +578,7 @@ pub fn light_normalize_event( | |||
| })?; | |||
|
|
|||
| // Default required attributes, even if they have errors | |||
| normalize_logentry(&mut event.logentry, meta)?; | |||
There was a problem hiding this comment.
Originally, this used to run between normalizing IP addresses and validating the release, see.
The order here is important. It still runs after the schema processor and normalization of security reports and IP addresses. I've placed it here, after validating the release and environment, because it doesn't affect the output and it makes the function easier to read by placing all normalization logic together.
| events_consumer.assert_empty() | ||
| else: | ||
| events_consumer.get_event() | ||
| events_consumer.assert_empty() |
There was a problem hiding this comment.
I ran this parametrized test on master, and all 8 instances of it passed, so there might still be something wrong with the hypothesis.
There was a problem hiding this comment.
I added a 1s wait time after sending the event, in bf1d39c. When I was testing it manually, I saw a successful assert_empty followed by a get_event retrieving the event. I'm not sure what is causing that, but adding that 1s addressed this issue (passing here, failing on master). The failing tests on master are those with a message and parameters, with both processing and non-processing relays.
Why 1s? 0.5s isn't enough, and 2s seems too much for now (we can reconsider this if it causes flakiness).
Error message filters look at the
formattedandmessageentries ofan event, in that order. If
formattedis not provided in the payload,relay builds it from
messageandparams, seedocs.
That build, aka logentry normalization, doesn't happen before filters
are applied. As a result, events with a
formattedstring that shouldbe filtered out are not, due to the string not being built yet.