Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ignored exceptions are still built #1017

Closed
greg0ire opened this issue May 13, 2020 · 18 comments
Closed

Ignored exceptions are still built #1017

greg0ire opened this issue May 13, 2020 · 18 comments

Comments

@greg0ire
Copy link
Contributor

I have a microservice that calls an external API. Sometimes, this external API will timeout, and my application will create a GatewayTimeoutException, with a NoResponseException as previous exception, with a Http\Client\Exception\NetworkException as previous exception, with a GuzzleHttp\Exception\ConnectException. It's 4 level deep.

I found that a lot of time was spent handling those in Sentry, so I added them to the list of ignored exceptions. This did not result in an improvement, because it seems the exceptions are still handled by Sentry, even if they are ultimately not sent to the server. I mitigated the issue by not setting the NoResponseException as a previous exception when not in debug mode, it resulted in a 100ms improvement. I won't share the blackfire trace because I can't redact things in it, but here is a screenshot of the interesting part, which does not involve code in my application:

Screenshot_2020-05-13 Comparison from Untitled to Untitled - Blackfire

Using

sentry/sdk                          2.1.0   This is a metapackage shipping sentry/sentry with a recommended http client.
sentry/sentry                       2.3.2   A PHP SDK for Sentry (http://sentry.io)
sentry/sentry-symfony               3.5.1   Symfony integration for Sentry (http://getsentry.com)
@Jean85
Copy link
Collaborator

Jean85 commented May 14, 2020

It seems to me that the issue is bound to #928, which introduced the IgnoreErrorsIntegration; due to that, the check for ignored exceptions is no longer performed at the top of the stack here:

if (!isset($this->integrations[IgnoreErrorsIntegration::class]) && $this->options->isExcludedException($exception, false)) {
return null;
}

...but later, after the whole stacktrace is extracted, which is obviously costly with a 4-levels-deep exception chain...

@ste93cry WDYT?

@greg0ire
Copy link
Contributor Author

I remember debugging through that code and being a bit confused by line 97 not being executed… I also saw there is an integrations config node, but I didn't figure how I should configure it, so I stuck with excluded_exceptions

@ste93cry
Copy link
Collaborator

so I stuck with excluded_exceptions

If you don't have the IgnoreErrorsIntegration integration enabled and you configured correctly that option then the code should exit at line 97 so it sounds strange to me that it's not executed.

but later, after the whole stacktrace is extracted, which is obviously costly with a 4-levels-deep exception chain

As can be seen from the screenshot at the beginning, the problems seems to be that for each frame we read the source code from the disk and this is pretty I/O intensive. @greg0ire you should try to see if with #1003 (not released yet) the issue goes away

@greg0ire
Copy link
Contributor Author

greg0ire commented May 14, 2020

it sounds strange to me that it's not executed.

It does, right? I just booted my work PC because I remember it being enabled in some sort of BC layer, and that's indeed the case, just not in this package. Here is the culprit I think:

https://github.com/getsentry/sentry-symfony/blob/6c3f3236504c2722eb5a8b26a10a2596bee62494/src/DependencyInjection/SentryExtension.php#L131-L137

So I suppose it's as if I have both the option and the integration enabled?

As can be seen from the screenshot at the beginning, the problems seems to be that for each frame we read the source code from the disk and this is pretty I/O intensive. @greg0ire you should try to see if with #1003 (not released yet) the issue goes away

I don't fully understand what this done, but sure, I can try tomorrow, unless you tell me the issue above should be fixed instead.

@ste93cry
Copy link
Collaborator

So I suppose it's as if I have both the option and the integration enabled?

Yes, excluded_exceptions option is not being unsetted and thus both the legacy code and the new integration get executed: it's a bug and should be fixed

I don't fully understand what this done

While in the documentation it was mentioned that the context_lines option would have accepted null value to skip sending the source code of the frames of the stacktrace in reality it never worked, so I fixed it.

@Jean85
Copy link
Collaborator

Jean85 commented May 15, 2020

Yes, excluded_exceptions option is not being unsetted and thus both the legacy code and the new integration get executed: it's a bug and should be fixed

Woops, my bad, yes, that's a bug! I've opened getsentry/sentry-symfony#345 to track this.

@greg0ire
Copy link
Contributor Author

greg0ire commented May 16, 2020

@greg0ire you should try to see if with #1003

I'm trying it right now, for science, but as I understand it, this implies setting context_lines to null for all exceptions, including of course exceptions that are actually sent. I don't think I really want to do that.

@greg0ire
Copy link
Contributor Author

Ah it looks like a change is needed on the Symfony bundle for null to be accepted 🤔

@greg0ire
Copy link
Contributor Author

Probably too laxist, but redefining the configuration node as a scalar node (as opposed to an integer node) allows null.

@greg0ire
Copy link
Contributor Author

greg0ire commented May 16, 2020

I managed to do it, looks like you did a great job with that PR, -27% improvement! :

Screenshot_2020-05-16 Comparison from Untitled to Untitled - Blackfire

The thing is I don't think I want that, and I think I have uncovered a big architectural issue: things are built that are not needed to take a decision.

This integration is plugged to a scope at some point:

Scope::addGlobalEventProcessor(function (Event $event): ?Event {

The unified API, that I just discovered, describes a scope as

A scope holds data that should implicitly be sent with Sentry events. It can hold context data, extra parameters, level overrides, fingerprints etc.

Why should it know about data not being sent (excluded exceptions)? This looks wrong. I think there should be another thing this integration could plug to, that would be called earlier (the best place being probably

if (!isset($this->integrations[IgnoreErrorsIntegration::class]) && $this->options->isExcludedException($exception, false)) {
return null;
}
). I hope this architecture is something you can change and not something that is forced upon you across SDKs

@Jean85
Copy link
Collaborator

Jean85 commented May 18, 2020

I hope this architecture is something you can change and not something that is forced upon you across SDKs

It is something requested to all SDK, but we have some leeway.

In this case, maybe we can fix this by putting the IgnoreErrorsIntegration first, so it will stop the execution early?

@greg0ire
Copy link
Contributor Author

If you mean "first in the array of integrations", I doubt it will change anything. What this integrations does is register itself as a global event processor in the Scope. Then the scope calls it in a loop of event processing, but way, way too late (after the event is built, obviously).

@ste93cry
Copy link
Collaborator

ste93cry commented May 18, 2020

I managed to do it, looks like you did a great job with that PR, -27% improvement! :

Well the improvement is not thanks to me: it's just that you are not reading anymore the source files to extract the context lines to send along with each frame, so there is less I/O which is heavy by nature.

this implies setting context_lines to null for all exceptions, including of course exceptions that are actually sent. I don't think I really want to do that.

It was just a test to see if it was the culprit of the problem, I didn't mean that it was the solution 😉

Probably too laxist, but redefining the configuration node as a scalar node (as opposed to an integer node) allows null.

@Jean85 this is another bug to be fixed related to #1003

What this integrations does is register itself as a global event processor in the Scope. Then the scope calls it in a loop of event processing, but way, way too late (after the event is built, obviously)

I think that #1011 can definitely help because it will move this task to an integration itself, and if configured to run later than the aforementioned integration it will solve all problems. If you are willing to test the branch and see if it helps you it would be cool

@greg0ire
Copy link
Contributor Author

Sure! Can you please run this gist from your local repo, with your branch checked out, then post the results on the PR? It will help me do the test. https://gist.github.com/greg0ire/a404831add1247d2bc20fa11107c5d5e

@ste93cry
Copy link
Collaborator

Here you go:

composer config repositories.ste93cry vcs https://github.com/ste93cry/sentry-php
composer require sentry/sentry "dev-feature/add-frame-contextifier-integration as 2.3.2"

@greg0ire
Copy link
Contributor Author

Screenshot_2020-05-18 Comparison from Untitled to Untitled - Blackfire

Nice job here too, that's a 50% improvement!

@ste93cry
Copy link
Collaborator

Are these changes sufficient for your use-case? If so, feel free to close the issue

@greg0ire
Copy link
Contributor Author

They are, thanks

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants