When using the new breadcrumbs handler with Messenger, the Messenger should either flush or clear *before* every new message

[dkarlovi]

Environment

sentry/sdk                             3.3.0                         This is a metapackage shipping sentry/sentry with a recommended HTTP client.
sentry/sentry                          3.11.0                        A PHP SDK for Sentry (http://sentry.io)
sentry/sentry-symfony                  4.4.0                         Symfony integration for Sentry (http://getsentry.com)

Steps to Reproduce

sentry:
    register_error_listener: false
    dsn: "%env(file:SENTRY_DSN_FILE)%"
    messenger:
        enabled: true
        capture_soft_fails: false
    tracing:
        enabled: false
    options:
        environment: '%env(APP_COHORT)%'
        integrations:
            - 'Sentry\Integration\IgnoreErrorsIntegration'

services:
    Sentry\Monolog\BreadcrumbHandler:
        arguments:
            - '@Sentry\State\HubInterface'
            - !php/const Monolog\Logger::INFO

monolog:
    handlers:
        sentry_breadcrumbs:
            type: service
            name: sentry_breadcrumbs
            id: Sentry\Monolog\BreadcrumbHandler
        sentry:
            type: sentry
            level: !php/const Monolog\Logger::ERROR
            hub_id: Sentry\State\HubInterface

Expected Result

The captured error contains breadcrumbs for the current message.

Actual Result

The captured error contains breadcrumbs for all the messages prior, most of which didn't trigger a Sentry capture.

[cleptric]

Just to clarify, you're talking about unrelated breadcrumbs during the current request? This sounds like it's expected to me, breadcrumbs should show a trail of events that happened before an event. Or do I miss something?

[dkarlovi]

The issue is it can show you many unrelated events, sometimes minutes before the current one. In the example I'm looking at, the first breadcrumb is from 10:48:07, the capture happened in 11:08:16, there were totally unrelated messages processed in the meantime, but they're still marked as "breadcrumbs".

From my POV, the breadcrumbs should be related to the current event, no? They're not meant to replace distributed tracing.

[cleptric]

Are you running in some sort of CLI context? For HTTP requests, yes, the breadcrumbs should only be related to the current request cycle and nothing more.

[dkarlovi]

Yes, this is Symfony Messenger specifically.

[dkarlovi]

But I think I understand what you mean, the state of the process is also part of the story. It having processed previous messages can also be something to influence the current issue. 👍 I guess it's working as intended, it just looks weird when you're not used to it. :)

[cleptric]

In our Laravel SDK, we do clear the breadcrumbs for each job.

https://github.com/getsentry/sentry-laravel/blob/8ce96842a9c3b047077fd59d66692ccf4eee5fc0/src/Sentry/Laravel/EventHandler.php#L573-L584

I can see how this would be helpful, not clearing them might be helpful as well. So it depends 🙂

[dkarlovi]

So, what do you think here? Do I reopen?

[cleptric]

Yes, let's take a look on how to improve this a bit.

[Jean85]

I would vote toward clearing by default: a memory leak or an event too fat to be received by Sentry would be around the corner otherwise. The only safeguard would be the limit that we have on breadcrumbs on the main SDK.

We could reverse this decision once #51 kicks in, because the logger would explicitly state that a previous message was consumed, making easier to understand where each message consumption starts and ends.

[dkarlovi]

TBH since I've opened the issue I've been thinking on POV made by @cleptric where the previous messages being processed by the same worker are also "breadcrumbs" in a way. I can see merit in both approaches, but clearing is for sure more efficient.

Having a longer history could be some sort of opt-in, for example:

sentry:
    messenger:
        breadcrumbs: 50 # would control the main SDK limit specifically in Messenger / CLI mode

The same problem will be present in newer runner based PHP runtimes like Swoole etc. The state of the process (previous requests processed) might directly be responsible for the event being captured by Sentry, having that in breadcrumbs would be extremely valuable.

Might we worth thinking it over in both directions.

[Jean85]

#702 was opened as a duplicate of this one. There seems to be still request for this change.

[rvanlaak]

What also is worth mentioning is that the ResetInterface was introduced on the DI component to support resetting services on the container, which is something that by-default happens on many services already (to prevent memory leaks / prevent stateful services to affect processing).

Having a stateless worker could be considered more valuable as having a trail of breadcrumbs from previous iterations. Why? Let's say you use supervisor to always have 20 workers, then the breadcrumb trail became more irrelevant because you don't know which worker processes which message, and that basically also wouldn't be considered as that valuable. It mostly leads to confusion.

[hildebro]

I've ran into the same problem using symfony messenger. Are there any plans on tackling this?

[cleptric]

We'll look at this eventually. Can't give you a timeframe though 🙁

[dkarlovi]

@rvanlaak

Let's say you use supervisor to always have 20 workers, then the breadcrumb trail became more irrelevant because you don't know which worker processes which message

The breadcrumbs would come from the current worker, as in, the worker which is reporting into Sentry. It doesn't matter which worker processed which messages, it's more like

This specific worker processed these specific messages when the error condition was reached.

Hence "breadcrumbs". We've actually solved one issue because of this feature, there was a message which wasn't cleared properly after having been completed and the next message would error out, but it itself wasn't at fault, the previous message was (which didn't trigger the error!). We've noticed in the breadcrumbs this happening and it gave us an idea what to look for. On one hand, yes it leads to memory leakage, on the other hand it has value in a distributed environment so it's a tradeoff.

[rvanlaak]

@dkarlovi yes you are right about the difference, the goal would not be to reset the breadcrumbs per worker process but per Symfony Messenger message. What about a simple fix by letting the handler implement ResetInterface ?

https://symfony.com/doc/current/messenger.html#stateless-worker

https://github.com/symfony/symfony/blob/6.4/src/Symfony/Contracts/Service/ResetInterface.php

[dkarlovi]

This would mean you don't get the described information about the previous messages in your Sentry issue breadcrumbs.

[rvanlaak]

Correct. Given that every bus message by most users is considered to be an isolated transaction, that preferably is the expected behaviour as described in the issue above. Would you have a scenario in which you would like to know the breadcrumbs of a previous message?

[dkarlovi]

Would you have a scenario in which you would like to know the breadcrumbs of a previous message?

I've literally just wrote about it today? 🤔

[cleptric]

We could add listening to WorkerMessageReceivedEvent & WorkerMessageHandledEvent and push/pop a scope for each job executed. As breadcrumbs are stored on the scope, this would clear those. And we likely also should make this configurable, as both behaviours have their merit.

[hildebro]

We could add listening to WorkerMessageReceivedEvent & WorkerMessageHandledEvent and push/pop a scope for each job executed. As breadcrumbs are stored on the scope, this would clear those. And we likely also should make this configurable, as both behaviours have their merit.

That's exactly what I did to solve this problem for now:

    public function onWorkerMessageReceived(WorkerMessageReceivedEvent $event): void
    {
        $this->sentryHub->configureScope(function (Scope $scope) {
            $scope->clear();
        });
    }

[dkarlovi]

IMO, my suggestion from here still makes sense, I'd just change the name:

sentry:
    messenger:
        prior_breadcrumbs: 10

This would mean you keep at most 10 most recent breadcrumbs from previous messages (or disable with setting to 0). If the handler generates say 5 breadcrumbs while handling the current message, you'd get 15 in total.

The listener then does the equivalent of:

    public function onWorkerMessageReceived(WorkerMessageReceivedEvent $event): void
    {
        $this->sentryHub->configureScope(function (Scope $scope) {
            $scope->clearAllButMostRecent(10);
        });
    }

[cleptric]

This would require changing the base SDK, and to be honest, I'm not keen on adding such a specific method there.

[dkarlovi]

I said "the equivalent of", you already have the possibility to keep last X breadcrumbs:
https://github.com/getsentry/sentry-php/blob/fbe4c4a3e1b26ca5302d1c431359226c92b1fba3/src/State/Scope.php#L278

[kkevindev]

Experiencing the same problem here! Hopefully Sentry would change this because it (previous message exceptions in the breadcrumbs) can potentially lead a developer to the wrong path when trying to figure out why an error has occurred.