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

Fatal errors are not recorded with the curl method async #391

Closed
e98cuenc opened this issue Dec 19, 2016 · 19 comments
Closed

Fatal errors are not recorded with the curl method async #391

e98cuenc opened this issue Dec 19, 2016 · 19 comments
Assignees

Comments

@e98cuenc
Copy link

Sentry flushes the unsent messages and calls curl join in the onShutdown method, which is correctly registered to run on shutdown.

However, fatal errors are logged on the ErrorHandler shutdown callback, which is registered after onShutdown. (onShutdown is registered on the Client constructor, and error_handler->registerShutdownFunction is call after you build the Client).

The end result is that a Fatal error gets recorded internally, but it's not send as onShutdown has already been called.

You need to make sure onShutdown runs after all other shutdown handlers.

@mfb
Copy link
Contributor

mfb commented Feb 17, 2018

Although some work was done on this last year, I believe this is still an issue, see #552 (comment)

@Jean85
Copy link
Contributor

Jean85 commented Feb 19, 2018

Isn't onShutdown called on the client destructor?

BTW yes, this is surely related to #552

@nokitakaze IIRC you wrote this part, what do you think?

@nokitakaze
Copy link
Contributor

I'm afraid I don't know. This case must be tested in separate process to test the behaviour.

mfb added a commit to mfb/sentry-php that referenced this issue Feb 20, 2018
…d async

very inelegant, but if we call onShutdown() then error could be logged
(if other logic allows it :)
@mfb
Copy link
Contributor

mfb commented Feb 20, 2018

I pushed a commit to demonstrate what needs to happen during the fatal error shutdown.

@Jean85
Copy link
Contributor

Jean85 commented Mar 20, 2018

@mfb do you think it would be feasible to write a test case for this issue? Maybe using a PHPT test like with #571?

@mfb
Copy link
Contributor

mfb commented Mar 20, 2018

Hmm not sure off the top of my head, if you had access to $client->_curl_handler->requests you could see if the requests were sent off?

@mfb
Copy link
Contributor

mfb commented Mar 20, 2018

here's code to reproduce the problem, just need a way to detect it:

<?php
include './vendor/autoload.php';
ini_set('memory_limit', '8M');
$client = new Raven_Client('...', ['curl_method' => 'async']);
$client->install();
while (TRUE) {
  $a[] = 'b';
}

@Jean85
Copy link
Contributor

Jean85 commented Mar 20, 2018

I think that the only way to detect it would be adding first an other exception handler which could output the result... I'll try that now.

@Jean85
Copy link
Contributor

Jean85 commented Mar 20, 2018

I cannot reproduce the issue, at least not under PHP 7.
This is my test script:

<?php
include '../vendor/autoload.php';

$dsnPublicSite = 'https://*****:******@sentry.io/*****';
$client = new Raven_Client($dsnPublicSite, ['curl_method' => 'async']);
$client->install();

ini_set('memory_limit', '8M');
while (TRUE) {
    $a[] = 'b';
}

... and this is the correct result:

schermata del 2018-03-20 23-21-39

I think that curl is called correctly because it's registered as a shutdown function here:

register_shutdown_function(array($this, 'join'));

@Jean85
Copy link
Contributor

Jean85 commented Mar 20, 2018

I've just tested it under PHP 5.6 and I can reproduce the issue, but my test is still green... Don't know why!

[EDIT] This is my test: e4fde16

@mfb
Copy link
Contributor

mfb commented Mar 20, 2018

Well, I can't get it to work on PHP 7.1, presumably because Raven_ErrorHandler registers its shutdown function last, so when it runs (firing off the last exception message), join() has already been called.

@mfb
Copy link
Contributor

mfb commented Mar 20, 2018

Your test is noting that join() was called, but it needs to be called again after handleFatalError() is called.

@Jean85
Copy link
Contributor

Jean85 commented Mar 21, 2018

You're right, thanks! Fixed in cf49ac1, opened #575 as a WIP PR.

Jean85 added a commit that referenced this issue Mar 21, 2018
Jean85 added a commit that referenced this issue Mar 21, 2018
* Try to recreate a regression PHPT tests for async sending of fatal errors
* Refactor PHPT regression test to check correctly for bug
* Apply fix for #391: culprit was bad autoloading during fatal handling under PHP > 7
* Add PHPT tests to PHPUnit config to be run on Travis (cherry picked from commit 92db2d9)
@Jean85
Copy link
Contributor

Jean85 commented Mar 21, 2018

#575 merged, can you test if this solves this issue?

@mfb
Copy link
Contributor

mfb commented Mar 21, 2018

I added some echo statements in the shutdown-related methods to make sure I'm not crazy, here's what I see:

  1. PHP Fatal error: Allowed memory size of 10485760 bytes exhausted (tried to allocate 8388616 bytes) in myapp/test.php on line 9
  2. running curl handler join
  3. running Client onShutdown
  4. running curl handler join
  5. running handleFatalError

So handleFatalError() is still running last, and there is no additional call to join() after that.

The order makes sense because that's the order that register_shutdown_function() is called (the Client makes its own additional call to join).

@mfb
Copy link
Contributor

mfb commented Mar 21, 2018

I had to tweak the test to have an actual working DSN, otherwise it seems like requests didn't queue up?

Also passed a reference to the client into the anonymous shutdown function rather than copying the variables.

This gives me "There are still queued request inside the Curl Handler":

<?php
$client = new \Raven_Client('ACTUAL WORKING DSN HERE', array('curl_method' => 'async'));

$client->setSendCallback(function () {
    echo 'Sending handled fatal error...' . PHP_EOL;
});

$client->install();

register_shutdown_function(function () use (&$client) {
    $pendingEvents = \PHPUnit\Framework\Assert::getObjectAttribute($client, '_pending_events');
    $curlHandler = \PHPUnit\Framework\Assert::getObjectAttribute($client, '_curl_handler');
    $pendingRequests = \PHPUnit\Framework\Assert::getObjectAttribute($curlHandler, 'requests');

    if (! empty($pendingEvents)) {
        echo 'There are pending events inside the client';
    }

    if (empty($pendingRequests)) {
        echo 'Curl handler successfully emptied';
    } else {
        echo 'There are still queued request inside the Curl Handler';
    }
});

ini_set('memory_limit', '8M');
while (TRUE) {
    $a[] = 'b';
}

Jean85 added a commit that referenced this issue Mar 21, 2018
@Jean85
Copy link
Contributor

Jean85 commented Mar 21, 2018

You're right once again @mfb, thanks a lot for your help!
You can check out the result in #576, I used your code to finally fix it! Does that work for you?

Jean85 added a commit that referenced this issue Apr 20, 2018
)

* Improve regression test for #575
* Apply final fix for #575 and #391
* Refactor PHPT test to avoid triggering autoloader during shutdown
* Trigger early autoload for the gzcompress function
* Disable zip compression while handling a fatal under PHP 5.x
* Trigger other autoloads
* Avoid false failure in regression test
* Ignore failures under PHP 5.4/5.5
* Move inspection of client state inside the shutdown function
* Apply review fixes
@stayallive
Copy link
Collaborator

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.

@mfb
Copy link
Contributor

mfb commented Jun 14, 2018

I have a related PR at #613 to provide a method for registering the async shutdown function. This is required by any custom setups of the client that don't call install()

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

6 participants