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

Capturing E_ERROR fatal errors broken on PHP 7 #552

Closed
stayallive opened this issue Feb 17, 2018 · 48 comments · Fixed by #571 or ChristophWurst/nextcloud_sentry#18
Closed

Capturing E_ERROR fatal errors broken on PHP 7 #552

stayallive opened this issue Feb 17, 2018 · 48 comments · Fixed by #571 or ChristophWurst/nextcloud_sentry#18
Assignees

Comments

@stayallive
Copy link
Collaborator

As commented by @mfb on #514:

What are you all doing to capture fatal PHP errors, such as allowed memory size exhausted? To capture this fatal error successfully, I had to comment out the return FALSE; in shouldCaptureFatalError():

if (PHP_VERSION_ID >= 70000 && $type === E_ERROR) {
  // return false;
}

sample code:

<?php
include '../vendor/autoload.php';
$client = new Raven_Client('...');
$client->install();
while (TRUE) {
  $a[] = 11111111111;
}

It seems like this does prevent those errors from being reporting, however removing that seems to bring us back to the original issue causing 2 reports for the same error, likely caused by

which causes the following error in my PHP 7.2 installation:

Parse error: syntax error, unexpected '}' in /private/var/www/sentry-php/error.php on line 5

Fatal error: Exception thrown without a stack frame in Unknown on line 0

Which are both reported, which is ofcourse incorrect.

@Jean85
Copy link
Collaborator

Jean85 commented Feb 17, 2018

Two thing from the docs that could interest us:

It is important to remember that the standard PHP error handler is completely bypassed for the error types specified by error_types unless the callback function returns FALSE.

Also note that it is your responsibility to die() if necessary. If the error-handler function returns, script execution will continue with the next statement after the one that caused an error.

@mfb
Copy link
Contributor

mfb commented Feb 17, 2018

Is there a complete list of fatal errors in PHP 7.x which aren't being thrown?

I found this: "Fatal errors still exist for certain conditions, such as running out of memory, and still behave as before by immediately halting script execution" @ https://trowski.com/2015/06/24/throwable-exceptions-and-errors-in-php7/

Also found this list of fatal error to exception conversions in PHP 7.1: http:https://php.net/manual/en/migration71.incompatible.php#migration71.incompatible.fatal-errors-to-error-exceptions

@mfb
Copy link
Contributor

mfb commented Feb 17, 2018

In my quick testing, it looks like for maximum execution time exceeded, PHP won't give Sentry enough time to fire off an error report? But it would be nice to catch allowed memory size exhausted at least.

Actually we can catch maximum execution time exceeded. This was related to the below bug, using curl async.

@mfb
Copy link
Contributor

mfb commented Feb 17, 2018

I found a related bug: When using curl async, it looks like we need to call $this->client->onShutdown(); in handleFatalError() after $this->handleException($e, true); to actually send off the fatal error.

@Jean85
Copy link
Collaborator

Jean85 commented Feb 19, 2018

@mfb calling onShutdown() immediately will basically erase the usefulness of that method: it's used to send errors in an async way. Maybe we can disable that behavior in some specific cases?

mfb added a commit to mfb/sentry-php that referenced this issue Feb 20, 2018
ignore Uncaught Error if exception handling is active; capture other errors
mfb added a commit to mfb/sentry-php that referenced this issue Feb 20, 2018
ignore "Uncaught" if exception handling is active; capture other errors
@mfb
Copy link
Contributor

mfb commented Feb 20, 2018

It actually seems correct for Sentry to log both the initial Throwable (Error or Exception) and also log if it was uncaught. Because those are two separate events?

But for folks who just want one event to be logged, we could add some configuration to fatal error handling to ignore messages that start with "Uncaught", as this should represent an already-captured Throwable if exception handling is active...?

@stayallive
Copy link
Collaborator Author

Yes technically it is correct to capture both, but not very useful to capture the fatal too since it won't contain a stack trace and thus makes it quite unuseful.

Your idea is a good one, will need to test it a bit since I never got the unhandled exception (int he message) with the parse error.

@stayallive
Copy link
Collaborator Author

The changes from @mfb (mfb@17233a7) are working with memory exhaustion for example, but for a syntax error we are still catching the original handler causing there to be no output. Even when returning false from handleException.

Rethrowing the exception in handleException does help to show the Parse Error again but also causes a Fatal error: Exception thrown without a stack frame in Unknown on line 0.

@mfb
Copy link
Contributor

mfb commented Feb 23, 2018

Since the Sentry exception handler would have already logged an exception, we could add "Exception thrown without a stack frame" as another message to ignore in shouldCaptureFatalError..? (It would be nice to find a more elegant solution - if I find some more free time to debug this I will..)

@Jean85
Copy link
Collaborator

Jean85 commented Feb 26, 2018

I'm currently experiencing a strange issue with this too: using the Symfony integration, when a fatal (like a type error) is thrown, the actual behavior of the client creates a loop that does capture the exception but not the fatal, which "continues" and re-captures it again as an exception, generating a loop and creating thousands of identical events.

@mfb
Copy link
Contributor

mfb commented Mar 1, 2018

@Jean85 I haven't seen that on sentry-php alone. So should be a bug report on sentry-symfony?

@Jean85
Copy link
Collaborator

Jean85 commented Mar 2, 2018

@stayallive was saying that this happened with the Laravel integration. I'm not sure if it's the bundle's fault or it's the presence of the Symfony's error handler that's complicating stuff.

@acleon
Copy link

acleon commented Mar 7, 2018

@Jean85 Same here.

The original error is logged to Sentry. Then we see essentially a loop with Symfony\Component\Debug\Exception\FatalErrorException - Error: Uncaught Symfony\Component\Debug\Exception\FatalThrowableError being logged several thousand times until it eventually pushed over PHP-FPM.

Obviously this is really inconvenient, as it means Sentry is pushing a whole production server over when an error is encountered.

Symfony 3.4.4, Sentry Symfony 2.0.2, Sentry 1.8.3

@acleon
Copy link

acleon commented Mar 7, 2018

I've attempted to use the skip capture part of the config to ignore those two exceptions:

skip_capture:
    - "Symfony\\Component\\Debug\\Exception\\FatalErrorException"
    - "Symfony\\Component\\Debug\\Exception\\FatalThrowableError"

But I still get the same thing - the original error, a few thousand more of FatalErrorException, then death.

@acleon
Copy link

acleon commented Mar 7, 2018

Have moved Sentry's kernel.exception listener to the lowest priority and then later to the highest priority. Neither solved the issue.

@Jean85
Copy link
Collaborator

Jean85 commented Mar 7, 2018

I think the best approach could be changing how we handle the PHP 5/7 cross-compat for thorwable errors, and how the bundle wires to the app to catch exceptions. I'll have to investigate on that...

@Jean85
Copy link
Collaborator

Jean85 commented Mar 7, 2018

@acleon can you try do disable the call to the Client::install() method in the bundle? It's here: https://github.com/getsentry/sentry-symfony/blob/ea4de1359e77127784c58d4dcbc865d148c8a8cb/src/Resources/config/services.yml#L6-L7

This wouldn't be an ideal solution (we would miss memory exaustion error, for example) but I want to understand if this is a possible good approach.

[EDIT] or maybe the reverse approach is better? Leave the install on, do not use the ExceptionListener...

@acleon
Copy link

acleon commented Mar 7, 2018

Removing the call to Client::install() does solve the problem. A FatalThrowableError gets logged to Sentry and there's no run-away loop that crashes FPM.

Was able to force an out-of-memory error and, as you suspected, this didn't make it to Sentry.

@acleon
Copy link

acleon commented Mar 7, 2018

For anybody else with this, the best thing to do at the moment seems to be to disable the SentryBundle and use Monolog with a setup similar to this:

monolog:
    handlers:
        sentry:
            type: raven
            dsn: "<dsn goes here>"
            level: notice

@Jean85
Copy link
Collaborator

Jean85 commented Mar 7, 2018

Does the Monolog setup catch out-of-memory errors?

@acleon
Copy link

acleon commented Mar 7, 2018

No, it doesn't

@istepaniuk
Copy link

istepaniuk commented Mar 8, 2018

For reasons that hours of debugging couldn't explain yet, FatalThrowableError triggers a runaway only when the NewRelic exception handler was installed by their extension first. Stack looks like (newer frame last)

  • Raven_ErrorHandler->handleException
  • Symfony\Component\Debug\ErrorHandler->handleException
  • newrelic_exception_handler
  • Symfony\Component\Debug\ErrorHandler->handleFatalError
  • Symfony\Component\Debug\ErrorHandler->handleException
  • Raven_ErrorHandler->handleException
  • Symfony\Component\Debug\ErrorHandler->handleException
  • Raven_ErrorHandler->handleException
  • (loops last two until FPM dies, flooding sentry with errors)

Is this the same issue?

(sentry/sentry 1.8.2, sentry/sentry-symfony 0.8.7)

@kwolniak
Copy link

@istepaniuk I can confirm it, when we disabled NewRelic there is no more event picks in sentry but we don't have NR :(

On php 5.6 it was working ok.

(php: 7.1, sentry/sentry: 1.8.2, sentry/sentry-symfony: 1.0.1)

@Jean85
Copy link
Collaborator

Jean85 commented Mar 14, 2018

On php 5.6 it was working ok.

@kwolniak yes that makes sense, it's the \Throwable interface of PHP 7+ that creates this mess: errors are now catched like exceptions, and the error handler doesn't behave correctly in this respect.

@kwolniak
Copy link

kwolniak commented Mar 14, 2018

@Jean85 Any idea how we can prevent this?
Because there is other errors like "out of memeory" and "max execution time", and this erros still make a mess.

@Jean85
Copy link
Collaborator

Jean85 commented Mar 14, 2018

I'm currently not sure how this should be fixed. I need to find time to investigate this further, because I do not know the full extent of this problem.

It seems that the combination that triggers this issue is

  • PHP 7.x
  • Sentry Client
  • Sentry bundle
  • NewRelic ext

Is this right?

@Jean85
Copy link
Collaborator

Jean85 commented Mar 14, 2018

We have an other report here: symfony/symfony#26438

It says that Symfony 3.4.5+ should contain an important bug fix in the error handler, could you check if that changes anything?

@istepaniuk
Copy link

istepaniuk commented Mar 14, 2018

There is something odd I've noticed while debugging this issue:

Symfony\Component\Debug\ErrorHandler->setExceptionHandler() gets called when booting the symfony kernel but ALSO right after the error (wrong type passed to a function) ocurred.

The second time, trace comes from nowhere (from the new_relic extension code) and the $handler passed is the Raven one. Since the Raven handler has the symfony one as previous, this causes a loop.

I can't really understand why setExceptionHandler gets called at other than at kernel boot time.

@Jean85
Copy link
Collaborator

Jean85 commented Mar 14, 2018

@istepaniuk this doesn't seem to happen in the stacktrace reported in symfony/symfony#26438...

@Jean85
Copy link
Collaborator

Jean85 commented Mar 14, 2018

As reported in symfony/symfony#26438 (comment):

[...] I just confirmed that disabling the NewRelic extensions solves the issue! I was able to reproduce this only in production don't know why, but I re-deployed the container without the NewRelic ext and it stopped looping over the fatal error.

My setup:

  • PHP 7.2.3
  • Symfony 3.4.6
  • Sentry client 1.8.3
  • Sentry bundle 2.0.2
  • NewRelic ext 8 (when used)

@istepaniuk
Copy link

@Jean85 I see. I did not save this particular trace, sorry. I'm guessing the stack trace is split by the non-php code and that is the other part.

Maybe @alcohol can reproduce this part too, we are actually on the same codebase (and office). Setting all this in our local environment was already quite complicated.

@alcohol
Copy link

alcohol commented Mar 15, 2018

I think this should help repro the issue. If not, please leave an issue on said repo with details: https://github.com/alcohol/repro-infinite-loop

@Jean85
Copy link
Collaborator

Jean85 commented Mar 17, 2018

It seems that symfony/symfony#26568 fixes the issue, yay! 🎉

@mfb
Copy link
Contributor

mfb commented Mar 18, 2018

So now back to the original issue here, which can be reproduced w/ just a few lines of PHP (no symfony). The one solution I've thought of is ignoring messages that start with "Uncaught " or "Exception thrown without a stack frame" when sending fatal errors to sentry. Which feels hacky but should work.

@Jean85
Copy link
Collaborator

Jean85 commented Mar 19, 2018

@mfb can you share with us the lines of PHP necessary to reproduce that issue?

@mfb
Copy link
Contributor

mfb commented Mar 19, 2018

See the sample code at the top of this issue.

@Jean85
Copy link
Collaborator

Jean85 commented Mar 19, 2018

@mfb I just tested that snippet with PHP 7.0 and Sentry client v1.8.3, and I do not have that problem, you probably have something else in your system which is causing the issue.

In my case, on the very contrary I do NOT get any error reported due to this little piece of code:

if (PHP_VERSION_ID >= 70000 && $type === E_ERROR) {
return false;
}

If I comment that out, I get the error, correctly; I believe that that check is doing more harm than good... @stayallive what do you think? IMO we should move that check into the exception handler, which is eventually called later. I'm not sure how to do that, at least in Symfony's case I can add a specific ignore to the class that Symfony uses in the re-throw and call it a day, but elsewhere? Not sure...

@mfb
Copy link
Contributor

mfb commented Mar 19, 2018

That's exactly what this issue is about: see the top of the issue where I commented out that line. :)

mfb added a commit to mfb/sentry-php that referenced this issue Mar 19, 2018
ignore "Uncaught" and "Exception thrown without a stack frame" if exception handling is active; capture other errors
@Jean85
Copy link
Collaborator

Jean85 commented Mar 19, 2018

Oh ok I was missing that out, I misunderstood your request, sorry!
I just opened #571 to fix this.

@Jean85 Jean85 self-assigned this Mar 19, 2018
@mfb
Copy link
Contributor

mfb commented Mar 20, 2018

That would be a nice solution if it's doable.

I thought there was an issue with duplicates in some scenarios, due to logging the initial throwable, plus a rethrown fatal error due to "Exception thrown without a stack frame" or "Uncaught" exception. In which case see also this awful hack: mfb@77325d7

@Jean85
Copy link
Collaborator

Jean85 commented Mar 20, 2018

@mfb I don't see this behavior with a crude PHP script. I think that comes from some third party error handler that changes this stuff, like with Symfony.

@mfb
Copy link
Contributor

mfb commented Mar 20, 2018

Here's two pieces of reproduce code for the redundant fatal error reporting in Sentry version 1.8.4 - this is why I created that ugly code above to ignore certain fatal errors.


<?php
include '../vendor/autoload.php';
$client = new Raven_Client('...');
$client->install();
function thisiswrong(): float {
  return 'not a float';
}
thisiswrong();

Sentry records:

  • TypeError test.php in thisiswrong Return value of thisiswrong() must be of the type float, string returned
  • ErrorException test.php in handleFatalError Uncaught TypeError: Return value of thisiswrong() must be of the type float, string returned in...

<?php
include '../vendor/autoload.php';
$client = new Raven_Client('...');
$client->install();
include 'badcode.php';

badcode.php contains:

<?php
asdasdasdasd

Sentry records:

  • ParseError badcode.php in ? syntax error, unexpected end of file
  • ErrorException Unknown in handleFatalError Exception thrown without a stack frame

@Jean85
Copy link
Collaborator

Jean85 commented Mar 21, 2018

#574 is merged and should fix the double-reporting, @mfb can you check if this solves the issue for you?

@stayallive
Copy link
Collaborator Author

Thanks everyone for helping out 👍

We believe this issue should be fixed in 1.9.0 that was just released, if there is still an issue please reopen this issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment